search

trinodb / trino

Official repository of Trino, the distributed SQL query engine for big data, formerly known as PrestoSQL (https://trino.io)
https://trino.io
Apache License 2.0
10.29k stars 2.96k forks source link

Product test launcher should be able to stop containers forcefully #5491

Closed kokosing closed 3 years ago

kokosing commented 4 years ago 
2020-10-09T10:10:49.7891264Z tests               | ===============================================
2020-10-09T10:10:49.7892659Z tests               | tempto-tests
2020-10-09T10:10:49.7893410Z tests               | Total tests run: 9, Failures: 0, Skips: 0
2020-10-09T10:10:49.7894102Z tests               | ===============================================
2020-10-09T10:10:49.7894685Z tests               | 
2020-10-09T10:10:49.9773394Z tests               | (exited)
2020-10-09T10:10:59.2130469Z 2020-10-09T10:10:59.212Z   INFO    main    io.prestosql.tests.product.launcher.env.Environment Test container 8cf9df2ef2ff0e9d8880ffca7f4322f9ea3a91259b471ee08a74b2cd79ff7bdd is exited, with exitCode 0
2020-10-09T10:10:59.2135672Z 2020-10-09T10:10:59.213Z   INFO    environment-listener-2  io.prestosql.tests.product.launcher.env.EnvironmentListener Environment stopping: singlenode-hive-privacera-ranger
2020-10-09T10:10:59.2157622Z 2020-10-09T10:10:59.215Z   INFO    environment-listener-2  io.prestosql.tests.product.launcher.env.EnvironmentListener Container stopping: ranger-admin
2020-10-09T10:11:01.5116340Z solr                | 2020-10-09 10:11:01.510 INFO  (commitScheduler-25-thread-1) [   ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
2020-10-09T10:11:01.5120462Z solr                | 2020-10-09 10:11:01.510 INFO  (commitScheduler-25-thread-1) [   ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@14dd5c53 commitCommandVersion:0
2020-10-09T10:11:01.5468577Z solr                | 2020-10-09 10:11:01.545 INFO  (commitScheduler-25-thread-1) [   ] o.a.s.s.SolrIndexSearcher Opening [Searcher@689b0d8f[ranger_audits] realtime]
2020-10-09T10:11:01.5470435Z solr                | 2020-10-09 10:11:01.546 INFO  (commitScheduler-25-thread-1) [   ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
2020-10-09T10:11:28.2037814Z presto-master       | 2020-10-09T15:56:28.202+0545 INFO    AsyncAuditProvider1 org.apache.ranger.audit.provider.AsyncAuditProvider AsyncAuditProvider-stats:MySolrAuditProvider: past 01:00.026 minutes: inLogs=3, outLogs=3, dropped=0, currentQueueSize=0
2020-10-09T10:11:28.2041023Z presto-master       | 2020-10-09T15:56:28.202+0545 INFO    AsyncAuditProvider1 org.apache.ranger.audit.provider.AsyncAuditProvider AsyncAuditProvider-stats:MySolrAuditProvider: process lifetime: inLogs=3, outLogs=3, dropped=0
2020-10-09T10:11:29.2171311Z 2020-10-09T10:11:29.216Z   WARN    main    io.prestosql.tests.product.launcher.env.DockerContainer Could not stop container correctly: java.util.concurrent.ExecutionException: net.jodah.failsafe.TimeoutExceededException
2020-10-09T10:11:29.2175194Z    at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
2020-10-09T10:11:29.2177180Z    at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
2020-10-09T10:11:29.2179489Z    at io.prestosql.tests.product.launcher.env.DockerContainer.tryStop(DockerContainer.java:398)
2020-10-09T10:11:29.2181148Z    at net.jodah.failsafe.Functions.lambda$toSupplier$10(Functions.java:240)
2020-10-09T10:11:29.2182186Z    at net.jodah.failsafe.Functions.lambda$get$0(Functions.java:48)
2020-10-09T10:11:29.2183505Z    at net.jodah.failsafe.RetryPolicyExecutor.lambda$supply$0(RetryPolicyExecutor.java:62)
2020-10-09T10:11:29.2184987Z    at net.jodah.failsafe.TimeoutExecutor.lambda$supply$2(TimeoutExecutor.java:91)
2020-10-09T10:11:29.2186249Z    at net.jodah.failsafe.Execution.executeSync(Execution.java:129)
2020-10-09T10:11:29.2187480Z    at net.jodah.failsafe.FailsafeExecutor.call(FailsafeExecutor.java:376)
2020-10-09T10:11:29.2188760Z    at net.jodah.failsafe.FailsafeExecutor.run(FailsafeExecutor.java:210)
2020-10-09T10:11:29.2193326Z    at io.prestosql.tests.product.launcher.env.Environment.lambda$stop$6(Environment.java:177)
2020-10-09T10:11:29.2196299Z    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
2020-10-09T10:11:29.2198520Z    at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177)
2020-10-09T10:11:29.2200891Z    at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:948)
2020-10-09T10:11:29.2203509Z    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
2020-10-09T10:11:29.2206473Z    at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
2020-10-09T10:11:29.2209218Z    at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
2020-10-09T10:11:29.2211651Z    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
2020-10-09T10:11:29.2214133Z    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
2020-10-09T10:11:29.2216790Z    at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
2020-10-09T10:11:29.2219755Z    at io.prestosql.tests.product.launcher.env.Environment.stop(Environment.java:177)
2020-10-09T10:11:29.2223109Z    at io.prestosql.tests.product.launcher.env.Environment.close(Environment.java:273)
2020-10-09T10:11:29.2226399Z    at io.prestosql.tests.product.launcher.cli.TestRun$Execution.tryExecuteTests(TestRun.java:199)
2020-10-09T10:11:29.2228895Z    at io.prestosql.tests.product.launcher.cli.TestRun$Execution.lambda$call$0(TestRun.java:179)
2020-10-09T10:11:29.2230214Z    at net.jodah.failsafe.Functions.lambda$get$0(Functions.java:48)
2020-10-09T10:11:29.2231447Z    at net.jodah.failsafe.TimeoutExecutor.lambda$supply$2(TimeoutExecutor.java:91)
2020-10-09T10:11:29.2232762Z    at net.jodah.failsafe.Execution.executeSync(Execution.java:129)
2020-10-09T10:11:29.2234035Z    at net.jodah.failsafe.FailsafeExecutor.call(FailsafeExecutor.java:376)
2020-10-09T10:11:29.2235516Z    at net.jodah.failsafe.FailsafeExecutor.get(FailsafeExecutor.java:67)
2020-10-09T10:11:29.2237252Z    at io.prestosql.tests.product.launcher.cli.TestRun$Execution.call(TestRun.java:179)
2020-10-09T10:11:29.2238806Z    at io.prestosql.tests.product.launcher.cli.SuiteRun$Execution.runTest(SuiteRun.java:228)
2020-10-09T10:11:29.2240559Z    at io.prestosql.tests.product.launcher.cli.SuiteRun$Execution.executeSuiteTestRun(SuiteRun.java:220)
2020-10-09T10:11:29.2242266Z    at io.prestosql.tests.product.launcher.cli.SuiteRun$Execution.call(SuiteRun.java:167)
2020-10-09T10:11:29.2243821Z    at io.prestosql.tests.product.launcher.cli.SuiteRun$Execution.call(SuiteRun.java:117)
2020-10-09T10:11:29.2245547Z    at io.prestosql.tests.product.launcher.cli.Commands.runCommand(Commands.java:42)
2020-10-09T10:11:29.2247401Z    at io.prestosql.tests.product.launcher.cli.SuiteRun.call(SuiteRun.java:85)
2020-10-09T10:11:29.2249003Z    at io.prestosql.tests.product.launcher.cli.SuiteRun.call(SuiteRun.java:55)
2020-10-09T10:11:29.2250384Z    at picocli.CommandLine.executeUserObject(CommandLine.java:1933)
2020-10-09T10:11:29.2251555Z    at picocli.CommandLine.access$1100(CommandLine.java:145)
2020-10-09T10:11:29.2253093Z    at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2332)
2020-10-09T10:11:29.2254605Z    at picocli.CommandLine$RunLast.handle(CommandLine.java:2326)
2020-10-09T10:11:29.2255434Z    at picocli.CommandLine$RunLast.handle(CommandLine.java:2291)
2020-10-09T10:11:29.2256514Z    at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2159)
2020-10-09T10:11:29.2257609Z    at picocli.CommandLine.execute(CommandLine.java:2058)
2020-10-09T10:11:29.2259535Z    at com.starburstdata.presto.tests.product.launcher.cli.StarburstLauncher.main(StarburstLauncher.java:62)
2020-10-09T10:11:29.2261605Z Caused by: net.jodah.failsafe.TimeoutExceededException
2020-10-09T10:11:29.2262864Z    at net.jodah.failsafe.TimeoutExecutor.lambda$null$3(TimeoutExecutor.java:119)
2020-10-09T10:11:29.2264752Z    at net.jodah.failsafe.internal.util.DelegatingScheduler.lambda$schedule$0(DelegatingScheduler.java:141)
2020-10-09T10:11:29.2266346Z    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2020-10-09T10:11:29.2267767Z    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-10-09T10:11:29.2269364Z    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-10-09T10:11:29.2270432Z    at java.base/java.lang.Thread.run(Thread.java:834)
2020-10-09T10:11:29.2270808Z 
2020-10-09T10:11:31.7040352Z presto-master       | 2020-10-09T15:56:31.703+0545 INFO    AsyncAuditProvider1 org.apache.ranger.audit.provider.AsyncAuditProvider AsyncAuditProvider-stats:MySolrAuditProvider: past 01:00.010 minutes: inLogs=31, outLogs=31, dropped=0, currentQueueSize=0
2020-10-09T10:11:31.7043512Z presto-master       | 2020-10-09T15:56:31.703+0545 INFO    AsyncAuditProvider1 org.apache.ranger.audit.provider.AsyncAuditProvider AsyncAuditProvider-stats:MySolrAuditProvider: process lifetime: inLogs=31, outLogs=31, dropped=0
2020-10-09T11:39:44.2516695Z ##[error]The operation was canceled.
2020-10-09T11:39:44.2588931Z Post job cleanup.
2020-10-09T11:39:44.2933074Z Post

At 10:10:59.215Z it was known that container failed to stop, but yet launcher was blocked anyway.

findepi commented 3 years ago

Does this relate to https://github.com/prestosql/presto/issues/5422?

kokosing commented 3 years ago

5422 was closed for a while, so maybe this why I opened new one. But why I reopened the old one? 🤔 Let me close this one, as the other one has more comments.