Flaky test TestJdbcConnection.testConcurrentCancellationOnConnectionClose

[findepi]

2021-07-19T16:15:09.7299630Z [ERROR] Tests run: 210, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 136.634 s <<< FAILURE! - in TestSuite
2021-07-19T16:15:09.7309885Z [ERROR] testConcurrentCancellationOnConnectionClose(io.trino.jdbc.TestJdbcConnection)  Time elapsed: 0.029 s  <<< FAILURE!
2021-07-19T16:15:09.7313732Z java.lang.AssertionError: 
2021-07-19T16:15:09.7314989Z 
2021-07-19T16:15:09.7317465Z Expecting ArrayList:
2021-07-19T16:15:09.7319901Z   <["USER_CANCELED",
2021-07-19T16:15:09.7322249Z     "USER_CANCELED",
2021-07-19T16:15:09.7324621Z     "USER_CANCELED",
2021-07-19T16:15:09.7326989Z     "USER_CANCELED",
2021-07-19T16:15:09.7329329Z     "USER_CANCELED",
2021-07-19T16:15:09.7331945Z     "USER_CANCELED",
2021-07-19T16:15:09.7334463Z     "USER_CANCELED",
2021-07-19T16:15:09.7337015Z     "USER_CANCELED",
2021-07-19T16:15:09.7340866Z     "TRANSACTION_ALREADY_ABORTED",
2021-07-19T16:15:09.7343590Z     "USER_CANCELED"]>
2021-07-19T16:15:09.7345900Z to contain only:
2021-07-19T16:15:09.7348488Z   <["USER_CANCELED"]>
2021-07-19T16:15:09.7352671Z but the following element(s) were unexpected:
2021-07-19T16:15:09.7356927Z   <["TRANSACTION_ALREADY_ABORTED"]>
2021-07-19T16:15:09.7358147Z 
2021-07-19T16:15:09.7366990Z 	at io.trino.jdbc.TestJdbcConnection.testConcurrentCancellationOnConnectionClose(TestJdbcConnection.java:538)
2021-07-19T16:15:09.7375289Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-07-19T16:15:09.7384005Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2021-07-19T16:15:09.7393683Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-07-19T16:15:09.7400353Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-07-19T16:15:09.7408920Z 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2021-07-19T16:15:09.7416680Z 	at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:54)
2021-07-19T16:15:09.7424087Z 	at org.testng.internal.InvokeMethodRunnable.run(InvokeMethodRunnable.java:44)
2021-07-19T16:15:09.7431290Z 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
2021-07-19T16:15:09.7438462Z 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2021-07-19T16:15:09.7446677Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-07-19T16:15:09.7454174Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-07-19T16:15:09.7459234Z 	at java.base/java.lang.Thread.run(Thread.java:829)

cc @kokosing

[sopel39]

I think this still happens:
https://github.com/trinodb/trino/pull/9336/checks?check_run_id=3684390362

2021-09-23T07:46:41.1370428Z [ERROR] Tests run: 212, Failures: 2, Errors: 0, Skipped: 0, Time elapsed: 196.672 s <<< FAILURE! - in TestSuite
2021-09-23T07:46:41.1375474Z [ERROR] io.trino.jdbc.TestJdbcConnection.testConcurrentCancellationOnConnectionClose[false](4)  Time elapsed: 3.447 s  <<< FAILURE!
2021-09-23T07:46:41.1378530Z java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.sql.SQLException: Query failed (#20210923_074352_00055_3artj): Nested transactions not supported
2021-09-23T07:46:41.1383629Z 	at io.trino.jdbc.TestJdbcConnection.assertThatFutureIsBlocked(TestJdbcConnection.java:698)
2021-09-23T07:46:41.1385501Z 	at com.google.common.collect.ImmutableList.forEach(ImmutableList.java:406)
2021-09-23T07:46:41.1387975Z 	at io.trino.jdbc.TestJdbcConnection.lambda$testConcurrentCancellationOnConnectionClose$8(TestJdbcConnection.java:526)
2021-09-23T07:46:41.1390734Z 	at io.trino.testing.assertions.Assert.assertEventually(Assert.java:71)
2021-09-23T07:46:41.1393155Z 	at io.trino.testing.assertions.Assert.assertEventually(Assert.java:63)
2021-09-23T07:46:41.1395377Z 	at io.trino.testing.assertions.Assert.assertEventually(Assert.java:58)
2021-09-23T07:46:41.1398480Z 	at io.trino.jdbc.TestJdbcConnection.testConcurrentCancellationOnConnectionClose(TestJdbcConnection.java:525)
2021-09-23T07:46:41.1403224Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-09-23T07:46:41.1405951Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2021-09-23T07:46:41.1408738Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-09-23T07:46:41.1411525Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-09-23T07:46:41.1413424Z 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2021-09-23T07:46:41.1415950Z 	at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:54)
2021-09-23T07:46:41.1417649Z 	at org.testng.internal.InvokeMethodRunnable.run(InvokeMethodRunnable.java:44)
2021-09-23T07:46:41.1419673Z 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
2021-09-23T07:46:41.1421258Z 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2021-09-23T07:46:41.1422826Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-09-23T07:46:41.1425742Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-09-23T07:46:41.1427524Z 	at java.base/java.lang.Thread.run(Thread.java:829)
2021-09-23T07:46:41.1429603Z Caused by: java.util.concurrent.ExecutionException: java.sql.SQLException: Query failed (#20210923_074352_00055_3artj): Nested transactions not supported
2021-09-23T07:46:41.1431185Z 	at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
2021-09-23T07:46:41.1432442Z 	at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
2021-09-23T07:46:41.1434201Z 	at io.trino.jdbc.TestJdbcConnection.assertThatFutureIsBlocked(TestJdbcConnection.java:695)
2021-09-23T07:46:41.1435502Z 	... 18 more
2021-09-23T07:46:41.1436213Z Caused by: java.sql.SQLException: Query failed (#20210923_074352_00055_3artj): Nested transactions not supported
2021-09-23T07:46:41.1437810Z 	at io.trino.jdbc.AbstractTrinoResultSet.resultsException(AbstractTrinoResultSet.java:1912)
2021-09-23T07:46:41.1439534Z 	at io.trino.jdbc.TrinoResultSet.getColumns(TrinoResultSet.java:243)
2021-09-23T07:46:41.1440967Z 	at io.trino.jdbc.TrinoResultSet.create(TrinoResultSet.java:53)
2021-09-23T07:46:41.1442292Z 	at io.trino.jdbc.TrinoStatement.internalExecute(TrinoStatement.java:262)
2021-09-23T07:46:41.1444847Z 	at io.trino.jdbc.TrinoStatement.execute(TrinoStatement.java:238)
2021-09-23T07:46:41.1446531Z 	at io.trino.jdbc.TrinoStatement.executeQuery(TrinoStatement.java:78)
2021-09-23T07:46:41.1472634Z 	at io.trino.jdbc.TestJdbcConnection.lambda$testConcurrentCancellationOnConnectionClose$6(TestJdbcConnection.java:514)
2021-09-23T07:46:41.1474375Z 	... 4 more
2021-09-23T07:46:41.1476218Z Caused by: io.trino.spi.TrinoException: Nested transactions not supported
2021-09-23T07:46:41.1477966Z 	at io.trino.execution.StartTransactionTask.execute(StartTransactionTask.java:62)
2021-09-23T07:46:41.1480150Z 	at io.trino.execution.StartTransactionTask.execute(StartTransactionTask.java:38)
2021-09-23T07:46:41.1482476Z 	at io.trino.execution.DataDefinitionExecution.start(DataDefinitionExecution.java:170)
2021-09-23T07:46:41.1484294Z 	at io.trino.execution.SqlQueryManager.createQuery(SqlQueryManager.java:237)
2021-09-23T07:46:41.1486066Z 	at io.trino.dispatcher.LocalDispatchQuery.lambda$startExecution$7(LocalDispatchQuery.java:143)
2021-09-23T07:46:41.1487562Z 	at io.trino.$gen.Trino_testversion____20210923_074345_15.run(Unknown Source)
2021-09-23T07:46:41.1488914Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-09-23T07:46:41.1490700Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-09-23T07:46:41.1491898Z 	at java.base/java.lang.Thread.run(Thread.java:829)
2021-09-23T07:46:41.1492387Z 
2021-09-23T07:46:41.1493240Z [ERROR] io.trino.jdbc.TestJdbcConnection.tearDown  Time elapsed: 0.841 s  <<< FAILURE!
2021-09-23T07:46:41.1494713Z io.airlift.bootstrap.LifeCycleStopException: Exceptions occurred during lifecycle stop
2021-09-23T07:46:41.1496281Z 	at io.airlift.bootstrap.LifeCycleManager.stop(LifeCycleManager.java:164)
2021-09-23T07:46:41.1498478Z 	at io.trino.server.testing.TestingTrinoServer.lambda$close$3(TestingTrinoServer.java:344)
2021-09-23T07:46:41.1500073Z 	at com.google.common.io.Closer.close(Closer.java:213)
2021-09-23T07:46:41.1503277Z 	at io.trino.server.testing.TestingTrinoServer.close(TestingTrinoServer.java:347)
2021-09-23T07:46:41.1505034Z 	at io.airlift.testing.Closeables.closeAll(Closeables.java:60)
2021-09-23T07:46:41.1506973Z 	at io.airlift.testing.Closeables.closeAll(Closeables.java:41)
2021-09-23T07:46:41.1508710Z 	at io.trino.jdbc.TestJdbcConnection.tearDown(TestJdbcConnection.java:116)
2021-09-23T07:46:41.1510745Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-09-23T07:46:41.1513038Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2021-09-23T07:46:41.1515630Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-09-23T07:46:41.1517444Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-09-23T07:46:41.1519070Z 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2021-09-23T07:46:41.1521268Z 	at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:515)
2021-09-23T07:46:41.1523790Z 	at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:217)
2021-09-23T07:46:41.1525834Z 	at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:144)
2021-09-23T07:46:41.1532464Z 	at org.testng.internal.TestMethodWorker.invokeAfterClassMethods(TestMethodWorker.java:217)
2021-09-23T07:46:41.1534569Z 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:115)
2021-09-23T07:46:41.1536283Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-09-23T07:46:41.1538415Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-09-23T07:46:41.1539790Z 	at java.base/java.lang.Thread.run(Thread.java:829)
2021-09-23T07:46:41.1540247Z 
2021-09-23T07:46:41.5845426Z [INFO] 
2021-09-23T07:46:41.5846309Z [INFO] Results:
2021-09-23T07:46:41.5847498Z [INFO] 
2021-09-23T07:46:41.5848018Z [ERROR] Failures: 
2021-09-23T07:46:41.5852787Z [ERROR]   TestJdbcConnection.tearDown:116 » LifeCycleStop Exceptions occurred during lif...
2021-09-23T07:46:41.5861466Z [ERROR]   TestJdbcConnection.testConcurrentCancellationOnConnectionClose:525->lambda$testConcurrentCancellationOnConnectionClose$8:526->assertThatFutureIsBlocked:698 Runtime
2021-09-23T07:46:41.5864242Z [INFO] 
2021-09-23T07:46:41.5864991Z [ERROR] Tests run: 212, Failures: 2, Errors: 0, Skipped: 0

[sopel39]

#9428

[findepi]

https://github.com/trinodb/trino/runs/4106866404?check_suite_focus=true cc @kokosing

[findepi]

https://github.com/trinodb/trino/runs/4337909013?check_suite_focus=true cc @kokosing

[kokosing]

It is flaky because of: #10096

[kokosing]

#10097

[kokosing]

Fixed by #10097