I checked out your sandbox…

I changed to java 1.7, is there a reason you want 1.8?

I haven’t remembered how to get the tests to run in eclipse yet, but on java 7 
running gradlew in the tests all the tests pass; I’ve tried 15 or 20 times by 
now.

Can you collect the debug logging output from a failing run and get it to me 
somehow?  Maybe I can decipher what is going wrong.

thanks
david jencks

> On Jul 30, 2015, at 3:16 PM, Pierre De Rop <[email protected]> wrote:
> 
> Hi David,
> 
> Thanks, I just created the FELIX-4984
> <https://issues.apache.org/jira/browse/FELIX-4984> issue and described
> everything in it.
> 
> I have not yet modified the SCR core. I only ported SCR project to bndtools
> and integrated it in the DM project. what I did so far is that I reworked
> the SCR tests in order to not use anymore pax-exam and simply rely on
> BndTools integration tests.
> 
> So unless I did a mistake while reworking the tests, I think it's worth
> that you take a look in case there is really a pending bug somewhere that
> is sometimes reproduced by the CircularReferenceTest.
> (I can't reproduce it using maven from the current felix-trunk/scr/).
> 
> In the meantime, I will also continue to investigate.
> 
> thank you.
> /Pierre
> 
> 
> 
> On Thu, Jul 30, 2015 at 6:49 AM, David Jencks <[email protected]>
> wrote:
> 
>> Hi Pierre,
>> 
>> Please open a jira.  I will try to look into this soon.
>> 
>> I haven’t had much time lately but I would like to move the existing
>> feliix DS to bndtools no matter whether your idea of making DM support DS
>> works or not :-).  Is your current work available somewhere?
>> 
>> thanks
>> david jencks
>> 
>>> On Jul 29, 2015, at 6:53 PM, Pierre De Rop <[email protected]>
>> wrote:
>>> 
>>> 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
>> 
>> 

Reply via email to