Details
-
Improvement
-
Status: Resolved
-
Minor
-
Resolution: Fixed
-
3.14.1
-
None
-
Unknown
Description
Camel cannot shut down gracefully synchronous pull PubSub consumers due to uninterruptible threads that must be forcibly stopped:
2022-03-29 11:01:28.281 [SpringApplicationShutdownHook] INFO 22501 - - - --- [ionShutdownHook] o.a.c.impl.engine.AbstractCamelContext : Apache Camel 3.14.1 (****) shutting down (timeout:25s) 2022-03-29 11:01:28.285 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.c.g.pubsub.GooglePubsubConsumer : Stopping Google PubSub consumer for test/****JobQueue 2022-03-29 11:01:30.285 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 2s for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:32.286 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 4s1ms for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:34.286 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 6s1ms for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:36.287 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 8s2ms for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:38.285 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 10s for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:38.285 [Camel (****) thread #17 - ShutdownTask] WARN 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] due first await termination elapsed. 2022-03-29 11:01:40.286 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 2s for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:42.286 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 4s for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:44.287 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 6s1ms for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:46.287 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 8s1ms for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:48.286 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Waited 10s for ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] to terminate... 2022-03-29 11:01:48.287 [Camel (****) thread #17 - ShutdownTask] WARN 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Cannot completely force shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] due second await termination elapsed. 2022-03-29 11:01:48.287 [Camel (****) thread #17 - ShutdownTask] INFO 22501 - - - --- [ - ShutdownTask] o.a.c.i.e.BaseExecutorServiceManager : Shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@5a118efb[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0][GooglePubsubConsumer[****JobQueue]] is shutdown: true and terminated: false took: 20s2ms. 2022-03-29 11:01:48.742 [SpringApplicationShutdownHook] INFO 22501 - - - --- [ionShutdownHook] o.a.c.impl.engine.AbstractCamelContext : Apache Camel 3.14.1 (****) shutdown in 20s461ms (uptime:46s901ms)
A solution would be to use Google asynchronous API to store callbacks on the blocking requests and use these callbacks to cancel the requests when Camel shuts down.
Resulting shutdown logs:
2022-03-29 11:05:02.593 [SpringApplicationShutdownHook] INFO 24628 - - - --- [ionShutdownHook] o.a.c.impl.engine.AbstractCamelContext : Apache Camel 3.14.1 (****) shutting down (timeout:25s) 2022-03-29 11:05:02.616 [Camel (****) thread #17 - ShutdownTask] INFO 24628 - - - --- [ - ShutdownTask] o.a.c.c.g.pubsub.GooglePubsubConsumer : Stopping Google PubSub consumer for test/****JobQueue 2022-03-29 11:05:02.632 [Camel (****) thread #5 - GooglePubsubConsumer[****JobQueue]] INFO 24628 - - - --- [r[****JobQueue]] o.a.c.c.g.pubsub.GooglePubsubConsumer : PubSub synchronous pull request cancelled java.util.concurrent.CancellationException: Task was cancelled. at com.google.common.util.concurrent.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1496) at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:586) at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:567) at org.apache.camel.component.google.pubsub.GooglePubsubConsumer$SubscriberWrapper.synchronousPull(GooglePubsubConsumer.java:192) at org.apache.camel.component.google.pubsub.GooglePubsubConsumer$SubscriberWrapper.run(GooglePubsubConsumer.java:150) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) 2022-03-29 11:05:03.552 [SpringApplicationShutdownHook] INFO 24628 - - - --- [ionShutdownHook] o.a.c.impl.engine.AbstractCamelContext : Apache Camel 3.14.1 (****) shutdown in 959ms (uptime:1m56s)
```
Attachments
Issue Links
- links to