nizar.ben.mansour created FELIX-6309:
----------------------------------------
Summary: Unpredictible InterruptedException when starting bundles
Key: FELIX-6309
URL: https://issues.apache.org/jira/browse/FELIX-6309
Project: Felix
Issue Type: Bug
Affects Versions: framework-5.6.12
Reporter: nizar.ben.mansour
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}
| 118 - org.apache.camel.camel-blueprint - 2.23.4 | Attempting to start
CamelContext: MappingCustomerIdLDdnContext | 118 -
org.apache.camel.camel-blueprint - 2.23.4 | Attempting 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 enabled{code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
