felix-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Pierre De Rop (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (FELIX-4984) Issues in CircularReferenceTest
Date Tue, 08 Sep 2015 20:39:46 GMT

    [ https://issues.apache.org/jira/browse/FELIX-4984?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14735567#comment-14735567
] 

Pierre De Rop commented on FELIX-4984:
--------------------------------------

Just commited in revision 1701869 org.apache.felix.scr.integration.Felix4984Test.java, which
seems to reproduce the issue in the felix-trunk/scr project.

The problem is reproduced in DEBUG level.
To reproduce this issue, you can edit the pom.xml and modify the line 277, like this:

{code}
                    <includes>
                        <include>**/integration/Felix4984Test.java</include>
                    </includes>
{code}

instead of 

{code}
                    <includes>
                        <include>**/integration/**</include>
                    </includes>
{code}

then type mvn clean install > /tmp/log 2>&1

You will normally see the test fail with a log that displays "detected problem ..." followed
by the two following stack traces, where the A.setB(B b) method is called twice:

{code}
log level: 2 D=22:16:51,318 T=Thread[RMI TCP Connection(1)-139.54.130.12,5,RMI Runtime]: detected
problem ...
log level: 2 D=22:16:51,318 T=Thread[RMI TCP Connection(1)-139.54.130.12,5,RMI Runtime]: Stack
traces when B was bound:
log level: 2 D=22:16:51,318 T=Thread[RMI TCP Connection(1)-139.54.130.12,5,RMI Runtime]: stack
trace:
java.lang.Exception
	at org.apache.felix.scr.integration.components.felix4984.A.setB(A.java:48)
	at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.felix.scr.impl.helper.BaseMethod.invokeMethod(BaseMethod.java:222)
	at org.apache.felix.scr.impl.helper.BaseMethod.access$500(BaseMethod.java:37)
	at org.apache.felix.scr.impl.helper.BaseMethod$Resolved.invoke(BaseMethod.java:615)
	at org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:499)
	at org.apache.felix.scr.impl.helper.BindMethod.invoke(BindMethod.java:41)
	at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1653)
	at org.apache.felix.scr.impl.manager.DependencyManager.open(DependencyManager.java:1491)
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:265)
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:113)
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:847)
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:814)
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:763)
	at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:343)
	at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:243)
	at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:351)
	at org.apache.felix.framework.Felix.getService(Felix.java:3671)
	at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:472)
	at org.apache.felix.scr.integration.Felix4984Test.test_A11_B0n_delayed_B_first_ABoundToAtMostOneB(Felix4984Test.java:59)
	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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
	at org.ops4j.pax.exam.invoker.junit.internal.ContainerTestRunner.runChild(ContainerTestRunner.java:67)
	at org.ops4j.pax.exam.invoker.junit.internal.ContainerTestRunner.runChild(ContainerTestRunner.java:37)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138)
	at org.ops4j.pax.exam.invoker.junit.internal.JUnitProbeInvoker.invokeViaJUnit(JUnitProbeInvoker.java:123)
	at org.ops4j.pax.exam.invoker.junit.internal.JUnitProbeInvoker.findAndInvoke(JUnitProbeInvoker.java:96)
	at org.ops4j.pax.exam.invoker.junit.internal.JUnitProbeInvoker.call(JUnitProbeInvoker.java:72)
	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.ops4j.pax.swissbox.framework.RemoteFrameworkImpl.invokeMethodOnService(RemoteFrameworkImpl.java:420)
	at org.ops4j.pax.swissbox.framework.RemoteFrameworkImpl.invokeMethodOnService(RemoteFrameworkImpl.java:393)
	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 sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:322)
	at sun.rmi.transport.Transport$2.run(Transport.java:202)
	at sun.rmi.transport.Transport$2.run(Transport.java:199)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:198)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:567)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:828)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.access$400(TCPTransport.java:619)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$1.run(TCPTransport.java:684)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$1.run(TCPTransport.java:681)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:681)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

log level: 2 D=22:16:51,318 T=Thread[RMI TCP Connection(1)-139.54.130.12,5,RMI Runtime]: stack
trace:
java.lang.Exception
	at org.apache.felix.scr.integration.components.felix4984.A.setB(A.java:48)
	at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.felix.scr.impl.helper.BaseMethod.invokeMethod(BaseMethod.java:222)
	at org.apache.felix.scr.impl.helper.BaseMethod.access$500(BaseMethod.java:37)
	at org.apache.felix.scr.impl.helper.BaseMethod$Resolved.invoke(BaseMethod.java:615)
	at org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:499)
	at org.apache.felix.scr.impl.helper.BindMethod.invoke(BindMethod.java:41)
	at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1653)
	at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1629)
	at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:370)
	at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethodLate(DependencyManager.java:1573)
	at org.apache.felix.scr.impl.ComponentRegistry$1.run(ComponentRegistry.java:570)
	at org.apache.felix.scr.impl.ComponentActorThread.run(ComponentActorThread.java:99)
	at java.lang.Thread.run(Thread.java:745)
{code}

Again, my opinion is the following:

- A.setB(B b) is first called when we dereference the A service from Felix4984Test.java, line
59 (see the first stacktrace, above).
- Then A.setB(B b) is called a second time because previously, when the B service reference
was dereferenced from Felix4984Test.java, line 53, then a task was internally scheduled in
the ComponentActor thread, which calls invokeBindMethodLate (see the second stacktrace).

So, it looks like there is a concurrency hole in the invokeBindMethodLate method ?





> Issues in CircularReferenceTest
> -------------------------------
>
>                 Key: FELIX-4984
>                 URL: https://issues.apache.org/jira/browse/FELIX-4984
>             Project: Felix
>          Issue Type: Bug
>          Components: Declarative Services (SCR)
>            Reporter: Pierre De Rop
>            Priority: Minor
>             Fix For: scr-2.0.2
>
>         Attachments: felix-4984.diff, org.apache.felix.scr.integration.CircularReferenceTest.test_A11_B0n_delayed_B_first.log,
org.apache.felix.scr.integration.Felix4984Test.test_A11_B0n_delayed_B_first_ABoundToAtMostOneB-NPE-with_patch.log.gz,
org.apache.felix.scr.integration.Felix4984Test.test_A11_B0n_delayed_B_first_ABoundToAtMostOneB.log
>
>
> This issue is described in the dev mailing list, in http://www.mail-archive.com/dev@felix.apache.org/msg37281.html
> while working on FELIX-4955, I sometimes have the CircularReferenceTest failing.
> Everything is located in my sandbox, in http://svn.apache.org/repos/asf/felix/sandbox/pderop/dependencymanager.ds/
> To reproduce the test:
> install eclipse Mars
> install latest bndtools using "install new software" from Eclipse, and then add latest
stable release from http://dl.bintray.com/bndtools/bndtools/latest/
> install a java8 runtime (I'm using oracle java8 1.8.0_45, 64 bit version). The whole
new dependencymanager.ds project is intented to be build in java8.
> checkout my sandbox:
> $ svn checkout http://svn.apache.org/repos/asf/felix/sandbox/pderop/dependencymanager.ds
> go to "dependencymanager.ds" directory:
> $ cd dependencymanager.ds/
> due to a pending issue, you have to first build the DM bnd annotation plugin before importing
the project into eclipse. to do so, just type:
> $ ./gradlew org.apache.felix.dependencymanager.annotation:jar
> now launch eclipse and use the the dependencymanager/ds directory as the workspace dir
for Eclipse.
> switch to BndTools perpective.
> import the bndtools project into eclipse: Import -> Existing Projects into Workspace
-> Browse -> select dependencymanager.ds directory (it is proposed by default).
> normally, and hopefully, everything should compile fine. Junit tests are left in org.apache.felix.dependencymanager.ds/
directory and integration tests are located in org.apache.felix.dependencymanager.ds.itest/
directory.
> Open under Eclipse the org.apache.felix.dependencymanager.ds.itest/src/org/apache/felix/scr/integration/CircularReferenceTest.java
> I slightly modified it in order to dump stack traces when A component is bound multiple
times to the same B instance.
> (I believe that only delayed components are concerned by the issue).
> For example, in the test_A11_B0n_delayed_A_first() method, I added a call to "assertABoundToOneB(a)"
like this:
> {code}
>     @Test
>     public void test_A11_B0n_delayed_A_first() throws InvalidSyntaxException
>     {
>         String componentNameA = "4.1.A.1.1.dynamic";
>         final ComponentConfigurationDTO componentA = findComponentConfigurationByName(
componentNameA, ComponentConfigurationDTO.SATISFIED );
>         String componentNameB = "4.1.B.0.n.dynamic";
>         final ComponentConfigurationDTO componentB = findComponentConfigurationByName(
componentNameB, ComponentConfigurationDTO.SATISFIED );
>         delay();
>         A a = getServiceFromConfiguration(componentA, A.class);
>         assertABoundToOneB(a);
>         delay(); //async binding of a to b after circular ref detected
>         B b = getServiceFromConfiguration(componentB, B.class);
>         assertEquals( 1, b.getAs().size() );
>     }
> {code}
> the "assertABoundToOneB(a)" call does this:
> {code}
>     private void assertABoundToOneB(A a) {
>         if (a.getBs().size() != 1) {
>             System.err.println("detected problem ...");
>             a.dumpStackTracesWhenBWasBound();
>         }
>         assertEquals( 1, a.getBs().size());
>     }
> {code}
> And stacktraces will be dumped in order to determine why A was bound two times to the
same B instance.
> it's possible that you have to run several times the "CircularReferenceTest" test before
having a failure (and some stacktraces).
> Thanks.



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

Mime
View raw message