aries-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Michael Hirsch (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (ARIES-1240) TimeoutException when using Blueprint-Service-Proxy within ServiceTracker
Date Thu, 02 Oct 2014 18:34:34 GMT

     [ https://issues.apache.org/jira/browse/ARIES-1240?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Michael Hirsch updated ARIES-1240:
----------------------------------
    Affects Version/s: blueprint-core-1.4.2

> 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, blueprint-core-1.4.2
>         Environment: Felix OSGi container
> blueprint-core
> blueprint-contexts for providing and consuming OSGi services
> plain OSGi ServiceTracker
>            Reporter: Michael Hirsch
>         Attachments: TestApplication BugTesting Setup.jpg, TestApplication BugTesting
Sources.zip, ThreadDump.txt, blueprint_bugtesting_timeoutexception.zip
>
>
> *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}
> Console Output of the TimeoutException bug testing application you should see when you
running it
> {code}
> Starting Bug Testing ...
> Listening for transport dt_socket at address: 8001
> ____________________________
> Welcome to Apache Felix Gogo
> g! [Blueprint Extender: 1] INFO org.bugtesting.servicetracker.MyConsumerServiceTracker
- Before calling the blueprint proxy class com.sun.proxy.$Proxy1 within the ServiceTracker#ad
> dingService()
> [Blueprint Extender: 1] INFO org.bugtesting.servicetracker.MyConsumerServiceTracker -
After calling the blueprint proxy class com.sun.proxy.$Proxy1
> [Blueprint Extender: 1] INFO org.bugtesting.servicetracker.MyConsumerServiceTracker -
No timeout exception occured during invocation of the blueprint proxy, everything ok
> g!
> g! breakit
> [Gogo shell] INFO org.bugtesting.managedservice.provider.impl.BugTestingCommand - I'm
going to cause an timeout exception by re-register the org.bugtesting.managedservice.provider.
> MyManagedService service
> [Gogo shell] INFO org.bugtesting.managedservice.provider.impl.BugTestingCommand - unregistering
the org.bugtesting.managedservice.provider.MyManagedService service
> [Gogo shell] INFO org.bugtesting.managedservice.provider.impl.BugTestingCommand - registering
the org.bugtesting.managedservice.provider.MyManagedService service
> [Gogo shell] INFO org.bugtesting.servicetracker.MyConsumerServiceTracker - Before calling
the blueprint proxy class com.sun.proxy.$Proxy1 within the ServiceTracker#addingService()
> Waiting ............................................................................................................................................................................
> ....................................................................................................................................................................................
> ....................................................................................................................................................................................
> ...................................................................
> [Gogo shell] ERROR org.bugtesting.servicetracker.MyConsumerServiceTracker - Retrieved
a ServiceUnavailableException after 299983ms for filter (objectClass=org.bugtesting.managedser
> vice.provider.MyManagedService), which should not happen because the service is registered
but blueprints ReferenceRecipe has not been informed because I'm blocking the org.osgi.fr
> amework.ServiceEvent.REGISTERED for being delivered
> g!
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message