[
https://issues.apache.org/jira/browse/ARIES-1991?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
nizar.ben.mansour updated ARIES-1991:
-------------------------------------
Affects Version/s: blueprint-core-1.10.2
> Unpredictible InterruptedException when starting bundles
> --------------------------------------------------------
>
> Key: ARIES-1991
> URL: https://issues.apache.org/jira/browse/ARIES-1991
> Project: Aries
> Issue Type: Bug
> Components: Blueprint
> Affects Versions: blueprint-core-1.10.2
> Reporter: nizar.ben.mansour
> Priority: Critical
>
> Hello,
> I'm facing an issue that happens sometimes when starting my bundles that
> occurs only after TimeoutException (i think it relates to this issue
> https://issues.apache.org/jira/browse/ARIES-1990) .
>
> Here is the full log:
>
> {code:java}
>
> Attempting to start CamelContext: MappingCustomerIdLDdnContextAttempting to
> start CamelContext: MappingCustomerIdLDdnContext2020-07-20T19:29:05,304 |
> INFO | Blueprint Event Dispatcher: 1 | BlueprintCamelContext |
> 118 - org.apache.camel.camel-blueprint - 2.23.4 | Apache Camel 2.23.4
> (CamelContext: MappingCustomerIdLDdnContext) is
> starting2020-07-20T19:29:05,304 | INFO | Blueprint Event Dispatcher: 1 |
> ManagedManagementStrategy | 120 - org.apache.camel.camel-core - 2.23.4
> | JMX is enabled2020-07-20T19:30:05,304 | WARN | FelixStartLevel |
> BlueprintEventDispatcher | 100 - org.apache.aries.blueprint.core -
> 1.10.2 | Listener timed out, will be
> ignoredjava.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:185)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper$15.call(ScheduledExecutorServiceWrapper.java:446)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.utils.threading.RWLock.runReadOperation(RWLock.java:33)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper.runUnlessShutdown(ScheduledExecutorServiceWrapper.java:443)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper.invokeAny(ScheduledExecutorServiceWrapper.java:180)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintEventDispatcher.callListener(BlueprintEventDispatcher.java:188)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintEventDispatcher.callListeners(BlueprintEventDispatcher.java:178)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintEventDispatcher.blueprintEvent(BlueprintEventDispatcher.java:133)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:447)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:298)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:311)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:280)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:276)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:266)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:500)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:433)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$AbstractTracked.track(BundleHookBundleTracker.java:725)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.bundleChanged(BundleHookBundleTracker.java:463)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$BundleEventHook.event(BundleHookBundleTracker.java:422)
> [100:org.apache.aries.blueprint.core:1.10.2] 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.startBundle(Felix.java:2174) [?:?]
> at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1373)
> [?:?] at
> org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)
> [?:?] at java.lang.Thread.run(Thread.java:748) [?:?]2020-07-20T19:30:08,049
> | INFO | Blueprint Event Dispatcher: 1 | BlueprintCamelContext |
> 118 - org.apache.camel.camel-blueprint - 2.23.4 | Apache Camel 2.23.4
> (CamelContext: MappingCustomerIdLDdnContext) is shutting
> down2020-07-20T19:30:08,065 | INFO | Blueprint Event Dispatcher: 1 |
> BlueprintCamelContext | 118 - org.apache.camel.camel-blueprint -
> 2.23.4 | Apache Camel 2.23.4 (CamelContext: MappingCustomerIdLDdnContext)
> uptime 1 minute2020-07-20T19:30:08,066 | INFO | Blueprint Event Dispatcher:
> 1 | BlueprintCamelContext | 118 - org.apache.camel.camel-blueprint
> - 2.23.4 | Apache Camel 2.23.4 (CamelContext: MappingCustomerIdLDdnContext)
> is shutdown in 0.017 seconds2020-07-20T19:30:08,066 | WARN | Blueprint Event
> Dispatcher: 1 | BlueprintCamelStateService | 118 -
> org.apache.camel.camel-blueprint - 2.23.4 | Changing Camel state for bundle
> 86 to Failure2020-07-20T19:30:08,066 | ERROR | Blueprint Event Dispatcher: 1
> | BlueprintCamelContext | 118 - org.apache.camel.camel-blueprint -
> 2.23.4 | Error occurred during starting CamelContext:
> MappingCustomerIdLDdnContextorg.apache.camel.RuntimeCamelException:
> java.lang.RuntimeException: java.lang.InterruptedException at
> org.apache.camel.util.ObjectHelper.wrapRuntimeCamelException(ObjectHelper.java:1826)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext.getTypeConverter(DefaultCamelContext.java:2569)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext.getTypeConverterRegistry(DefaultCamelContext.java:2590)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext.forceLazyInitialization(DefaultCamelContext.java:4097)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext.doStartCamel(DefaultCamelContext.java:3376)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext$4.call(DefaultCamelContext.java:3247)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext$4.call(DefaultCamelContext.java:3243)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext.doWithDefinedClassLoader(DefaultCamelContext.java:3266)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext.doStart(DefaultCamelContext.java:3243)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.support.ServiceSupport.start(ServiceSupport.java:72)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.impl.DefaultCamelContext.start(DefaultCamelContext.java:3159)
> ~[120:org.apache.camel.camel-core:2.23.4] at
> org.apache.camel.blueprint.BlueprintCamelContext.start(BlueprintCamelContext.java:255)
> ~[118:org.apache.camel.camel-blueprint:2.23.4] at
> org.apache.camel.blueprint.BlueprintCamelContext.maybeStart(BlueprintCamelContext.java:297)
> ~[118:org.apache.camel.camel-blueprint:2.23.4] at
> org.apache.camel.blueprint.BlueprintCamelContext.blueprintEvent(BlueprintCamelContext.java:188)
> [118:org.apache.camel.camel-blueprint:2.23.4] at
> org.apache.aries.blueprint.container.BlueprintEventDispatcher$3.call(BlueprintEventDispatcher.java:190)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintEventDispatcher$3.call(BlueprintEventDispatcher.java:188)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [?:?] at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [?:?] at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [?:?] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [?:?] at java.lang.Thread.run(Thread.java:748) [?:?]Caused by:
> java.lang.RuntimeException: java.lang.InterruptedException at
> org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:369)
> ~[?:?] at org.apache.felix.framework.Felix.getService(Felix.java:3737)
> ~[?:?] at
> org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:470)
> ~[?:?] at
> org.apache.camel.core.osgi.OsgiTypeConverter.addingService(OsgiTypeConverter.java:69)
> ~[?:?] at
> org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)
> ~[?:?] at
> org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)
> ~[?:?] at
> org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)
> ~[?:?] at
> org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)
> ~[?:?] at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318)
> ~[?:?] at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261)
> ~[?:?] at
> org.apache.camel.core.osgi.OsgiTypeConverter.doStart(OsgiTypeConverter.java:101)
> ~[?:?] at
> org.apache.camel.support.ServiceSupport.start(ServiceSupport.java:72) ~[?:?]
> at org.apache.camel.util.ServiceHelper.startService(ServiceHelper.java:75)
> ~[?:?] at
> org.apache.camel.impl.DefaultCamelContext.doAddService(DefaultCamelContext.java:1486)
> ~[?:?] at
> org.apache.camel.impl.DefaultCamelContext.addService(DefaultCamelContext.java:1446)
> ~[?:?] at
> org.apache.camel.impl.DefaultCamelContext.getTypeConverter(DefaultCamelContext.java:2567)
> ~[?:?] ... 24 moreCaused by: java.lang.InterruptedException at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1302)
> ~[?:?] at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
> ~[?:?] at
> org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:365)
> ~[?:?] at org.apache.felix.framework.Felix.getService(Felix.java:3737)
> ~[?:?] at
> org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:470)
> ~[?:?] at
> org.apache.camel.core.osgi.OsgiTypeConverter.addingService(OsgiTypeConverter.java:69)
> ~[?:?] at
> org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)
> ~[?:?] at
> org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)
> ~[?:?] at
> org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)
> ~[?:?] at
> org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)
> ~[?:?] at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318)
> ~[?:?] at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261)
> ~[?:?] at
> org.apache.camel.core.osgi.OsgiTypeConverter.doStart(OsgiTypeConverter.java:101)
> ~[?:?] at
> org.apache.camel.support.ServiceSupport.start(ServiceSupport.java:72) ~[?:?]
> at org.apache.camel.util.ServiceHelper.startService(ServiceHelper.java:75)
> ~[?:?] at
> org.apache.camel.impl.DefaultCamelContext.doAddService(DefaultCamelContext.java:1486)
> ~[?:?] at
> org.apache.camel.impl.DefaultCamelContext.addService(DefaultCamelContext.java:1446)
> ~[?:?] at
> org.apache.camel.impl.DefaultCamelContext.getTypeConverter(DefaultCamelContext.java:2567)
> ~[?:?] ... 24 more2020-07-20T19:30:08,070 | INFO | Blueprint Event
> Dispatcher: 1 | BlueprintCamelContext | 118 -
> org.apache.camel.camel-blueprint - 2.23.4 | Attempting to start CamelContext:
> mappingCustomerIdLdnContext2020-07-20T19:30:08,071 | INFO | Blueprint Event
> Dispatcher: 1 | BlueprintCamelContext | 118 -
> org.apache.camel.camel-blueprint - 2.23.4 | Apache Camel 2.23.4
> (CamelContext: mappingCustomerIdLdnContext) is
> starting2020-07-20T19:30:08,071 | INFO | Blueprint Event Dispatcher: 1 |
> ManagedManagementStrategy | 120 - org.apache.camel.camel-core - 2.23.4
> | JMX is enabled2020-07-20T19:30:29,223 | INFO | activator-1-thread-1 |
> ServiceComponentRuntimeMBeanImpl | 181 - org.apache.karaf.scr.management -
> 4.2.6 | Activating the Apache Karaf ServiceComponentRuntime
> MBean2020-07-20T19:31:05,306 | WARN | FelixStartLevel |
> BlueprintEventDispatcher | 100 - org.apache.aries.blueprint.core -
> 1.10.2 | Listener timed out, will be
> ignoredjava.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:185)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper$15.call(ScheduledExecutorServiceWrapper.java:446)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.utils.threading.RWLock.runReadOperation(RWLock.java:33)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper.runUnlessShutdown(ScheduledExecutorServiceWrapper.java:443)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.utils.threading.ScheduledExecutorServiceWrapper.invokeAny(ScheduledExecutorServiceWrapper.java:180)
> ~[100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintEventDispatcher.callListener(BlueprintEventDispatcher.java:188)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintEventDispatcher.callListeners(BlueprintEventDispatcher.java:178)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintEventDispatcher.blueprintEvent(BlueprintEventDispatcher.java:133)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:447)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:298)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:311)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:280)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:276)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:266)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:500)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:433)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$AbstractTracked.track(BundleHookBundleTracker.java:725)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.bundleChanged(BundleHookBundleTracker.java:463)
> [100:org.apache.aries.blueprint.core:1.10.2] at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$BundleEventHook.event(BundleHookBundleTracker.java:422)
> [100:org.apache.aries.blueprint.core:1.10.2] 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.startBundle(Felix.java:2174) [?:?]
> at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1373)
> [?:?] at
> org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)
> [?:?] at java.lang.Thread.run(Thread.java:748) [?:?]2020-07-20T19:31:11,612
> | WARN | Blueprint Event Dispatcher: 1 | DefaultTypeConverter |
> 120 - org.apache.camel.camel-core - 2.23.4 | Overriding type converter from:
> {code}
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
