ops4j / org.ops4j.pax.logging

The OSGi Logging framework implementation. Supports SLF4J,LOG4J,JCL etc.
https://ops4j1.jira.com/wiki/spaces/paxlogging/overview
Apache License 2.0
46 stars 79 forks source link

ConcurrentModificationException in Activator [PAXLOGGING-125] #206

Closed ops4j-issues closed 12 years ago

ops4j-issues commented 12 years ago

Harald Wellmann created PAXLOGGING-125

The following sporadic error occured in a test of the Pax Exam 2.3.0 regression suite. There appears to be a race condition which makes it hard to reproduce the problem.

Running org.ops4j.pax.exam.regression.paxrunner.felix.options.FrameworkPropertyTest
0    [main] INFO  org.ops4j.pax.exam.spi.DefaultExamSystem  - Pax Exam System (Version: 2.3.0.M2-SNAPSHOT) created.
4    [main] DEBUG org.ops4j.store.intern.TemporaryStore  - Storage Area is /tmp/1324120412004-0
25   [main] DEBUG org.ops4j.pax.exam.container.def.internal.RMIRegistry  - Created Registry on 21413
25   [main] DEBUG org.ops4j.pax.exam.container.def.internal.RMIRegistry  - Currently 1 out of 98 ports are in use. Port range is from 21413 up to 21511
25   [main] DEBUG org.ops4j.pax.exam.spi.PaxExamRuntime  - Found TestContainerFactory: org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainerFactory
31   [main] DEBUG org.ops4j.pax.exam.junit.JUnit4TestRunner  - No User defined probe hook found
32   [main] DEBUG org.ops4j.pax.exam.spi.intern.DefaultTestAddress  - NEW ADDRESS= PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040 parent=null root=[TestAddress:PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040 root:PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040] args=[Ljava.lang.Object;@3b6f0be8
36   [main] DEBUG org.ops4j.store.intern.TemporaryStore  - Storage Area is /tmp/tb
37   [main] DEBUG org.ops4j.pax.exam.spi.intern.TestProbeBuilderImpl  - Top level dir . has been verified.
59   [main] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder  - make()
60   [main] DEBUG org.ops4j.store.intern.TemporaryStore  - Enter store()
62   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Creating manifest from added headers.
63   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - DynamicImport-Package = *
63   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Ignore-Package =
63   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040 = org.ops4j.pax.exam.regression.paxrunner.felix.options.FrameworkPropertyTest;startLevel
63   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - PaxExam-Executable = PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040,
63   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Bundle-SymbolicName = PAXEXAM-PROBE-2aa99686-07d1-4682-9e81-fed73bf09c26
65   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/cache/CacheTestBase.class
66   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/porcelain/A2.class
67   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/reference/ExplodedReferenceTest.class
68   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/porcelain/A2_B.class
68   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/cache/CacheTestCleanTrue.class
69   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/felix/options/FrameworkPropertyTest.class
69   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/porcelain/A2_A.class
70   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/cache/CacheTestKeep.class
70   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/plumbing/Main.class
71   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/plumbing/Probe2.class
71   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/felix/options/SystemPropertyTest.class
72   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/cache/CacheTest.class
73   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/plumbing/ReactorAPITest.class
73   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/reference/ReferenceJarTest.class
74   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/reference/EquinoxReferenceTest.class
75   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/porcelain/MutliFrameworkTest.class
75   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/cache/CacheTestCleanFalse.class
76   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource log4j.properties
76   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/reference/PdeExplodedReferenceTest.class
76   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/plumbing/SingleTestProbe.class
77   [Thread-1] DEBUG org.ops4j.pax.tinybundles.core.intern.RawBuilder - Copying resource org/ops4j/pax/exam/regression/paxrunner/plumbing/BareAPITest.class
82   [main] DEBUG org.ops4j.store.intern.TemporaryStore  - Exit store(): ba385c6bc5358691c0cc1bacd803682f54339ec2
86   [main] DEBUG org.ops4j.pax.exam.spi.DefaultExamReactor  - Staging reactor with probes: 1 using strategy: org.ops4j.pax.exam.spi.reactors.AllConfinedStagedReactorFactory@6a3b8b49
87   [main] DEBUG org.ops4j.store.intern.TemporaryStore  - Storage Area is /tmp/1324120412088-0
110  [main] DEBUG org.ops4j.pax.exam.spi.intern.DefaultTestAddress  - NEW ADDRESS= PaxExam-52509a4f-b9bf-4cfd-8835-182a4d4a2e2d parent=[TestAddress:PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040 root:PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040] root=[TestAddress:PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040 root:PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040] args=[Ljava.lang.Object;@3df78040
120  [main] DEBUG org.ops4j.pax.exam.junit.JUnit4TestRunner  - Invoke startLevel:FrameworkPropertyTest.startLevel:PaxRunnerTestContainer{felix} @ [TestAddress:PaxExam-52509a4f-b9bf-4cfd-8835-182a4d4a2e2d root:PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040] Arguments: [Ljava.lang.Object;@3b6f0be8
120  [main] DEBUG org.ops4j.store.intern.TemporaryStore  - Storage Area is /tmp/1324120412121-0
129  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - Starting up the test container (Pax Runner ${dependency.runner.version} )
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - Pax Runner Arguments: ( 16)
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # --platform=felix
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # --bootDelegation=sun.*
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # scan-bundle:link:classpath:META-INF/links/org.ops4j.pax.exam.rbc.link@update@2
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # scan-bundle:link:classpath:META-INF/links/org.ops4j.pax.exam.inject.link@update@2
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # scan-bundle:link:classpath:META-INF/links/org.ops4j.pax.extender.service.link@update@2
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # scan-bundle:link:classpath:META-INF/links/org.osgi.compendium.link@update@2
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # scan-bundle:link:classpath:META-INF/links/org.ops4j.pax.logging.api.link@update@2
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # scan-bundle:link:classpath:META-INF/links/org.apache.geronimo.specs.atinject.link@update@2
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # scan-bundle:mvn:org.junit/com.springsource.org.junit/4.9.0@2
130  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # scan-bundle:mvn:org.ops4j.pax.exam/pax-exam-invoker-junit/2.3.0.M2-SNAPSHOT@update
131  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # --startLevel=5
131  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # --vmOptions=-Dpax.exam.invoker=junit -Dorg.ops4j.pax.exam.rbc.rmi.host=handel -Dorg.ops4j.pax.exam.rbc.rmi.port=21413 -Dorg.ops4j.pax.exam.rbc.rmi.name=445762f1-7591-4bb4-9e13-aaf154b30f19 -Dfelix.startlevel.bundle=4
131  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # --noConsole
131  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # --noDownloadFeedback
131  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # --log=warn
131  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - # --workingDirectory=/tmp/1324120412121-0
181  [main] DEBUG org.ops4j.pax.swissbox.tracker.ReplaceableService  - Creating replaceable service for [interface org.osgi.service.obr.RepositoryAdmin]
483  [main] DEBUG org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - Test Container started in 360 millis
483  [main] INFO org.ops4j.pax.exam.container.def.internal.PaxRunnerTestContainer  - Wait for test container to finish its initialization [ RelativeTimeout value = 180000 ]
483  [main] INFO org.ops4j.pax.exam.rbc.client.RemoteBundleContextClient  - Waiting for remote bundle context.. on 21413 name: 445762f1-7591-4bb4-9e13-aaf154b30f19 timout: [ RelativeTimeout value = 180000 ]

[org.ops4j.pax.exam.rbc.internal.Activator] : Trying to find registry on [host=handel port=21413]
[org.ops4j.pax.exam.rbc.internal.Activator] : Now Binding RemoteBundleContext as name=445762f1-7591-4bb4-9e13-aaf154b30f19 to RMI registry
ERROR: Bundle org.ops4j.pax.logging.pax-logging-api [6] Error starting file:bundles/org.ops4j.pax.logging.pax-logging-api_1.6.2.jar (org.osgi.framework.BundleException: Activator start error in bundle org.ops4j.pax.logging.pax-logging-api [6].)
java.util.ConcurrentModificationException
        at java.util.WeakHashMap$HashIterator.nextEntry(WeakHashMap.java:762)
        at java.util.WeakHashMap$EntryIterator.next(WeakHashMap.java:801)
        at java.util.WeakHashMap$EntryIterator.next(WeakHashMap.java:799)
        at org.ops4j.pax.logging.slf4j.Slf4jLoggerFactory.setBundleContext(Slf4jLoggerFactory.java:55)
        at org.ops4j.pax.logging.internal.Activator.start(Activator.java:32)
        at org.apache.felix.framework.util.SecureAction.startActivator(SecureAction.java:641)
        at org.apache.felix.framework.Felix.activateBundle(Felix.java:1977)
        at org.apache.felix.framework.Felix.startBundle(Felix.java:1895)
        at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1191)
        at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:295)
        at java.lang.Thread.run(Thread.java:662)
org.ops4j.pax.logging.pax-logging-api[org.ops4j.pax.exam.rbc.internal.Activator] : Container with name 445762f1-7591-4bb4-9e13-aaf154b30f19 has added its RBC
944  [main] DEBUG org.ops4j.pax.exam.rbc.client.RemoteBundleContextClient  - Remote bundle context found after 461 millis
998  [main] DEBUG org.ops4j.pax.exam.container.remote.RBCRemoteTarget  - Preparing and Installing bundle (from stream )..
998  [main] DEBUG org.ops4j.pax.exam.rbc.client.RemoteBundleContextClient  - Packing probe into memory for true RMI. Hopefully things will fill in..
1012 [main] DEBUG org.ops4j.pax.exam.container.remote.RBCRemoteTarget  - Installed bundle (from stream) as ID: 9
1013 [main] DEBUG org.ops4j.pax.exam.container.remote.RBCRemoteTarget  - call [[TestAddress:PaxExam-52509a4f-b9bf-4cfd-8835-182a4d4a2e2d root:PaxExam-fd301efe-e89a-458c-9797-99c54aa1b040]] 

Affects: 1.6.2 Fixed in: 1.6.3 Votes: 0, Watches: 0


Referenced issues

is aggregated into:

ops4j-issues commented 12 years ago

Harald Wellmann commented

Already fixed in PAXLOGGING-110 .