Michael Hirsch created ARIES-1240:
-------------------------------------
Summary: TimeoutException when using Blueprint-Service-Proxy
within ServiceTracker
Key: ARIES-1240
URL: https://issues.apache.org/jira/browse/ARIES-1240
Project: Aries
Issue Type: Bug
Components: Blueprint
Affects Versions: blueprint-core-1.2.0
Environment: Felix OSGi container
blueprint-core
blueprint-contexts for providing and consuming OSGi services
plain OSGi ServiceTracker
Reporter: Michael Hirsch
*Environment Setup*
In a large/complex OSGi environment we are using blueprint for providing and
consuming OSGi services in combination with plain OSGi to register services and
consume using ServiceTracker.
*Failure Description*
It occurs that when an underlying OSGi service will be unregister and register
again (e.g. by configuration updates) blueprint unregisters and re-register all
depending services which is correct but it will causing that when re-register
OSGi blueprint the services in the blueprint context get also registered which
might be an ServiceTracker is tracking these services.
In case the ServiceTracker using an Blueprint-Service-Proxy within the
_addingService()_ method which has been re-registered in the registration chain
the Blueprint-Service is running into a TimeoutException caused that
ServiceListenerEvents are synchronous delivered and the ServiceTracker is
running in the same thread as the blueprints ReferenceRecipe will be notified
about the re-registration.
This issue only occurs with the blueprint-core version *1.2.0* which is related
to the bug fix change ARIES-896 where the ServiceListener events has been
handled in a blueprint executor.
{quote}
Aries-896: Undo threading changes to
AbstractServiceReferenceRecipe.serviceChanged() since they can result in
unbind-methods being driven with invalid service references.
{quote}
Without this change this error does not occur.
*Reproduce / Verification*
I attached a complete thread dump showing the the blueprint proxy is waiting
for the ServiceReference
Thread Dump, the whole thread dump is attached.
{code}
"Gogo shell" daemon prio=6 tid=0x000000000e4eb800 nid=0x2a88 in Object.wait()
[0x00000000117db000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000007d6018608> (a java.lang.Object)
at
org.apache.aries.blueprint.container.ReferenceRecipe.getService(ReferenceRecipe.java:206)
- locked <0x00000007d6018608> (a java.lang.Object)
at
org.apache.aries.blueprint.container.ReferenceRecipe.access$000(ReferenceRecipe.java:55)
at
org.apache.aries.blueprint.container.ReferenceRecipe$ServiceDispatcher.call(ReferenceRecipe.java:294)
at
org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:54)
at
org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:119)
at com.sun.proxy.$Proxy1.doSomething(Unknown Source)
at
org.bugtesting.provider.impl.MyServiceImpl.callManagedServiceProvider(MyServiceImpl.java:18)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:54)
at
org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:119)
at com.sun.proxy.$Proxy0.callManagedServiceProvider(Unknown Source)
at
org.bugtesting.servicetracker.MyConsumerServiceTracker.addingService(MyConsumerServiceTracker.java:50)
at
org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:932)
at
org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:864)
at
org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)
at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)
at
org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:894)
at
org.apache.felix.framework.util.EventDispatcher.invokeServiceListenerCallback(EventDispatcher.java:943)
at
org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:794)
at
org.apache.felix.framework.util.EventDispatcher.fireServiceEvent(EventDispatcher.java:544)
at org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:4425)
at org.apache.felix.framework.Felix.registerService(Felix.java:3429)
at
org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:346)
at
org.apache.aries.blueprint.container.BlueprintContainerImpl.registerService(BlueprintContainerImpl.java:552)
at
org.apache.aries.blueprint.container.ServiceRecipe.register(ServiceRecipe.java:191)
at
org.apache.aries.blueprint.container.BlueprintContainerImpl.notifySatisfaction(BlueprintContainerImpl.java:837)
- locked <0x00000007d5fc17e8> (a
org.apache.aries.blueprint.container.ServiceRecipe)
at
org.apache.aries.blueprint.container.AbstractServiceReferenceRecipe.setSatisfied(AbstractServiceReferenceRecipe.java:424)
at
org.apache.aries.blueprint.container.AbstractServiceReferenceRecipe.serviceAdded(AbstractServiceReferenceRecipe.java:366)
at
org.apache.aries.blueprint.container.AbstractServiceReferenceRecipe.serviceChanged(AbstractServiceReferenceRecipe.java:346)
at
org.apache.felix.framework.util.EventDispatcher.invokeServiceListenerCallback(EventDispatcher.java:943)
at
org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:794)
at
org.apache.felix.framework.util.EventDispatcher.fireServiceEvent(EventDispatcher.java:544)
at org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:4425)
at org.apache.felix.framework.Felix.registerService(Felix.java:3429)
at
org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:346)
at
org.apache.aries.blueprint.container.BlueprintContainerImpl.registerService(BlueprintContainerImpl.java:552)
at
org.apache.aries.blueprint.container.ServiceRecipe.register(ServiceRecipe.java:191)
at
org.apache.aries.blueprint.container.BlueprintContainerImpl.notifySatisfaction(BlueprintContainerImpl.java:837)
- locked <0x00000007d6018a88> (a
org.apache.aries.blueprint.container.ServiceRecipe)
{code}
Futheremore there is an test application (OSGi container) where this bug can be
reproduced within the test application there is also an how to text file how to
re-produce the bug.
{quote}
#1 Start Container of the TestApplication with bin/start.bat
#2 You'll see log information that the ServiceTracker-AddingService has been
called
and using the Blueprint-Proxy (MyService) and everything is ok
#3 Use the command 'breakit' (without quotes) to re-register the underlying
managed-service (MyManagedService).
After 10seconds (blueprint-reference-timeout, but sometimes the defined
timeout does not work
and you need to wait 5minutes - default timeout) you see that the MyService
is running into a timeout
#4 verify the bug with diffrent blueprint-core versions by replacing the
"org.apache.aries.blueprint.core-1.2.0.jar" bundle
with another one. Before 1.2.0 version the TimeoutException will not occure
{quote}
--
This message was sent by Atlassian JIRA
(v6.2#6252)
