Hello all; While working on FELIX-4955 <https://issues.apache.org/jira/browse/FELIX-4955> I think I'm facing an issue with the CircularReferenceTest in the SCR integration tests.
Unfortunately, I can not currently reproduces this problem in the scr maven/pax-exam environment. I can only (sometimes, not always) reproduce it under bndtools in the context of FELIX-4955. <https://issues.apache.org/jira/browse/FELIX-4955> The problem comes from the CircularReferenceTest.test_A11_B01_delayed_B_first() method: sometimes, this test fails because A component has been bound with two B instances and the following assertion fails: assertEquals( 1, a.getBs().size()); I'm showing now the original code from the scr integration test: @Test public void test_A11_B01_delayed_B_first() throws Exception { String componentNameA = "7.A.1.1.dynamic"; ComponentConfigurationDTO componentA = findComponentConfigurationByName( componentNameA, ComponentConfigurationDTO.SATISFIED ); String componentNameB = "7.B.0.1.dynamic"; final ComponentConfigurationDTO componentB = findComponentConfigurationByName( componentNameB, ComponentConfigurationDTO.SATISFIED ); ServiceReference[] serviceReferencesB = bundleContext.getServiceReferences( B.class.getName(), "(service.pid=" + componentNameB + ")" ); TestCase.assertEquals( 1, serviceReferencesB.length ); ServiceReference serviceReferenceB = serviceReferencesB[0]; Object serviceB = bundleContext.getService( serviceReferenceB ); assertNotNull( serviceB ); ServiceReference[] serviceReferencesA = bundleContext.getServiceReferences( A.class.getName(), "(service.pid=" + componentNameA + ")" ); TestCase.assertEquals( 1, serviceReferencesA.length ); ServiceReference serviceReferenceA = serviceReferencesA[0]; Object serviceA = bundleContext.getService( serviceReferenceA ); assertNotNull( serviceA ); delay(); A a = getServiceFromConfiguration(componentA, A.class); ------------------------------------------------------------------------------------------------------------ -> assertEquals( 1, a.getBs().size()); // this assert sometimes fails and a.getBs().size() returns 2 ------------------------------------------------------------------------------------------------------------ B b = getServiceFromConfiguration(componentB, B.class); assertEquals( 1, b.getAs().size() ); //disabling (removing the A service registration) and re-enabling will //result in a service event to B, so B will bind A. disableAndCheck(componentA); delay(); enableAndCheck(componentA.description); delay(); //new component.id, refetch configuration. componentA = findComponentConfigurationByName( componentNameA, ComponentConfigurationDTO.ACTIVE ); a = getServiceFromConfiguration(componentA, A.class); assertEquals( 1, a.getBs().size()); b = getServiceFromConfiguration(componentB, B.class); assertEquals( 1, b.getAs().size() ); } Sometimes, the a.getBs().size() method returns 2 and this test fails. I have tried to make a diagnostic and here is my current understanding of the problem: - I have added some logs in the A component like this: (a log is done when A.setB(B b) is called, and the stacktrace call is stored in "bsStackTraces" list: public class A { private List<B> bs = new ArrayList<B>(); private List<Exception> bsStackTraces = new ArrayList<>(); private boolean activated; private void activate(ComponentContext cc) { activated = true; } private void setB(B b) { System.out.println(Thread.currentThread().getName() + ":" + "A.setB(" + b + ")"); bs.add( b ); bsStackTraces.add(new Exception()); } private void unsetB(B b) { System.out.println(Thread.currentThread().getName() + ":" + "A.unsetB(" + b + ")"); bs.remove( b ); bsStackTraces.remove(bsStackTraces.size()-1); } public List<B> getBs() { return bs; } public void dumpStackTracesWhenBWasBound() { System.out.println("stack traces when B was bound:"); for (Exception e : bsStackTraces) { e.printStackTrace(); } } } - so, under bndtools (in the context of FELIX-4955 <https://issues.apache.org/jira/browse/FELIX-4955>), I see that A.setB(B b) is called twice: main:A.setB(org.apache.felix.scr.integration.components.circular.B@192d43ce) SCR Component Actor:A.setB(org.apache.felix.scr.integration.components.circular.B@192d43ce ) here, a.setB(B b) is first called from the main thread, and called a second time from the component actor thread. - now, from the test method, I have added this debug statement: @Test public void test_A11_B01_delayed_B_first() throws Exception { String componentNameA = "7.2.A.1.1.dynamic"; ComponentConfigurationDTO componentA = findComponentConfigurationByName( componentNameA, ComponentConfigurationDTO.SATISFIED ); String componentNameB = "7.2.B.0.1.dynamic"; final ComponentConfigurationDTO componentB = findComponentConfigurationByName( componentNameB, ComponentConfigurationDTO.SATISFIED ); ServiceReference[] serviceReferencesB = bundleContext.getServiceReferences( B.class.getName(), "(service.pid=" + componentNameB + ")" ); TestCase.assertEquals( 1, serviceReferencesB.length ); ServiceReference serviceReferenceB = serviceReferencesB[0]; Object serviceB = bundleContext.getService( serviceReferenceB ); assertNotNull( serviceB ); ServiceReference[] serviceReferencesA = bundleContext.getServiceReferences( A.class.getName(), "(service.pid=" + componentNameA + ")" ); TestCase.assertEquals( 1, serviceReferencesA.length ); ServiceReference serviceReferenceA = serviceReferencesA[0]; Object serviceA = bundleContext.getService( serviceReferenceA ); assertNotNull( serviceA ); delay(); A a = getServiceFromConfiguration(componentA, A.class); // TODO remove if (a.getBs().size() != 1) { System.err.println("detected problem ..."); a.dumpStackTracesWhenBWasBound(); } assertEquals( 1, a.getBs().size()); ... so, when a.getBs().size() does not return 1, we call "a.dumpStackTracesWhenBWasBound()" and here are those stacktraces: stack traces when B was bound: java.lang.Exception at org.apache.felix.scr.integration.components.circular.A.setB(A.java:48) at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) 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:347) at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:247) at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:343) at org.apache.felix.framework.Felix.getService(Felix.java:3692) at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:470) at org.apache.felix.scr.integration.CircularReferenceTest.test_A11_B01_delayed_B_first(CircularReferenceTest.java:255) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at junit.framework.TestCase.runTest(TestCase.java:176) at junit.framework.TestCase.runBare(TestCase.java:141) at junit.framework.TestResult$1.protect(TestResult.java:122) at junit.framework.TestResult.runProtected(TestResult.java:142) at junit.framework.TestResult.run(TestResult.java:125) at junit.framework.TestCase.run(TestCase.java:129) at junit.framework.TestSuite.runTest(TestSuite.java:255) at junit.framework.TestSuite.run(TestSuite.java:250) at junit.framework.TestSuite.runTest(TestSuite.java:255) at junit.framework.TestSuite.run(TestSuite.java:250) at aQute.junit.Activator.test(Activator.java:303) at aQute.junit.Activator.run(Activator.java:128) at aQute.launcher.Launcher$5.call(Launcher.java:1175) at aQute.launcher.Launcher$5.call(Launcher.java:1173) at aQute.launcher.Launcher.run(Launcher.java:278) at aQute.launcher.Launcher.main(Launcher.java:87) java.lang.Exception at org.apache.felix.scr.integration.components.circular.A.setB(A.java:48) at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) 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) So, in the first stacktrace, a.setB(B b) is called when the test_A11_B01_delayed_B_first method calls "Object serviceA = bundleContext.getService( serviceReferenceA );" which then calls SingleComponentManager.createComponent() method. And that method then calls createImplementationObject which then opens the DependencyManager, which then calls A.bind(A b). But now in the second stacktrace (which comes from the componen actor thread), "A.setB(B b)" is called a second time because in the first stacktrace, the SingleComponentManager.createComponent() method has schedule a task in the actor thread like this: if ( activator != null ) { activator.missingServicePresent( getServiceReference() ); } and the missingServicePresent schedules in the ComponentActor thread a task which then calls invokeBindLate, which then finally calls a second time the A.bind(B b) method. Am I correct with this diagnostic ? Should I open a jira issue ? thank you; /Pierre
