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
