Flaky test io.prestosql.tests.hive.TestCsv: Error committing write to Hive

[findepi]

2020-03-19T15:50:55.0539634Z ptl-tests           | 2020-03-19 21:35:55 INFO: FAILURE     /    io.prestosql.tests.hive.TestCsv.testInsertIntoPartitionedCsvTable (Groups: storage_formats) took 7.5 seconds
2020-03-19T15:50:55.0589737Z ptl-tests           | 2020-03-19 21:35:55 SEVERE: Failure cause:
2020-03-19T15:50:55.0590300Z ptl-tests           | io.prestosql.tempto.query.QueryExecutionException: java.sql.SQLException: Query failed (#20200319_155048_00322_m3er2): Error committing write to Hive
2020-03-19T15:50:55.0590762Z ptl-tests           | 	at io.prestosql.tempto.query.JdbcQueryExecutor.execute(JdbcQueryExecutor.java:114)
2020-03-19T15:50:55.0591153Z ptl-tests           | 	at io.prestosql.tempto.query.JdbcQueryExecutor.executeQuery(JdbcQueryExecutor.java:82)
2020-03-19T15:50:55.0591770Z ptl-tests           | 	at io.prestosql.tempto.query.QueryExecutor.query(QueryExecutor.java:57)
2020-03-19T15:50:55.0592136Z ptl-tests           | 	at io.prestosql.tests.hive.TestCsv.testInsertIntoPartitionedCsvTable(TestCsv.java:126)
2020-03-19T15:50:55.0592500Z ptl-tests           | 	at io.prestosql.tests.hive.TestCsv.testInsertIntoPartitionedCsvTable(TestCsv.java:101)
2020-03-19T15:50:55.0592843Z ptl-tests           | 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-03-19T15:50:55.0593187Z ptl-tests           | 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-03-19T15:50:55.0593563Z ptl-tests           | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-03-19T15:50:55.0593888Z ptl-tests           | 	at java.lang.reflect.Method.invoke(Method.java:498)
2020-03-19T15:50:55.0594268Z ptl-tests           | 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2020-03-19T15:50:55.0594622Z ptl-tests           | 	at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
2020-03-19T15:50:55.0594961Z ptl-tests           | 	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
2020-03-19T15:50:55.0595304Z ptl-tests           | 	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
2020-03-19T15:50:55.0595666Z ptl-tests           | 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
2020-03-19T15:50:55.0596015Z ptl-tests           | 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
2020-03-19T15:50:55.0596374Z ptl-tests           | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2020-03-19T15:50:55.0596732Z ptl-tests           | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-03-19T15:50:55.0597047Z ptl-tests           | 	at java.lang.Thread.run(Thread.java:748)
2020-03-19T15:50:55.0597449Z ptl-tests           | Caused by: java.sql.SQLException: Query failed (#20200319_155048_00322_m3er2): Error committing write to Hive
2020-03-19T15:50:55.0597823Z ptl-tests           | 	at io.prestosql.jdbc.PrestoResultSet.resultsException(PrestoResultSet.java:1894)
2020-03-19T15:50:55.0598200Z ptl-tests           | 	at io.prestosql.jdbc.PrestoResultSet$ResultsPageIterator.computeNext(PrestoResultSet.java:1883)
2020-03-19T15:50:55.0598578Z ptl-tests           | 	at io.prestosql.jdbc.PrestoResultSet$ResultsPageIterator.computeNext(PrestoResultSet.java:1843)
2020-03-19T15:50:55.0598960Z ptl-tests           | 	at io.prestosql.jdbc.$internal.guava.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
2020-03-19T15:50:55.0599332Z ptl-tests           | 	at io.prestosql.jdbc.$internal.guava.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
2020-03-19T15:50:55.0599688Z ptl-tests           | 	at java.util.Spliterators$IteratorSpliterator.tryAdvance(Spliterators.java:1811)
2020-03-19T15:50:55.0600185Z ptl-tests           | 	at java.util.stream.StreamSpliterators$WrappingSpliterator.lambda$initPartialTraversalState$0(StreamSpliterators.java:295)
2020-03-19T15:50:55.0600617Z ptl-tests           | 	at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(StreamSpliterators.java:207)
2020-03-19T15:50:55.0601003Z ptl-tests           | 	at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(StreamSpliterators.java:162)
2020-03-19T15:50:55.0602094Z ptl-tests           | 	at java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(StreamSpliterators.java:301)
2020-03-19T15:50:55.0602965Z ptl-tests           | 	at java.util.Spliterators$1Adapter.hasNext(Spliterators.java:681)
2020-03-19T15:50:55.0603363Z ptl-tests           | 	at io.prestosql.jdbc.PrestoResultSet$AsyncIterator.lambda$new$0(PrestoResultSet.java:1785)
2020-03-19T15:50:55.0603736Z ptl-tests           | 	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
2020-03-19T15:50:55.0604023Z ptl-tests           | 	... 3 more
2020-03-19T15:50:55.0605207Z ptl-tests           | Caused by: io.prestosql.spi.PrestoException: Error committing write to Hive
2020-03-19T15:50:55.0606389Z ptl-tests           | 	at io.prestosql.plugin.hive.RecordFileWriter.commit(RecordFileWriter.java:184)
2020-03-19T15:50:55.0606780Z ptl-tests           | 	at io.prestosql.plugin.hive.HiveWriter.commit(HiveWriter.java:86)
2020-03-19T15:50:55.0607123Z ptl-tests           | 	at io.prestosql.plugin.hive.HivePageSink.doFinish(HivePageSink.java:190)
2020-03-19T15:50:55.0607537Z ptl-tests           | 	at io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.lambda$executeActionInDoAs$0(UserGroupInformationUtils.java:29)
2020-03-19T15:50:55.0607939Z ptl-tests           | 	at java.base/java.security.AccessController.doPrivileged(Native Method)
2020-03-19T15:50:55.0608398Z ptl-tests           | 	at java.base/javax.security.auth.Subject.doAs(Subject.java:361)
2020-03-19T15:50:55.0608866Z ptl-tests           | 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1710)
2020-03-19T15:50:55.0609278Z ptl-tests           | 	at io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.executeActionInDoAs(UserGroupInformationUtils.java:27)
2020-03-19T15:50:55.0609691Z ptl-tests           | 	at io.prestosql.plugin.hive.authentication.ImpersonatingHdfsAuthentication.doAs(ImpersonatingHdfsAuthentication.java:39)
2020-03-19T15:50:55.0610046Z ptl-tests           | 	at io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-03-19T15:50:55.0610389Z ptl-tests           | 	at io.prestosql.plugin.hive.HivePageSink.finish(HivePageSink.java:181)
2020-03-19T15:50:55.0610787Z ptl-tests           | 	at io.prestosql.plugin.base.classloader.ClassLoaderSafeConnectorPageSink.finish(ClassLoaderSafeConnectorPageSink.java:77)
2020-03-19T15:50:55.0611208Z ptl-tests           | 	at io.prestosql.operator.TableWriterOperator.finish(TableWriterOperator.java:194)
2020-03-19T15:50:55.0611533Z ptl-tests           | 	at io.prestosql.operator.Driver.processInternal(Driver.java:397)
2020-03-19T15:50:55.0611880Z ptl-tests           | 	at io.prestosql.operator.Driver.lambda$processFor$8(Driver.java:283)
2020-03-19T15:50:55.0612212Z ptl-tests           | 	at io.prestosql.operator.Driver.tryWithLock(Driver.java:675)
2020-03-19T15:50:55.0612735Z ptl-tests           | 	at io.prestosql.operator.Driver.processFor(Driver.java:276)
2020-03-19T15:50:55.0613144Z ptl-tests           | 	at io.prestosql.execution.SqlTaskExecution$DriverSplitRunner.processFor(SqlTaskExecution.java:1075)
2020-03-19T15:50:55.0613525Z ptl-tests           | 	at io.prestosql.execution.executor.PrioritizedSplitRunner.process(PrioritizedSplitRunner.java:163)
2020-03-19T15:50:55.0613900Z ptl-tests           | 	at io.prestosql.execution.executor.TaskExecutor$TaskRunner.run(TaskExecutor.java:484)
2020-03-19T15:50:55.0614414Z ptl-tests           | 	at io.prestosql.$gen.Presto_331_52_gb803a6e____20200319_153740_2.run(Unknown Source)
2020-03-19T15:50:55.0614841Z ptl-tests           | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-03-19T15:50:55.0615223Z ptl-tests           | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-03-19T15:50:55.0615550Z ptl-tests           | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-03-19T15:50:55.0616256Z ptl-tests           | Caused by: org.apache.hadoop.ipc.RemoteException: File /tmp/presto-hive/6259668e-87e8-4a02-bc80-0cab153cc272/suppkey=45/20200319_155048_00322_m3er2_a527ec43-3d2e-4817-bfc0-a6548835c620.gz could only be written to 0 of the 1 minReplication nodes. There are 1 datanode(s) running and no node(s) are excluded in this operation.
2020-03-19T15:50:55.0616705Z ptl-tests           | 	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.chooseTarget4NewBlock(BlockManager.java:2121)
2020-03-19T15:50:55.0617120Z ptl-tests           | 	at org.apache.hadoop.hdfs.server.namenode.FSDirWriteFileOp.chooseTargetForNewBlock(FSDirWriteFileOp.java:286)
2020-03-19T15:50:55.0617644Z ptl-tests           | 	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getAdditionalBlock(FSNamesystem.java:2706)
2020-03-19T15:50:55.0618040Z ptl-tests           | 	at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.addBlock(NameNodeRpcServer.java:875)
2020-03-19T15:50:55.0618479Z ptl-tests           | 	at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.addBlock(ClientNamenodeProtocolServerSideTranslatorPB.java:561)
2020-03-19T15:50:55.0618938Z ptl-tests           | 	at org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java)
2020-03-19T15:50:55.0619340Z ptl-tests           | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:524)
2020-03-19T15:50:55.0619680Z ptl-tests           | 	at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1025)
2020-03-19T15:50:55.0620018Z ptl-tests           | 	at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:876)
2020-03-19T15:50:55.0620448Z ptl-tests           | 	at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:822)
2020-03-19T15:50:55.0620890Z ptl-tests           | 	at java.security.AccessController.doPrivileged(Native Method)
2020-03-19T15:50:55.0621214Z ptl-tests           | 	at javax.security.auth.Subject.doAs(Subject.java:422)
2020-03-19T15:50:55.0621577Z ptl-tests           | 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1730)
2020-03-19T15:50:55.0621897Z ptl-tests           | 	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2682)
2020-03-19T15:50:55.0622159Z ptl-tests           | 
2020-03-19T15:50:55.0622483Z ptl-tests           | 	at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1511)
2020-03-19T15:50:55.0622810Z ptl-tests           | 	at org.apache.hadoop.ipc.Client.call(Client.java:1457)
2020-03-19T15:50:55.0623137Z ptl-tests           | 	at org.apache.hadoop.ipc.Client.call(Client.java:1367)
2020-03-19T15:50:55.0623502Z ptl-tests           | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:228)
2020-03-19T15:50:55.0623866Z ptl-tests           | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:116)
2020-03-19T15:50:55.0624188Z ptl-tests           | 	at com.sun.proxy.$Proxy200.addBlock(Unknown Source)
2020-03-19T15:50:55.0624596Z ptl-tests           | 	at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.addBlock(ClientNamenodeProtocolTranslatorPB.java:513)
2020-03-19T15:50:55.0624957Z ptl-tests           | 	at jdk.internal.reflect.GeneratedMethodAccessor741.invoke(Unknown Source)
2020-03-19T15:50:55.0625349Z ptl-tests           | 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-03-19T15:50:55.0625779Z ptl-tests           | 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-03-19T15:50:55.0626191Z ptl-tests           | 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:422)
2020-03-19T15:50:55.0626590Z ptl-tests           | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeMethod(RetryInvocationHandler.java:165)
2020-03-19T15:50:55.0626970Z ptl-tests           | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invoke(RetryInvocationHandler.java:157)
2020-03-19T15:50:55.0627356Z ptl-tests           | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeOnce(RetryInvocationHandler.java:95)
2020-03-19T15:50:55.0627735Z ptl-tests           | 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:359)
2020-03-19T15:50:55.0628113Z ptl-tests           | 	at com.sun.proxy.$Proxy201.addBlock(Unknown Source)
2020-03-19T15:50:55.0628475Z ptl-tests           | 	at org.apache.hadoop.hdfs.DFSOutputStream.addBlock(DFSOutputStream.java:1081)
2020-03-19T15:50:55.0628942Z ptl-tests           | 	at org.apache.hadoop.hdfs.DataStreamer.locateFollowingBlock(DataStreamer.java:1865)
2020-03-19T15:50:55.0672270Z ptl-tests           | 	at org.apache.hadoop.hdfs.DataStreamer.nextBlockOutputStream(DataStreamer.java:1668)
2020-03-19T15:50:55.0674060Z ptl-tests           | 	at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:716)

[findepi]

Similar failure for TestHive.testMetadataDelete in https://github.com/prestosql/presto/runs/802247499
on hive-tests (config-hdp3)

2020-06-24T06:30:11.3528195Z [ERROR] testMetadataDelete(io.prestosql.plugin.hive.TestHive)  Time elapsed: 0.779 s  <<< FAILURE!
2020-06-24T06:30:11.3532634Z io.prestosql.spi.PrestoException: Error committing write to Hive
2020-06-24T06:30:11.3537972Z 	at io.prestosql.plugin.hive.orc.OrcFileWriter.commit(OrcFileWriter.java:158)
2020-06-24T06:30:11.3542568Z 	at io.prestosql.plugin.hive.HiveWriter.commit(HiveWriter.java:86)
2020-06-24T06:30:11.3547189Z 	at io.prestosql.plugin.hive.HivePageSink.doFinish(HivePageSink.java:190)
2020-06-24T06:30:11.3553786Z 	at io.prestosql.plugin.hive.authentication.NoHdfsAuthentication.doAs(NoHdfsAuthentication.java:23)
2020-06-24T06:30:11.3559513Z 	at io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-06-24T06:30:11.3565024Z 	at io.prestosql.plugin.hive.HivePageSink.finish(HivePageSink.java:181)
2020-06-24T06:30:11.3570602Z 	at io.prestosql.plugin.hive.AbstractTestHive.insertData(AbstractTestHive.java:3981)
2020-06-24T06:30:11.3576553Z 	at io.prestosql.plugin.hive.AbstractTestHive.insertData(AbstractTestHive.java:3959)
2020-06-24T06:30:11.3582115Z 	at io.prestosql.plugin.hive.AbstractTestHive.doTestMetadataDelete(AbstractTestHive.java:4004)
2020-06-24T06:30:11.3588136Z 	at io.prestosql.plugin.hive.AbstractTestHive.testMetadataDelete(AbstractTestHive.java:2510)
2020-06-24T06:30:11.3593604Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-06-24T06:30:11.3600684Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-06-24T06:30:11.3607009Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-06-24T06:30:11.3611462Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-06-24T06:30:11.3617630Z 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2020-06-24T06:30:11.3621896Z 	at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
2020-06-24T06:30:11.3626471Z 	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
2020-06-24T06:30:11.3631157Z 	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
2020-06-24T06:30:11.3637010Z 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
2020-06-24T06:30:11.3642137Z 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
2020-06-24T06:30:11.3648228Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-06-24T06:30:11.3654001Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-06-24T06:30:11.3657567Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-06-24T06:30:11.3662221Z 	Suppressed: java.lang.AssertionError: Test did not commit or rollback
2020-06-24T06:30:11.3670495Z 		at io.prestosql.plugin.hive.metastore.SemiTransactionalHiveMetastore.testOnlyCheckIsReadOnly(SemiTransactionalHiveMetastore.java:1811)
2020-06-24T06:30:11.3677028Z 		at io.prestosql.plugin.hive.AbstractTestHive$HiveTransaction.close(AbstractTestHive.java:929)
2020-06-24T06:30:11.3683147Z 		at io.prestosql.plugin.hive.AbstractTestHive.insertData(AbstractTestHive.java:3968)
2020-06-24T06:30:11.3685106Z 		... 16 more
2020-06-24T06:30:11.3706034Z Caused by: org.apache.hadoop.ipc.RemoteException(java.io.IOException): File /tmp/presto-user/e87c1d71-548c-4d3e-a334-6e4409ff5ea7/ds=2015-07-01/20200624_062911_01035_dx73p_1a43e830-6694-4792-b8cd-82e1d3d36a0f could only be written to 0 of the 1 minReplication nodes. There are 1 datanode(s) running and no node(s) are excluded in this operation.
2020-06-24T06:30:11.3713253Z 	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.chooseTarget4NewBlock(BlockManager.java:2121)
2020-06-24T06:30:11.3721325Z 	at org.apache.hadoop.hdfs.server.namenode.FSDirWriteFileOp.chooseTargetForNewBlock(FSDirWriteFileOp.java:286)
2020-06-24T06:30:11.3727870Z 	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getAdditionalBlock(FSNamesystem.java:2706)
2020-06-24T06:30:11.3734263Z 	at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.addBlock(NameNodeRpcServer.java:875)
2020-06-24T06:30:11.3744317Z 	at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.addBlock(ClientNamenodeProtocolServerSideTranslatorPB.java:561)
2020-06-24T06:30:11.3753773Z 	at org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java)
2020-06-24T06:30:11.3760215Z 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:524)
2020-06-24T06:30:11.3763733Z 	at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1025)
2020-06-24T06:30:11.3767268Z 	at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:876)
2020-06-24T06:30:11.3771232Z 	at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:822)
2020-06-24T06:30:11.3775299Z 	at java.security.AccessController.doPrivileged(Native Method)
2020-06-24T06:30:11.3779000Z 	at javax.security.auth.Subject.doAs(Subject.java:422)
2020-06-24T06:30:11.3785035Z 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1730)
2020-06-24T06:30:11.3789590Z 	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2682)
2020-06-24T06:30:11.3790442Z 
2020-06-24T06:30:11.3794759Z 	at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1511)
2020-06-24T06:30:11.3799849Z 	at org.apache.hadoop.ipc.Client.call(Client.java:1457)
2020-06-24T06:30:11.3803936Z 	at org.apache.hadoop.ipc.Client.call(Client.java:1367)
2020-06-24T06:30:11.3809554Z 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:228)
2020-06-24T06:30:11.3820160Z 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:116)
2020-06-24T06:30:11.3823840Z 	at com.sun.proxy.$Proxy46.addBlock(Unknown Source)
2020-06-24T06:30:11.3831951Z 	at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.addBlock(ClientNamenodeProtocolTranslatorPB.java:513)
2020-06-24T06:30:11.3837245Z 	at jdk.internal.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
2020-06-24T06:30:11.3844107Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-06-24T06:30:11.3848263Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-06-24T06:30:11.3860668Z 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:422)
2020-06-24T06:30:11.3868143Z 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeMethod(RetryInvocationHandler.java:165)
2020-06-24T06:30:11.3875112Z 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invoke(RetryInvocationHandler.java:157)
2020-06-24T06:30:11.3881994Z 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeOnce(RetryInvocationHandler.java:95)
2020-06-24T06:30:11.3887512Z 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:359)
2020-06-24T06:30:11.3891067Z 	at com.sun.proxy.$Proxy47.addBlock(Unknown Source)
2020-06-24T06:30:11.3902986Z 	at org.apache.hadoop.hdfs.DFSOutputStream.addBlock(DFSOutputStream.java:1081)
2020-06-24T06:30:11.3910751Z 	at org.apache.hadoop.hdfs.DataStreamer.locateFollowingBlock(DataStreamer.java:1865)
2020-06-24T06:30:11.3916440Z 	at org.apache.hadoop.hdfs.DataStreamer.nextBlockOutputStream(DataStreamer.java:1668)
2020-06-24T06:30:11.3920923Z 	at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:716)

cc @MiguelWeezardo

[kokosing]

Can we just port this test to hive smoke tests?

[findepi]

Which one do you mean?

[MiguelWeezardo]

I found a very similar problem in my HDP3 test loop run from last night https://github.com/MiguelWeezardo/presto/runs/801422542:

2020-06-24T03:28:57.7654361Z presto-master       | 2020-06-24T09:13:57.763+0545	ERROR	remote-task-callback-29	io.prestosql.execution.StageStateMachine	Stage 20200624_032854_00432_f5d28.1 failed
2020-06-24T03:28:57.7654785Z presto-master       | io.prestosql.spi.PrestoException: Error committing write to Hive
2020-06-24T03:28:57.7655138Z presto-master       | 	at io.prestosql.plugin.hive.RecordFileWriter.commit(RecordFileWriter.java:184)
2020-06-24T03:28:57.7655471Z presto-master       | 	at io.prestosql.plugin.hive.HiveWriter.commit(HiveWriter.java:86)
2020-06-24T03:28:57.7655974Z presto-master       | 	at io.prestosql.plugin.hive.HivePageSink.doFinish(HivePageSink.java:190)
2020-06-24T03:28:57.7656361Z presto-master       | 	at io.prestosql.plugin.hive.authentication.NoHdfsAuthentication.doAs(NoHdfsAuthentication.java:23)
2020-06-24T03:28:57.7656719Z presto-master       | 	at io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-06-24T03:28:57.7657068Z presto-master       | 	at io.prestosql.plugin.hive.HivePageSink.finish(HivePageSink.java:181)
2020-06-24T03:28:57.7657491Z presto-master       | 	at io.prestosql.plugin.base.classloader.ClassLoaderSafeConnectorPageSink.finish(ClassLoaderSafeConnectorPageSink.java:77)
2020-06-24T03:28:57.7657872Z presto-master       | 	at io.prestosql.operator.TableWriterOperator.finish(TableWriterOperator.java:194)
2020-06-24T03:28:57.7658211Z presto-master       | 	at io.prestosql.operator.Driver.processInternal(Driver.java:397)
2020-06-24T03:28:57.7658565Z presto-master       | 	at io.prestosql.operator.Driver.lambda$processFor$8(Driver.java:283)
2020-06-24T03:28:57.7658906Z presto-master       | 	at io.prestosql.operator.Driver.tryWithLock(Driver.java:675)
2020-06-24T03:28:57.7659242Z presto-master       | 	at io.prestosql.operator.Driver.processFor(Driver.java:276)
2020-06-24T03:28:57.7659619Z presto-master       | 	at io.prestosql.execution.SqlTaskExecution$DriverSplitRunner.processFor(SqlTaskExecution.java:1075)
2020-06-24T03:28:57.7660115Z presto-master       | 	at io.prestosql.execution.executor.PrioritizedSplitRunner.process(PrioritizedSplitRunner.java:163)
2020-06-24T03:28:57.7660968Z presto-master       | 	at io.prestosql.execution.executor.TaskExecutor$TaskRunner.run(TaskExecutor.java:484)
2020-06-24T03:28:57.7661361Z presto-master       | 	at io.prestosql.$gen.Presto_c0c8339____20200624_030916_2.run(Unknown Source)
2020-06-24T03:28:57.7662838Z presto-master       | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-06-24T03:28:57.7663235Z presto-master       | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-06-24T03:28:57.7663575Z presto-master       | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-06-24T03:28:57.7664240Z presto-master       | Caused by: org.apache.hadoop.ipc.RemoteException: File /tmp/presto-hive/5cde9f47-c628-4a01-aef0-a47d2133483d/suppkey=36/20200624_032854_00432_f5d28_fdd0b665-9303-4b03-86b3-e07af89009ac.gz could only be written to 0 of the 1 minReplication nodes. There are 1 datanode(s) running and no node(s) are excluded in this operation.
2020-06-24T03:28:57.7664707Z presto-master       | 	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.chooseTarget4NewBlock(BlockManager.java:2121)
2020-06-24T03:28:57.7665560Z presto-master       | 	at org.apache.hadoop.hdfs.server.namenode.FSDirWriteFileOp.chooseTargetForNewBlock(FSDirWriteFileOp.java:286)
2020-06-24T03:28:57.7665975Z presto-master       | 	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getAdditionalBlock(FSNamesystem.java:2706)
2020-06-24T03:28:57.7666368Z presto-master       | 	at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.addBlock(NameNodeRpcServer.java:875)
2020-06-24T03:28:57.7666815Z presto-master       | 	at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.addBlock(ClientNamenodeProtocolServerSideTranslatorPB.java:561)
2020-06-24T03:28:57.7667277Z presto-master       | 	at org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java)
2020-06-24T03:28:57.7668055Z presto-master       | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:524)
2020-06-24T03:28:57.7669366Z presto-master       | 	at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1025)
2020-06-24T03:28:57.7670355Z presto-master       | 	at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:876)
2020-06-24T03:28:57.7670723Z presto-master       | 	at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:822)
2020-06-24T03:28:57.7671061Z presto-master       | 	at java.security.AccessController.doPrivileged(Native Method)
2020-06-24T03:28:57.7671391Z presto-master       | 	at javax.security.auth.Subject.doAs(Subject.java:422)
2020-06-24T03:28:57.7671756Z presto-master       | 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1730)
2020-06-24T03:28:57.7672551Z presto-master       | 	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2682)
2020-06-24T03:28:57.7672815Z presto-master       | 
2020-06-24T03:28:57.7673153Z presto-master       | 	at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1511)
2020-06-24T03:28:57.7673488Z presto-master       | 	at org.apache.hadoop.ipc.Client.call(Client.java:1457)
2020-06-24T03:28:57.7673815Z presto-master       | 	at org.apache.hadoop.ipc.Client.call(Client.java:1367)
2020-06-24T03:28:57.7674186Z presto-master       | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:228)
2020-06-24T03:28:57.7674550Z presto-master       | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:116)
2020-06-24T03:28:57.7674879Z presto-master       | 	at com.sun.proxy.$Proxy262.addBlock(Unknown Source)
2020-06-24T03:28:57.7675292Z presto-master       | 	at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.addBlock(ClientNamenodeProtocolTranslatorPB.java:513)
2020-06-24T03:28:57.7675665Z presto-master       | 	at jdk.internal.reflect.GeneratedMethodAccessor916.invoke(Unknown Source)
2020-06-24T03:28:57.7676063Z presto-master       | 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-06-24T03:28:57.7676410Z presto-master       | 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-06-24T03:28:57.7676924Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:422)
2020-06-24T03:28:57.7677306Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeMethod(RetryInvocationHandler.java:165)
2020-06-24T03:28:57.7677691Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invoke(RetryInvocationHandler.java:157)
2020-06-24T03:28:57.7678081Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeOnce(RetryInvocationHandler.java:95)
2020-06-24T03:28:57.7678463Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:359)
2020-06-24T03:28:57.7678800Z presto-master       | 	at com.sun.proxy.$Proxy263.addBlock(Unknown Source)
2020-06-24T03:28:57.7679157Z presto-master       | 	at org.apache.hadoop.hdfs.DFSOutputStream.addBlock(DFSOutputStream.java:1081)
2020-06-24T03:28:57.7679525Z presto-master       | 	at org.apache.hadoop.hdfs.DataStreamer.locateFollowingBlock(DataStreamer.java:1865)
2020-06-24T03:28:57.7679912Z presto-master       | 	at org.apache.hadoop.hdfs.DataStreamer.nextBlockOutputStream(DataStreamer.java:1668)
2020-06-24T03:28:57.7680256Z presto-master       | 	at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:716)
2020-06-24T03:28:57.7699626Z presto-master       | 
2020-06-24T03:28:57.7699860Z presto-master       | 
2020-06-24T03:28:57.7748192Z presto-master       | 2020-06-24T09:13:57.755+0545	ERROR	SplitRunner-1-101	io.prestosql.execution.executor.TaskExecutor	Error processing Split 20200624_032854_00432_f5d28.1.0-16  (start = 1.3139963584519E7, wall = 2904 ms, cpu = 141 ms, wait = 1 ms, calls = 3): HIVE_WRITER_CLOSE_ERROR: Error committing write to Hive
2020-06-24T03:28:57.7748690Z presto-master       | io.prestosql.spi.PrestoException: Error committing write to Hive
2020-06-24T03:28:57.7785415Z presto-master       | 	at io.prestosql.plugin.hive.RecordFileWriter.commit(RecordFileWriter.java:184)
2020-06-24T03:28:57.7785794Z presto-master       | 	at io.prestosql.plugin.hive.HiveWriter.commit(HiveWriter.java:86)
2020-06-24T03:28:57.7786114Z presto-master       | 	at io.prestosql.plugin.hive.HivePageSink.doFinish(HivePageSink.java:190)
2020-06-24T03:28:57.7786471Z presto-master       | 	at io.prestosql.plugin.hive.authentication.NoHdfsAuthentication.doAs(NoHdfsAuthentication.java:23)
2020-06-24T03:28:57.7786807Z presto-master       | 	at io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-06-24T03:28:57.7787131Z presto-master       | 	at io.prestosql.plugin.hive.HivePageSink.finish(HivePageSink.java:181)
2020-06-24T03:28:57.7787520Z presto-master       | 	at io.prestosql.plugin.base.classloader.ClassLoaderSafeConnectorPageSink.finish(ClassLoaderSafeConnectorPageSink.java:77)
2020-06-24T03:28:57.7787863Z presto-master       | 	at io.prestosql.operator.TableWriterOperator.finish(TableWriterOperator.java:194)
2020-06-24T03:28:57.7788181Z presto-master       | 	at io.prestosql.operator.Driver.processInternal(Driver.java:397)
2020-06-24T03:28:57.7788507Z presto-master       | 	at io.prestosql.operator.Driver.lambda$processFor$8(Driver.java:283)
2020-06-24T03:28:57.7788819Z presto-master       | 	at io.prestosql.operator.Driver.tryWithLock(Driver.java:675)
2020-06-24T03:28:57.7789129Z presto-master       | 	at io.prestosql.operator.Driver.processFor(Driver.java:276)
2020-06-24T03:28:57.7789480Z presto-master       | 	at io.prestosql.execution.SqlTaskExecution$DriverSplitRunner.processFor(SqlTaskExecution.java:1075)
2020-06-24T03:28:57.7789834Z presto-master       | 	at io.prestosql.execution.executor.PrioritizedSplitRunner.process(PrioritizedSplitRunner.java:163)
2020-06-24T03:28:57.7790164Z presto-master       | 	at io.prestosql.execution.executor.TaskExecutor$TaskRunner.run(TaskExecutor.java:484)
2020-06-24T03:28:57.7790501Z presto-master       | 	at io.prestosql.$gen.Presto_c0c8339____20200624_030916_2.run(Unknown Source)
2020-06-24T03:28:57.7790849Z presto-master       | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-06-24T03:28:57.7791374Z presto-master       | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-06-24T03:28:57.7791681Z presto-master       | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-06-24T03:28:57.7792355Z presto-master       | Caused by: org.apache.hadoop.ipc.RemoteException(java.io.IOException): File /tmp/presto-hive/5cde9f47-c628-4a01-aef0-a47d2133483d/suppkey=36/20200624_032854_00432_f5d28_fdd0b665-9303-4b03-86b3-e07af89009ac.gz could only be written to 0 of the 1 minReplication nodes. There are 1 datanode(s) running and no node(s) are excluded in this operation.
2020-06-24T03:28:57.7792740Z presto-master       | 	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.chooseTarget4NewBlock(BlockManager.java:2121)
2020-06-24T03:28:57.7793074Z presto-master       | 	at org.apache.hadoop.hdfs.server.namenode.FSDirWriteFileOp.chooseTargetForNewBlock(FSDirWriteFileOp.java:286)
2020-06-24T03:28:57.7793405Z presto-master       | 	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getAdditionalBlock(FSNamesystem.java:2706)
2020-06-24T03:28:57.7793721Z presto-master       | 	at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.addBlock(NameNodeRpcServer.java:875)
2020-06-24T03:28:57.7794080Z presto-master       | 	at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.addBlock(ClientNamenodeProtocolServerSideTranslatorPB.java:561)
2020-06-24T03:28:57.7794448Z presto-master       | 	at org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java)
2020-06-24T03:28:57.7794843Z presto-master       | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:524)
2020-06-24T03:28:57.7795132Z presto-master       | 	at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1025)
2020-06-24T03:28:57.7795407Z presto-master       | 	at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:876)
2020-06-24T03:28:57.7795685Z presto-master       | 	at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:822)
2020-06-24T03:28:57.7795957Z presto-master       | 	at java.security.AccessController.doPrivileged(Native Method)
2020-06-24T03:28:57.7796223Z presto-master       | 	at javax.security.auth.Subject.doAs(Subject.java:422)
2020-06-24T03:28:57.7796520Z presto-master       | 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1730)
2020-06-24T03:28:57.7796795Z presto-master       | 	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2682)
2020-06-24T03:28:57.7797011Z presto-master       | 
2020-06-24T03:28:57.7797490Z presto-master       | 	at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1511)
2020-06-24T03:28:57.7797819Z presto-master       | 	at org.apache.hadoop.ipc.Client.call(Client.java:1457)
2020-06-24T03:28:57.7798142Z presto-master       | 	at org.apache.hadoop.ipc.Client.call(Client.java:1367)
2020-06-24T03:28:57.7798508Z presto-master       | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:228)
2020-06-24T03:28:57.7798874Z presto-master       | 	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:116)
2020-06-24T03:28:57.7799199Z presto-master       | 	at com.sun.proxy.$Proxy262.addBlock(Unknown Source)
2020-06-24T03:28:57.7799607Z presto-master       | 	at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.addBlock(ClientNamenodeProtocolTranslatorPB.java:513)
2020-06-24T03:28:57.7799975Z presto-master       | 	at jdk.internal.reflect.GeneratedMethodAccessor916.invoke(Unknown Source)
2020-06-24T03:28:57.7800672Z presto-master       | 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-06-24T03:28:57.7801039Z presto-master       | 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-06-24T03:28:57.7801419Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:422)
2020-06-24T03:28:57.7801887Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeMethod(RetryInvocationHandler.java:165)
2020-06-24T03:28:57.7802272Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invoke(RetryInvocationHandler.java:157)
2020-06-24T03:28:57.7802659Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeOnce(RetryInvocationHandler.java:95)
2020-06-24T03:28:57.7803039Z presto-master       | 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:359)
2020-06-24T03:28:57.7803371Z presto-master       | 	at com.sun.proxy.$Proxy263.addBlock(Unknown Source)
2020-06-24T03:28:57.7803728Z presto-master       | 	at org.apache.hadoop.hdfs.DFSOutputStream.addBlock(DFSOutputStream.java:1081)
2020-06-24T03:28:57.7804093Z presto-master       | 	at org.apache.hadoop.hdfs.DataStreamer.locateFollowingBlock(DataStreamer.java:1865)
2020-06-24T03:28:57.7804465Z presto-master       | 	at org.apache.hadoop.hdfs.DataStreamer.nextBlockOutputStream(DataStreamer.java:1668)
2020-06-24T03:28:57.7804808Z presto-master       | 	at org.apache.hadoop.hdfs.DataStreamer.run(DataStreamer.java:716)
2020-06-24T03:28:57.7805073Z presto-master       | 
2020-06-24T03:28:57.7805320Z presto-master       | 
2020-06-24T03:28:57.8109552Z tests               | 2020-06-24 09:13:57 INFO: FAILURE     /    io.prestosql.tests.hive.TestCsv.testInsertIntoPartitionedCsvTable (Groups: storage_formats) took 3.2 seconds

[findepi]

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

[MiguelWeezardo]

Similar error in https://github.com/prestosql/presto/runs/823250219

[findepi]

https://github.com/prestosql/presto/runs/828604528, on cdh5

[findepi]

TestCsv.testCreatePartitionedCsvTableAsWithCustomParamters too

[findepi]

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

[findepi]

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

[findepi]

Hopefully fixed by #4573.
Reopen if Error committing write to Hive resurfaces.