Hi,
Correct, when I change the time-out in the Camel DefaultShutdownStrategy to 30 seconds (staying within the blueprint container timeout) the exception went away. I’m just curious of why this seems to be a problem now as, if i recall correctly, it worked before. Before, i mean when i upgraded our application from Karaf 4.0.4 to 4.2.0, and Camel from 2.18.3 to 2.20.1. Thanks for the input so far! — Joery > On 3 Jun 2018, at 18:47, Jean-Baptiste Onofré <[email protected]> wrote: > > So, it seems that you have inflight messages and shutdown strategy are > longer then the blueprint container timeout. > > I would start to change the shutdown strategy to be a little bit more > aggressive. > > Regards > JB > >> On 03/06/2018 17:31, Joery Vreijsen wrote: >> Hi! >> >> Thanks for the quick response, yes I used the DefaultShutdownStrategy of >> Apache Camel 2.21.1. >> >> — >> >> Joery >>> On 3 Jun 2018, 17:24 +0200, Jean-Baptiste Onofré <[email protected]>, wrote: >>> Hi >>> >>> do you use the default Camel graceful shutdown strategy or a custom one ? >>> >>> Regards >>> JB >>> >>>> On 02/06/2018 22:17, Joery Vreijsen wrote: >>>> Hi there! >>>> >>>> I’m running into a weird issue regarding some timeouts when uninstalling >>>> a CamelContext in Karaf 4.2.0. >>>> Due to the fact that i’m not entirely sure if this is a Camel or Karaf >>>> issue, but the exception is thrown from inside Karaf i’m going to try it >>>> here first. >>>> >>>> I am installing a Camel Context in Karaf using a blueprint.xml. Say a >>>> route in this context has a syntax error in it, and when it’s still >>>> running i’m trying to uninstall the bundle in Karaf. >>>> The result is correct, i get the inflight message from Camel with the >>>> note saying it’s going to timeout in 5 minutes (300 seconds): >>>> >>>> /[Camel (context-1) thread #1 - ShutdownTask] Waiting as there are still >>>> 3 inflight and pending exchanges to complete, timeout in 295 seconds. >>>> Inflights per route: [route-3 = 1, route-2 = 1, route-1 = 1] >>>> [Camel (context-1) thread #1 - ShutdownTask] There are 2 inflight >>>> exchanges: >>>> InflightExchange: [exchangeId=ID-mac-local-1527969270260-1-1, >>>> fromRouteId=route-1, routeId=route-2, nodeId=split2, elapsed=0, >>>> duration=71634] >>>> InflightExchange: [exchangeId=ID-mac-local-1527969270260-1-3, >>>> fromRouteId=route-1, routeId=route-3, nodeId=to6, elapsed=0, >>>> duration=71634]/ >>>> >>>> But after exactly one minute (consistently) the graceful shutdown >>>> procedure of camel is interrupted and the following appears in the logs: >>>> >>>> /WARN [Blueprint Event Dispatcher: 1] Timeout occurred during graceful >>>> shutdown. Forcing the routes to be shutdown now. Notice: some resources >>>> may still be running as graceful shutdown did not complete successfully. >>>> WARN [pipe-bundle:uninstall 110] Listener timed out, will be ignored >>>> java.util.concurrent.TimeoutException: null >>>> at >>>> java.util.concurrent.AbstractExecutorService.doInvokeAny(AbstractExecutorService.java:184) >>>> ~[?:?] >>>> at >>>> java.util.concurrent.AbstractExecutorService.invokeAny(AbstractExecutorService.java:225) >>>> ~[?:?] >>>> at >>>> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper$4.call(ScheduledExecutorServiceWrapper.java:182) >>>> ~[45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper$15.call(ScheduledExecutorServiceWrapper.java:443) >>>> ~[45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.utils.threading.RWLock.runReadOperation(RWLock.java:33) >>>> ~[45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper.runUnlessShutdown(ScheduledExecutorServiceWrapper.java:440) >>>> ~[45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper.invokeAny(ScheduledExecutorServiceWrapper.java:177) >>>> ~[45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.container.BlueprintEventDispatcher.callListener(BlueprintEventDispatcher.java:188) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.container.BlueprintEventDispatcher.callListeners(BlueprintEventDispatcher.java:178) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.container.BlueprintEventDispatcher.blueprintEvent(BlueprintEventDispatcher.java:133) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.container.BlueprintContainerImpl.destroy(BlueprintContainerImpl.java:888) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.container.BlueprintExtender$3.run(BlueprintExtender.java:324) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) >>>> [?:?] >>>> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] >>>> at >>>> org.apache.aries.blueprint.container.BlueprintExtender.destroyContainer(BlueprintExtender.java:345) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:237) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:500) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:433) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$AbstractTracked.track(BundleHookBundleTracker.java:725) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.bundleChanged(BundleHookBundleTracker.java:463) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$BundleEventHook.event(BundleHookBundleTracker.java:422) >>>> [45:org.apache.aries.blueprint.core:1.9.0] >>>> at >>>> org.apache.felix.framework.util.SecureAction.invokeBundleEventHook(SecureAction.java:1179) >>>> [?:?] >>>> at >>>> org.apache.felix.framework.EventDispatcher.createWhitelistFromHooks(EventDispatcher.java:730) >>>> [?:?] >>>> at >>>> org.apache.felix.framework.EventDispatcher.fireBundleEvent(EventDispatcher.java:485) >>>> [?:?] >>>> at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4579) >>>> [?:?] >>>> at org.apache.felix.framework.Felix.stopBundle(Felix.java:2626) [?:?] >>>> at org.apache.felix.framework.Felix.uninstallBundle(Felix.java:2750) >>>> [?:?] >>>> at org.apache.felix.framework.BundleImpl.uninstall(BundleImpl.java:1055) >>>> [?:?] >>>> at >>>> org.apache.karaf.bundle.command.Uninstall.executeOnBundle(Uninstall.java:34) >>>> [15:org.apache.karaf.bundle.core:4.2.0] >>>> at >>>> org.apache.karaf.bundle.command.BundlesCommand.doExecute(BundlesCommand.java:65) >>>> [15:org.apache.karaf.bundle.core:4.2.0] >>>> at >>>> org.apache.karaf.bundle.command.BundlesCommand.execute(BundlesCommand.java:55) >>>> [15:org.apache.karaf.bundle.core:4.2.0] >>>> at >>>> org.apache.karaf.shell.impl.action.command.ActionCommand.execute(ActionCommand.java:84) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at >>>> org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at >>>> org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:571) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at >>>> org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:497) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:386) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:417) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) >>>> [33:org.apache.karaf.shell.core:4.2.0] >>>> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] >>>> at >>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) >>>> [?:?] >>>> at >>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) >>>> [?:?] >>>> at java.lang.Thread.run(Thread.java:745) [?:?] >>>> >>>> / >>>> /21:56:12.711 WARN [Camel (context-1) thread #1 - ShutdownTask] >>>> Interrupted while waiting during graceful shutdown, will force >>>> shutdown now. >>>> / >>>> >>>> I’m curious to why this exception occurs after exactly one minute, and >>>> the Camel Graceful Shutdown Timeout as specified is interrupted. >>>> >>>> I reproduced this on a clean Karaf 4.2.0 build with only the Camel >>>> feature installed to run the Camel Context. >>>> >>>> Any insight on why this might be happening? >>>> >>>> — >>>> >>>> Greetings, >>>> >>>> - Joery >>> >>> -- >>> Jean-Baptiste Onofré >>> [email protected] >>> http://blog.nanthrax.net >>> Talend - http://www.talend.com > > -- > Jean-Baptiste Onofré > [email protected] > http://blog.nanthrax.net > Talend - http://www.talend.com
