Hi Joe, Thanks for the information. There are four blueprint queiesce tests all bundled up into QuiesceBlueprintTest. Emily reported previously that she was seeing errors in testMultiBundleQuiesce. My change in ARIES-412 was for this test, as I managed to reproduce the failure. However, the test you're reporting as failing below is a different one - testMultiRequestQuiesce. I'm not seeing this failing on my machine, with or without the fix, so I didn't put in the corresponding change for that one.
I have very strong suspicions that this is a test timing issue, which isn't ideal :( I can suggest a patch for this... however as I can't reproduce it myself, would it be possible to try it on an affected machine? Thanks, Hannah On 21 September 2010 15:24, Joe Bohn <[email protected]> wrote: > > It may not be directly related to Hannah's changes or fix ... but I just > hit another failure in the QuiesceBlueprintTest even with the fix for > ARIES-412 applied. Also, I don't know how consistent this failure is since > this is the first time I built with the fix and a clean repo ... but here is > some information I see in the output log: > > > [System Bundle Shutdown] DEBUG > org.apache.aries.blueprint.container.BlueprintEventDispatcher - Sending > blueprint container event BlueprintEvent[type=DESTROYING] for bundle > org.apache.aries.blueprint.testquiescebundle > [System Bundle Shutdown] DEBUG > org.ops4j.pax.swissbox.extender.BundleWatcher - Releasing bundle > [org.apache.aries.blueprint.testquiescebundle] > [Framework Event Dispatcher] DEBUG org.apache.aries.blueprint - > FrameworkEvent ERROR > java.lang.IllegalStateException: The service has been unregistered > at > org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:204) > at > org.apache.aries.blueprint.container.BlueprintContainerImpl.destroy(BlueprintContainerImpl.java:800) > at > org.apache.aries.blueprint.container.BlueprintExtender.destroyContext(BlueprintExtender.java:221) > at > org.apache.aries.blueprint.container.BlueprintExtender.bundleChanged(BlueprintExtender.java:213) > at > org.apache.aries.blueprint.container.BlueprintExtender$BlueprintBundleTrackerCustomizer.modifiedBundle(BlueprintExtender.java:402) > at > org.apache.aries.util.tracker.InternalRecursiveBundleTracker.modifiedBundle(InternalRecursiveBundleTracker.java:89) > at > org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:453) > at > org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:237) > at > org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:413) > at > org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:916) > at > org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:220) > at > org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:149) > at > org.eclipse.osgi.framework.internal.core.Framework.publishBundleEventPrivileged(Framework.java:1350) > at > org.eclipse.osgi.framework.internal.core.Framework.publishBundleEvent(Framework.java:1301) > at > org.eclipse.osgi.framework.internal.core.BundleHost.stopWorker(BundleHost.java:470) > at > org.eclipse.osgi.framework.internal.core.AbstractBundle.suspend(AbstractBundle.java:546) > at > org.eclipse.osgi.framework.internal.core.Framework.suspendBundle(Framework.java:1098) > at > org.eclipse.osgi.framework.internal.core.StartLevelManager.decFWSL(StartLevelManager.java:593) > at > org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:261) > at > org.eclipse.osgi.framework.internal.core.StartLevelManager.shutdown(StartLevelManager.java:216) > at > org.eclipse.osgi.framework.internal.core.InternalSystemBundle.suspend(InternalSystemBundle.java:266) > at > org.eclipse.osgi.framework.internal.core.Framework.shutdown(Framework.java:685) > at > org.eclipse.osgi.framework.internal.core.Framework.close(Framework.java:583) > at > org.eclipse.osgi.framework.internal.core.InternalSystemBundle$1.run(InternalSystemBundle.java:243) > at java.lang.Thread.run(Thread.java:637) > [System Bundle Shutdown] DEBUG > org.apache.aries.blueprint.container.BlueprintExtender - Destroying > BlueprintContainer for bundle org.apache.aries.blueprint.testbundlea > [Framework Event Dispatcher] DEBUG > org.apache.aries.blueprint.testquiescebundle - BundleEvent STOPPED > [System Bundle Shutdown] DEBUG > org.apache.aries.blueprint.container.BlueprintEventDispatcher - Sending > blueprint container event BlueprintEvent[type=DESTROYING] for bundle > org.apache.aries.blueprint.testbundlea > [Framework Event Dispatcher] DEBUG org.apache.aries.blueprint - > FrameworkEvent ERROR > java.lang.IllegalStateException: The service has been unregistered > at > org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:204) > at > org.apache.aries.blueprint.container.BlueprintContainerImpl.destroy(BlueprintContainerImpl.java:800) > at > org.apache.aries.blueprint.container.BlueprintExtender.destroyContext(BlueprintExtender.java:221) > at > org.apache.aries.blueprint.container.BlueprintExtender.bundleChanged(BlueprintExtender.java:213) > at > org.apache.aries.blueprint.container.BlueprintExtender$BlueprintBundleTrackerCustomizer.modifiedBundle(BlueprintExtender.java:402) > at > org.apache.aries.util.tracker.InternalRecursiveBundleTracker.modifiedBundle(InternalRecursiveBundleTracker.java:89) > at > org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:453) > at > org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:237) > at > org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:413) > at > org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:916) > at > org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:220) > at > org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:149) > at > org.eclipse.osgi.framework.internal.core.Framework.publishBundleEventPrivileged(Framework.java:1350) > at > org.eclipse.osgi.framework.internal.core.Framework.publishBundleEvent(Framework.java:1301) > at > org.eclipse.osgi.framework.internal.core.BundleHost.stopWorker(BundleHost.java:470) > at > org.eclipse.osgi.framework.internal.core.AbstractBundle.suspend(AbstractBundle.java:546) > at > org.eclipse.osgi.framework.internal.core.Framework.suspendBundle(Framework.java:1098) > at > org.eclipse.osgi.framework.internal.core.StartLevelManager.decFWSL(StartLevelManager.java:593) > at > org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:261) > at > org.eclipse.osgi.framework.internal.core.StartLevelManager.shutdown(StartLevelManager.java:216) > at > org.eclipse.osgi.framework.internal.core.InternalSystemBundle.suspend(InternalSystemBundle.java:266) > at > org.eclipse.osgi.framework.internal.core.Framework.shutdown(Framework.java:685) > at > org.eclipse.osgi.framework.internal.core.Framework.close(Framework.java:583) > at > org.eclipse.osgi.framework.internal.core.InternalSystemBundle$1.run(InternalSystemBundle.java:243) > at java.lang.Thread.run(Thread.java:637) > [System Bundle Shutdown] DEBUG > org.ops4j.pax.swissbox.extender.BundleWatcher - Releasing bundle > [org.apache.aries.blueprint.testbundlea] > [Framework Event Dispatcher] DEBUG org.apache.aries.blueprint.testbundlea - > BundleEvent STOPPED > > > .... skipping lots of apparently normal messages ... > > > [Blueprint Extender: 1] DEBUG > org.apache.aries.blueprint.container.BlueprintEventDispatcher - Sending > blueprint container event BlueprintEvent[type=CREATED] for bundle > org.apache.aries.blueprint > [Blueprint Extender: 1] DEBUG > org.apache.aries.blueprint.container.BlueprintContainerImpl - Running > blueprint container for bundle org.apache.aries.blueprint in state Created > Woken up > Woken up > [RMI TCP Connection(1)-9.37.240.141] DEBUG sun.rmi.server.call - RMI TCP > Connection(1)-9.37.240.141: [9.37.240.141] exception: > java.lang.reflect.InvocationTargetException > > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > > at > org.ops4j.pax.exam.rbc.internal.RemoteBundleContextImpl.remoteCall(RemoteBundleContextImpl.java:80) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at > sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:305) > > at sun.rmi.transport.Transport$1.run(Transport.java:159) > at java.security.AccessController.doPrivileged(Native Method) > > at sun.rmi.transport.Transport.serviceCall(Transport.java:155) > at > sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535) > at > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790) > at > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649) > at > java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) > at java.lang.Thread.run(Thread.java:637) > Caused by: java.lang.reflect.InvocationTargetException > > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > > at > org.ops4j.pax.exam.junit.extender.impl.internal.CallableTestMethodImpl.injectContextAndInvoke(CallableTestMethodImpl.java:134) > at > org.ops4j.pax.exam.junit.extender.impl.internal.CallableTestMethodImpl.call(CallableTestMethodImpl.java:101) > ... 19 more > Caused by: junit.framework.AssertionFailedError: Quiesce callback should > have occurred once; calls should be 1, but it is 0 > > at junit.framework.Assert.fail(Assert.java:47) > at junit.framework.Assert.assertTrue(Assert.java:20) > at > org.apache.aries.blueprint.itests.QuiesceBlueprintTest.testMultiRequestQuiesce(QuiesceBlueprintTest.java:373) > ... 25 more > [org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer] : > Shutting down the test container (Pax Runner) > [RMI TCP Connection(1)-9.37.240.141] DEBUG sun.rmi.transport.tcp - RMI TCP > Connection(1)-9.37.240.141: (port 1099) op = 80 > [org.ops4j.pax.runner.platform.DefaultJavaRunner] : Waiting for framework > exit. > > > > > > > On 9/21/10 8:39 AM, Hannah Ramlee wrote: > >> Hi Emily, >> >> Thanks for the extra information. I managed to reproduce this a few times, >> and put in some changes to the blueprint quiesce test which has stopped >> the >> issue on my machine. >> >> I have attached the patch to jira ARIES-412. >> >> Thanks, >> Hannah >> >> On 19 September 2010 22:55, Emily Jiang<[email protected]> wrote: >> >> Hi Hannah, >>> >>> I ran 'mvn clean install' from trunk and got quiesce test failures quite >>> frequently. Below is the error I got for the QuiesceBlueprintTest from a >>> recent test run. >>> >>> >>> >>> ------------------------------------------------------------------------------- >>> Test set: org.apache.aries.blueprint.itests.QuiesceBlueprintTest >>> >>> >>> ------------------------------------------------------------------------------- >>> Tests run: 4, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 20.616 >>> sec >>> <<< FAILURE! >>> testMultiBundleQuiesce >>> [equinox/3.5.0](org.apache.aries.blueprint.itests.QuiesceBlueprintTest) >>> Time elapsed: 3.409 sec<<< FAILURE! >>> junit.framework.AssertionFailedError: Quiesce callback should have >>> occurred once for bundle a but not for bundle q; calls should be 1, but >>> it >>> is 2 >>> at junit.framework.Assert.fail(Assert.java:47) >>> at junit.framework.Assert.assertTrue(Assert.java:20) >>> at >>> >>> >>> org.apache.aries.blueprint.itests.QuiesceBlueprintTest.testMultiBundleQuiesce(QuiesceBlueprintTest.java:376) >>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >>> at >>> >>> >>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:48) >>> at >>> >>> >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) >>> at java.lang.reflect.Method.invoke(Method.java:600) >>> at >>> >>> >>> org.ops4j.pax.exam.junit.extender.impl.internal.CallableTestMethodImpl.injectContextAndInvoke(CallableTestMethodImpl.java:134) >>> at >>> >>> >>> org.ops4j.pax.exam.junit.extender.impl.internal.CallableTestMethodImpl.call(CallableTestMethodImpl.java:101) >>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >>> at >>> >>> >>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:48) >>> at >>> >>> >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) >>> at java.lang.reflect.Method.invoke(Method.java:600) >>> at >>> >>> >>> org.ops4j.pax.exam.rbc.internal.RemoteBundleContextImpl.remoteCall(RemoteBundleContextImpl.java:80) >>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >>> at >>> >>> >>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:48) >>> at >>> >>> >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) >>> at java.lang.reflect.Method.invoke(Method.java:600) >>> at >>> sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:310) >>> at sun.rmi.transport.Transport$1.run(Transport.java:159) >>> at >>> java.security.AccessController.doPrivileged(AccessController.java:284) >>> at sun.rmi.transport.Transport.serviceCall(Transport.java:155) >>> at >>> sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535) >>> at >>> >>> >>> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790) >>> at >>> >>> >>> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649) >>> at >>> >>> >>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:898) >>> at >>> >>> >>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:920) >>> at java.lang.Thread.run(Thread.java:736) >>> >>> Regards, >>> >>> Emily >>> >>> >>> >>> From: Hannah Ramlee<[email protected]> >>> To: [email protected] >>> Date: 18/09/2010 23:39 >>> Subject: Re: building Apache Aries trunk from the top level pom >>> >>> >>> >>> Hi Emily, >>> >>> I have been trying to reproduce the intermittent quiesce failures to >>> debug >>> them, however on my system they don't fail :( >>> >>> I'm not sure what is different about my environment that means I do not >>> see >>> these issues - will continue to investigate. >>> >>> Hannah >>> >>> >>> On 17 September 2010 22:30, Emily Jiang<[email protected]> wrote: >>> >>> I have fixed the application itests intermittent failures. After you >>>> >>> have >>> >>>> pulled the latest changes into your local repository, you should not see >>>> application itests failures any more. If it is not the case, please let >>>> >>> me >>> >>>> know. The fix does not fix the quiesce test failures though:(. >>>> >>>> Has someone started looking at the intermittent quiesce test failures? >>>> >>>> Thanks >>>> Emily >>>> >>>> >>>> >>>> From: Joe Bohn<[email protected]> >>>> To: [email protected] >>>> Date: 16/09/2010 18:11 >>>> Subject: Re: building Apache Aries trunk from the top level pom >>>> >>>> >>>> >>>> On 9/16/10 12:58 PM, Alasdair Nottingham wrote: >>>> >>>>> On 16 September 2010 01:45, Holly Cummins<[email protected]> >>>>> wrote: >>>>> >>>>>> I wonder if running with a bigger heap would help? >>>>>> >>>>> >>>>> That is plausible. I don't have these issues and I have to run with a >>>>> non-default heap size or the build fails with OOM errors on my mac. >>>>> Perhaps 512m is big enough not to see these errors. >>>>> >>>>> >>>> My MAVEN_OPTS="-XX:MaxPermSize=512m -Xms1024m -Xmx1024m" >>>> >>>> I'm also using mac ... which I was wondering for a time if it was >>>> related to the mac jdk - but it seems that is not the case given others >>>> are seeing similar issues on other environments. >>>> >>>> --- >>>> Joe >>>> >>>> >>>> >>>> >>>> >>>> >>>> >>>> Unless stated otherwise above: >>>> IBM United Kingdom Limited - Registered in England and Wales with number >>>> 741598. >>>> Registered office: PO Box 41, North Harbour, Portsmouth, Hampshire PO6 >>>> >>> 3AU >>> >>>> >>>> >>>> >>>> >>>> >>>> >>>> >>> >>> >>> >>> >>> >>> >>> Unless stated otherwise above: >>> IBM United Kingdom Limited - Registered in England and Wales with number >>> 741598. >>> Registered office: PO Box 41, North Harbour, Portsmouth, Hampshire PO6 >>> 3AU >>> >>> >>> >>> >>> >>> >>> >> > > -- > Joe >
