Hi, Let me check if we change the timeout on the Camel and Aries Blueprint sides.
It could be related to your inflight messages too, if they don't reach the onCompletion quickly. Regards JB On 03/06/2018 19:39, Joery Vreijsen wrote: > > 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 -- Jean-Baptiste Onofré [email protected] http://blog.nanthrax.net Talend - http://www.talend.com
