Home » Eclipse Projects » Riena » Riena vs. Equinox Log Nuisance(Dependency problems during start-up?)
Riena vs. Equinox Log Nuisance [message #539707] |
Sat, 12 June 2010 00:32 |
Christian Kesselheim Messages: 59 Registered: June 2010 |
Member |
|
|
I've recently bumped into some annoying Riena-related log messages for my RCP/Riena application (using Helios/Riena RC3 on MacOSX/Cocoa.x86_64):
!ENTRY org.eclipse.osgi 2 0 2010-06-12 02:22:19.888
!MESSAGE While loading class "org.eclipse.riena.internal.core.logging.LogLevelMapper", thread "Thread[Framework Event Dispatcher,5,main]" timed out waiting (5000ms) for thread "Thread[Thread-0,5,main]" to finish starting bundle "org.eclipse.riena.core_2.0.0.v20100608_2_0_0_RC4 [123]". To avoid deadlock, thread "Thread[Framework Event Dispatcher,5,main]" is proceeding but "org.eclipse.riena.internal.core.logging.LogLevelMapper" may not be fully initialized.
!STACK 0
org.osgi.framework.BundleException: State change in progress for bundle "reference:file:/Users/ckesselh/Documents/Eclipse/riena-workspace/.metadata/.plugins/org.eclipse.pde.core/.bundle_pool/plugins/org.eclipse.riena.core_2.0.0.v20100608_2_0_0_RC4.jar" by thread "Thread-0".
at org.eclipse.osgi.framework.internal.core.AbstractBundle.beginStateChange(AbstractBundle.java:1077)
at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:282)
at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:417)
at org.eclipse.osgi.internal.loader.BundleLoader.setLazyTrigger(BundleLoader.java:265)
at org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:106)
at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(ClasspathManager.java:453)
at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(DefaultClassLoader.java:216)
at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:393)
at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:469)
at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:422)
at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:410)
at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:107)
at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
at org.eclipse.riena.core.logging.SysoLogListener.logged(SysoLogListener.java:30)
at org.eclipse.riena.internal.core.logging.SynchronousLogListenerAdapter.logged(SynchronousLogListenerAdapter.java:37)
at org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFactory.safeLogged(ExtendedLogReaderServiceFactory.java:89)
at org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFactory.log(ExtendedLogReaderServiceFactory.java:147)
at org.eclipse.equinox.log.internal.Activator.bundleChanged(Activator.java:77)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:919)
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:227)
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:337)
Caused by: org.eclipse.osgi.framework.internal.core.AbstractBundle$BundleStatusException
... 21 more
Root exception:
org.eclipse.osgi.framework.internal.core.AbstractBundle$BundleStatusException
at org.eclipse.osgi.framework.internal.core.AbstractBundle.beginStateChange(AbstractBundle.java:1077)
at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:282)
at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:417)
at org.eclipse.osgi.internal.loader.BundleLoader.setLazyTrigger(BundleLoader.java:265)
at org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:106)
at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(ClasspathManager.java:453)
at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(DefaultClassLoader.java:216)
at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:393)
at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:469)
at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:422)
at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:410)
at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:107)
at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
at org.eclipse.riena.core.logging.SysoLogListener.logged(SysoLogListener.java:30)
at org.eclipse.riena.internal.core.logging.SynchronousLogListenerAdapter.logged(SynchronousLogListenerAdapter.java:37)
at org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFactory.safeLogged(ExtendedLogReaderServiceFactory.java:89)
at org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFactory.log(ExtendedLogReaderServiceFactory.java:147)
at org.eclipse.equinox.log.internal.Activator.bundleChanged(Activator.java:77)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:919)
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:227)
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:337)
Sat Jun 12 02:22:14 CEST 2010 INFO [Thread-0] org.eclipse.riena.internal.core.Activator No stage information set.
Sat Jun 12 02:22:14 CEST 2010 INFO [Framework Event Dispatcher] null BundleEvent STARTED
Incrementally increasing the start level for org.eclipse.equinox.log makes the warning go away at (at the expense of having much less messages to look at, of course), so I wonder if this is the right way to go?!
Thanks in advance,
Chris
|
|
|
Re: Riena vs. Equinox Log Nuisance [message #539960 is a reply to message #539707] |
Mon, 14 June 2010 12:47 |
Christian Campo Messages: 597 Registered: July 2009 |
Senior Member |
|
|
Hi Chris,
can you please post a bug for this. Add the stacktrace from this mail and also supply us with the loglevels where it
didnt work and the ones where it did work.
We'll try to look into this problem as soon as we can. We currently a little busy with the latest steps in Helios....
thanks
christian campo
12.06.10 02:32, schrieb Christian Kesselheim:
> I've recently bumped into some annoying Riena-related log messages for
> my RCP/Riena application (using Helios/Riena RC3 on MacOSX/Cocoa.x86_64):
>
>
> !ENTRY org.eclipse.osgi 2 0 2010-06-12 02:22:19.888
> !MESSAGE While loading class
> "org.eclipse.riena.internal.core.logging.LogLevelMapper", thread
> "Thread[Framework Event Dispatcher,5,main]" timed out waiting (5000ms)
> for thread "Thread[Thread-0,5,main]" to finish starting bundle
> "org.eclipse.riena.core_2.0.0.v20100608_2_0_0_RC4 [123]". To avoid
> deadlock, thread "Thread[Framework Event Dispatcher,5,main]" is
> proceeding but "org.eclipse.riena.internal.core.logging.LogLevelMapper"
> may not be fully initialized.
> !STACK 0
> org.osgi.framework.BundleException: State change in progress for bundle
> " reference:file:/Users/ckesselh/Documents/Eclipse/riena-works pace/.metadata/.plugins/org.eclipse.pde.core/.bundle_pool/pl ugins/org.eclipse.riena.core_2.0.0.v20100608_2_0_0_RC4.jar "
> by thread "Thread-0".
> at
> org.eclipse.osgi.framework.internal.core.AbstractBundle.begi nStateChange(AbstractBundle.java:1077)
>
> at
> org.eclipse.osgi.framework.internal.core.AbstractBundle.star t(AbstractBundle.java:282)
>
> at
> org.eclipse.osgi.framework.util.SecureAction.start(SecureAct ion.java:417)
> at
> org.eclipse.osgi.internal.loader.BundleLoader.setLazyTrigger (BundleLoader.java:265)
>
> at
> org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter .postFindLocalClass(EclipseLazyStarter.java:106)
>
> at
> org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLoc alClass(ClasspathManager.java:453)
>
> at
> org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.fin dLocalClass(DefaultClassLoader.java:216)
>
> at
> org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass (BundleLoader.java:393)
>
> at
> org.eclipse.osgi.internal.loader.BundleLoader.findClassInter nal(BundleLoader.java:469)
>
> at
> org.eclipse.osgi.internal.loader.BundleLoader.findClass(Bund leLoader.java:422)
>
> at
> org.eclipse.osgi.internal.loader.BundleLoader.findClass(Bund leLoader.java:410)
>
> at
> org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loa dClass(DefaultClassLoader.java:107)
>
> at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
> at
> org.eclipse.riena.core.logging.SysoLogListener.logged(SysoLo gListener.java:30)
>
> at
> org.eclipse.riena.internal.core.logging.SynchronousLogListen erAdapter.logged(SynchronousLogListenerAdapter.java:37)
>
> at
> org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFac tory.safeLogged(ExtendedLogReaderServiceFactory.java:89)
>
> at
> org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFac tory.log(ExtendedLogReaderServiceFactory.java:147)
>
> at
> org.eclipse.equinox.log.internal.Activator.bundleChanged(Act ivator.java:77)
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.d ispatchEvent(BundleContextImpl.java:919)
>
> at
> org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEve nt(EventManager.java:227)
>
> at
> org.eclipse.osgi.framework.eventmgr.EventManager$EventThread .run(EventManager.java:337)
>
> Caused by:
> org.eclipse.osgi.framework.internal.core.AbstractBundle$Bund leStatusException
>
> ... 21 more
> Root exception:
> org.eclipse.osgi.framework.internal.core.AbstractBundle$Bund leStatusException
>
> at
> org.eclipse.osgi.framework.internal.core.AbstractBundle.begi nStateChange(AbstractBundle.java:1077)
>
> at
> org.eclipse.osgi.framework.internal.core.AbstractBundle.star t(AbstractBundle.java:282)
>
> at
> org.eclipse.osgi.framework.util.SecureAction.start(SecureAct ion.java:417)
> at
> org.eclipse.osgi.internal.loader.BundleLoader.setLazyTrigger (BundleLoader.java:265)
>
> at
> org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter .postFindLocalClass(EclipseLazyStarter.java:106)
>
> at
> org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLoc alClass(ClasspathManager.java:453)
>
> at
> org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.fin dLocalClass(DefaultClassLoader.java:216)
>
> at
> org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass (BundleLoader.java:393)
>
> at
> org.eclipse.osgi.internal.loader.BundleLoader.findClassInter nal(BundleLoader.java:469)
>
> at
> org.eclipse.osgi.internal.loader.BundleLoader.findClass(Bund leLoader.java:422)
>
> at
> org.eclipse.osgi.internal.loader.BundleLoader.findClass(Bund leLoader.java:410)
>
> at
> org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loa dClass(DefaultClassLoader.java:107)
>
> at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
> at
> org.eclipse.riena.core.logging.SysoLogListener.logged(SysoLo gListener.java:30)
>
> at
> org.eclipse.riena.internal.core.logging.SynchronousLogListen erAdapter.logged(SynchronousLogListenerAdapter.java:37)
>
> at
> org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFac tory.safeLogged(ExtendedLogReaderServiceFactory.java:89)
>
> at
> org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFac tory.log(ExtendedLogReaderServiceFactory.java:147)
>
> at
> org.eclipse.equinox.log.internal.Activator.bundleChanged(Act ivator.java:77)
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.d ispatchEvent(BundleContextImpl.java:919)
>
> at
> org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEve nt(EventManager.java:227)
>
> at
> org.eclipse.osgi.framework.eventmgr.EventManager$EventThread .run(EventManager.java:337)
>
> Sat Jun 12 02:22:14 CEST 2010 INFO [Thread-0]
> org.eclipse.riena.internal.core.Activator No stage information set.
> Sat Jun 12 02:22:14 CEST 2010 INFO [Framework Event Dispatcher] null
> BundleEvent STARTED
>
>
> Incrementally increasing the start level for org.eclipse.equinox.log
> makes the warning go away at (at the expense of having much less
> messages to look at, of course), so I wonder if this is the right way to
> go?!
>
> Thanks in advance,
>
> Chris
|
|
|
Re: Riena vs. Equinox Log Nuisance [message #541381 is a reply to message #539707] |
Sun, 20 June 2010 17:26 |
Christian Kesselheim Messages: 59 Registered: June 2010 |
Member |
|
|
I will. Just to remind myself, here are some more details I found while debugging.
What I think happens is that org.eclipse.riena.internal.core.logging.SynchronousLogListen erAdapter gets registered too early in the Riena start-up procedure. At the time this error occurs, Thread-0 is right in the middle of calling the org.eclipse.riena.internal.core.Activator.start() method; namely at line 66 of Activator.java, which reads
stage = variableManager.performStringSubstitution("Riena is running in stage '${riena.stage}'."); //$NON-NLS-1$
As a result, Equinox will try to load and start the "org.eclipse.core.variables" bundle, which is set as lazy-loaded by default. Since org.eclipse.equinox.log.internal.Activator has registered itself as a BundleListener, it will try to raise an "BundleEvent STARTED" log once this succeeds. Finally, this then causes org.eclipse.riena.internal.core.logging.SynchronousLogListen erAdapter to be called, which happens to sit in the very bundle whose Activator.start() method is just being executed. Deadlock.
Again, I'm neither an RCP nor Riena expert so this might just be my rather naive interpretation of what I can see.
Here are the corresponding stacks of both threads at the time the error occurs:
Daemon Thread [Thread-0] (Suspended)
org.eclipse.riena.internal.core.Activator.logStage() line: 66
org.eclipse.riena.internal.core.Activator.start(org.osgi.framework.BundleContext) line: 54
org.eclipse.osgi.framework.internal.core.BundleContextImpl$1.run() line: 783
java.security.AccessController.doPrivileged(java.security.PrivilegedExceptionAction<T>) line: not available [native method]
org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(org.osgi.framework.BundleActivator) line: 774
org.eclipse.osgi.framework.internal.core.BundleContextImpl.start() line: 755
org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(int) line: 370
org.eclipse.osgi.framework.internal.core.BundleHost(org.eclipse.osgi.framework.internal.core.AbstractBundle).start(int) line: 284
org.eclipse.osgi.framework.util.SecureAction.start(org.osgi.framework.Bundle, int) line: 417
org.eclipse.osgi.internal.loader.BundleLoader.setLazyTrigger() line: 265
org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter.postFindLocalClass(java.lang.String, java.lang.Class, org.eclipse.osgi.baseadaptor.loader.ClasspathManager) line: 106
org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(java.lang.String) line: 453
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(java.lang.String) line: 216
org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(java.lang.String) line: 393
org.eclipse.osgi.internal.loader.SingleSourcePackage.loadClass(java.lang.String) line: 33
org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(java.lang.String, boolean, java.lang.ClassLoader) line: 466
org.eclipse.osgi.internal.loader.BundleLoader.findClass(java.lang.String, boolean) line: 422
org.eclipse.osgi.internal.loader.BundleLoader.findClass(java.lang.String) line: 410
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(java.lang.String, boolean) line: 107
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader(java.lang.ClassLoader).loadClass(java.lang.String) line: 248
java.lang.ClassLoader.defineClass1(java.lang.String, byte[], int, int, java.security.ProtectionDomain, java.lang.String, boolean) line: not available [native method]
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader(java.lang.ClassLoader).defineClassCond(java.lang.String, byte[], int, int, java.security.ProtectionDomain, boolean) line: 632
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader(java.lang.ClassLoader).defineClass(java.lang.String, byte[], int, int, java.security.ProtectionDomain) line: 616
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.defineClass(java.lang.String, byte[], org.eclipse.osgi.baseadaptor.loader.ClasspathEntry, org.eclipse.osgi.baseadaptor.bundlefile.BundleEntry) line: 188
org.eclipse.osgi.baseadaptor.loader.ClasspathManager.defineClass(java.lang.String, byte[], org.eclipse.osgi.baseadaptor.loader.ClasspathEntry, org.eclipse.osgi.baseadaptor.bundlefile.BundleEntry, org.eclipse.osgi.baseadaptor.hooks.ClassLoadingStatsHook[]) line: 580
org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findClassImpl(java.lang.String, org.eclipse.osgi.baseadaptor.loader.ClasspathEntry, org.eclipse.osgi.baseadaptor.hooks.ClassLoadingStatsHook[]) line: 550
org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClassImpl(java.lang.String, org.eclipse.osgi.baseadaptor.hooks.ClassLoadingStatsHook[]) line: 481
org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass_LockClassLoader(java.lang.String, org.eclipse.osgi.baseadaptor.hooks.ClassLoadingStatsHook[]) line: 469
org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(java.lang.String) line: 449
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(java.lang.String) line: 216
org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(java.lang.String) line: 393
org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(java.lang.String, boolean, java.lang.ClassLoader) line: 469
org.eclipse.osgi.internal.loader.BundleLoader.findClass(java.lang.String, boolean) line: 422
org.eclipse.osgi.internal.loader.BundleLoader.findClass(java.lang.String) line: 410
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(java.lang.String, boolean) line: 107
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader(java.lang.ClassLoader).loadClass(java.lang.String) line: 248
org.eclipse.osgi.internal.loader.BundleLoader.loadClass(java.lang.String) line: 338
org.eclipse.osgi.framework.internal.core.BundleHost.loadClass(java.lang.String, boolean) line: 232
org.eclipse.osgi.framework.internal.core.BundleHost(org.eclipse.osgi.framework.internal.core.AbstractBundle).loadBundleActivator() line: 149
org.eclipse.osgi.framework.internal.core.BundleContextImpl.start() line: 751
org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(int) line: 370
org.eclipse.osgi.framework.internal.core.BundleHost(org.eclipse.osgi.framework.internal.core.AbstractBundle).start(int) line: 284
org.eclipse.osgi.framework.util.SecureAction.start(org.osgi.framework.Bundle, int) line: 417
org.eclipse.osgi.internal.loader.BundleLoader.setLazyTrigger() line: 265
org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter.postFindLocalClass(java.lang.String, java.lang.Class, org.eclipse.osgi.baseadaptor.loader.ClasspathManager) line: 106
org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(java.lang.String) line: 453
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(java.lang.String) line: 216
org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(java.lang.String) line: 393
org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(java.lang.String, boolean, java.lang.ClassLoader) line: 469
org.eclipse.osgi.internal.loader.BundleLoader.findClass(java.lang.String, boolean) line: 422
org.eclipse.osgi.internal.loader.BundleLoader.findClass(java.lang.String) line: 410
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(java.lang.String, boolean) line: 107
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader(java.lang.ClassLoader).loadClass(java.lang.String) line: 248
org.eclipse.osgi.internal.loader.BundleLoader.loadClass(java.lang.String) line: 338
org.eclipse.osgi.framework.internal.core.BundleHost.loadClass(java.lang.String, boolean) line: 232
org.eclipse.osgi.framework.internal.core.BundleHost(org.eclipse.osgi.framework.internal.core.AbstractBundle).loadClass(java.lang.String) line: 1197
org.eclipse.core.internal.registry.osgi.EquinoxRegistryStrategy(org.eclipse.core.internal.registry.osgi.RegistryStrategyOSGI).createExecutableExtension(org.eclipse.core.runtime.spi.RegistryContributor, java.lang.String, java.lang.String) line: 174
org.eclipse.core.internal.registry.ExtensionRegistry.createExecutableExtension(org.eclipse.core.runtime.spi.RegistryContributor, java.lang.String, java.lang.String) line: 904
org.eclipse.core.internal.registry.ConfigurationElement.createExecutableExtension(java.lang.String) line: 243
org.eclipse.core.internal.registry.ConfigurationElementHandle.createExecutableExtension(java.lang.String) line: 55
org.eclipse.equinox.internal.app.EclipseAppHandle.run(java.lang.Object) line: 191
org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(java.lang.Object) line: 110
org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(java.lang.Object) line: 79
org.eclipse.core.runtime.adaptor.EclipseStarter.run(java.lang.Object) line: 369
org.eclipse.core.runtime.adaptor.EclipseStarter.run(java.lang.String[], java.lang.Runnable) line: 179
sun.reflect.NativeMethodAccessorImpl.invoke0(java.lang.reflect.Method, java.lang.Object, java.lang.Object[]) line: not available [native method]
sun.reflect.NativeMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) line: 39
sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) line: 25
java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object...) line: 597
org.eclipse.equinox.launcher.Main.invokeFramework(java.lang.String[], java.net.URL[]) line: 619
org.eclipse.equinox.launcher.Main.basicRun(java.lang.String[]) line: 574
org.eclipse.equinox.launcher.Main.run(java.lang.String[]) line: 1407
org.eclipse.equinox.launcher.Main.main(java.lang.String[]) line: 1383
Daemon Thread [Framework Event Dispatcher] (Suspended)
java.lang.Object.wait(long) line: not available [native method]
org.eclipse.osgi.framework.internal.core.BundleHost(org.eclipse.osgi.framework.internal.core.AbstractBundle).beginStateChange() line: 1085
org.eclipse.osgi.framework.internal.core.BundleHost(org.eclipse.osgi.framework.internal.core.AbstractBundle).start(int) line: 282
org.eclipse.osgi.framework.util.SecureAction.start(org.osgi.framework.Bundle, int) line: 417
org.eclipse.osgi.internal.loader.BundleLoader.setLazyTrigger() line: 265
org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter.postFindLocalClass(java.lang.String, java.lang.Class, org.eclipse.osgi.baseadaptor.loader.ClasspathManager) line: 106
org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(java.lang.String) line: 453
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(java.lang.String) line: 216
org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(java.lang.String) line: 393
org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(java.lang.String, boolean, java.lang.ClassLoader) line: 469
org.eclipse.osgi.internal.loader.BundleLoader.findClass(java.lang.String, boolean) line: 422
org.eclipse.osgi.internal.loader.BundleLoader.findClass(java.lang.String) line: 410
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(java.lang.String, boolean) line: 107
org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader(java.lang.ClassLoader).loadClass(java.lang.String) line: 248
org.eclipse.riena.core.logging.SysoLogListener.logged(org.osgi.service.log.LogEntry) line: 30
org.eclipse.riena.internal.core.logging.SynchronousLogListenerAdapter.logged(org.osgi.service.log.LogEntry) line: 37
org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFactory.safeLogged(org.osgi.service.log.LogListener, org.osgi.service.log.LogEntry) line: 89
org.eclipse.equinox.log.internal.ExtendedLogReaderServiceFactory.log(org.osgi.framework.Bundle, java.lang.String, java.lang.Object, int, java.lang.String, java.lang.Throwable) line: 147
org.eclipse.equinox.log.internal.Activator.bundleChanged(org.osgi.framework.BundleEvent) line: 77
org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(java.lang.Object, java.lang.Object, int, java.lang.Object) line: 919
org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(java.util.Set, org.eclipse.osgi.framework.eventmgr.EventDispatcher, int, java.lang.Object) line: 227
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run() line: 337
As mentioned before, forcing org.eclipse.core.variables to auto-start earlier than Riena (e.g. auto-start at SL1) or org.eclipse.equinox.log to delay start-up accordingly (e.g. SL7 or higher in my case) breaks the cycle and makes the error go away. Still, I think actually postponing the registration of SynchronousLogListenerAdapter to a later stage or making its logged() method resilient against invocations taking place during core bundle start-up would be a much safer way to address this kind of problem.
I'll turn this into a former bug report as soon as I can find the time (probably tomorrow). If someone from Riena core development would be so kind to point out a possible fix for this issue that's in line with general architecture and all, I'll also try to compile and include a preliminary patch against CVS HEAD myself.
For now, thanks again for putting out this great piece of technology. I really enjoy your work.
Chris
[Updated on: Sun, 20 June 2010 20:56] Report message to a moderator
|
|
|
Re: Riena vs. Equinox Log Nuisance [message #542289 is a reply to message #541381] |
Thu, 24 June 2010 12:45 |
Stefan Liebig Messages: 124 Registered: July 2009 |
Senior Member |
|
|
Hi Christian,
I am pretty sure that your analysis is correct. We do now (cvs head)
delay the initialization of riena's logging support.
Tschüß,
Stefan
On 20.06.2010 19:26, Christian Kesselheim wrote:
> I will. Just to remind myself, here are some more details I found while
> debugging.
>
> What I think happens is that
> org.eclipse.riena.internal.core.logging.SynchronousLogListen erAdapter
> gets registered too early in the Riena start-up procedure. At the time
> this error occurs, Thread-0 is right in the middle of calling the
> org.eclipse.riena.internal.core.Activator.start() method; namely at line
> 66 of Activator.java, which reads
>
> stage = variableManager.performStringSubstitution("Riena is running in
> stage '${riena.stage}'."); //$NON-NLS-1$
>
> As a result, Equinox will try to load and start the
> "org.eclipse.core.variables" bundle, which is set as lazy-loaded by
> default. Since org.eclipse.equinox.log.internal.Activator has registered
> itself as a BundleListener, it will try to raise an "BundleEvent
> STARTED" log once this succeeds. Finally, this then causes
> org.eclipse.riena.internal.core.logging.SynchronousLogListen erAdapter
> to be called, which happens to sit in the very bundle whose
> Activator.start() method is just being executed. Deadlock.
>
> Again, I'm neither an RCP nor Riena expert so this might just be my
> rather naive interpretation of what I can see.
>
> Here are the corresponding stacks of both threads at the time the error
> occurs:
>
> Daemon Thread [Thread-0] (Suspended)
> Activator.logStage() line: 66
> Activator.start(BundleContext) line: 54
> BundleContextImpl$1.run() line: 783
> AccessController.doPrivileged(PrivilegedExceptionAction<T>) line: not
> available [native method]
> BundleContextImpl.startActivator(BundleActivator) line: 774
> BundleContextImpl.start() line: 755
> BundleHost.startWorker(int) line: 370
> BundleHost(AbstractBundle).start(int) line: 284
> SecureAction.start(Bundle, int) line: 417
> BundleLoader.setLazyTrigger() line: 265
> EclipseLazyStarter.postFindLocalClass(String, Class, ClasspathManager)
> line: 106
> ClasspathManager.findLocalClass(String) line: 453
> DefaultClassLoader.findLocalClass(String) line: 216
> BundleLoader.findLocalClass(String) line: 393
> SingleSourcePackage.loadClass(String) line: 33
> BundleLoader.findClassInternal(String, boolean, ClassLoader) line: 466
> BundleLoader.findClass(String, boolean) line: 422
> BundleLoader.findClass(String) line: 410
> DefaultClassLoader.loadClass(String, boolean) line: 107
> DefaultClassLoader(ClassLoader).loadClass(String) line: 248
> ClassLoader.defineClass1(String, byte[], int, int, ProtectionDomain,
> String, boolean) line: not available [native method]
> DefaultClassLoader(ClassLoader).defineClassCond(String, byte[], int,
> int, ProtectionDomain, boolean) line: 632
> DefaultClassLoader(ClassLoader).defineClass(String, byte[], int, int,
> ProtectionDomain) line: 616
> DefaultClassLoader.defineClass(String, byte[], ClasspathEntry,
> BundleEntry) line: 188
> ClasspathManager.defineClass(String, byte[], ClasspathEntry,
> BundleEntry, ClassLoadingStatsHook[]) line: 580
> ClasspathManager.findClassImpl(String, ClasspathEntry,
> ClassLoadingStatsHook[]) line: 550
> ClasspathManager.findLocalClassImpl(String, ClassLoadingStatsHook[])
> line: 481
> ClasspathManager.findLocalClass_LockClassLoader(String,
> ClassLoadingStatsHook[]) line: 469
> ClasspathManager.findLocalClass(String) line: 449
> DefaultClassLoader.findLocalClass(String) line: 216
> BundleLoader.findLocalClass(String) line: 393
> BundleLoader.findClassInternal(String, boolean, ClassLoader) line: 469
> BundleLoader.findClass(String, boolean) line: 422
> BundleLoader.findClass(String) line: 410
> DefaultClassLoader.loadClass(String, boolean) line: 107
> DefaultClassLoader(ClassLoader).loadClass(String) line: 248
> BundleLoader.loadClass(String) line: 338
> BundleHost.loadClass(String, boolean) line: 232
> BundleHost(AbstractBundle).loadBundleActivator() line: 149
> BundleContextImpl.start() line: 751
> BundleHost.startWorker(int) line: 370
> BundleHost(AbstractBundle).start(int) line: 284
> SecureAction.start(Bundle, int) line: 417
> BundleLoader.setLazyTrigger() line: 265
> EclipseLazyStarter.postFindLocalClass(String, Class, ClasspathManager)
> line: 106
> ClasspathManager.findLocalClass(String) line: 453
> DefaultClassLoader.findLocalClass(String) line: 216
> BundleLoader.findLocalClass(String) line: 393
> BundleLoader.findClassInternal(String, boolean, ClassLoader) line: 469
> BundleLoader.findClass(String, boolean) line: 422
> BundleLoader.findClass(String) line: 410
> DefaultClassLoader.loadClass(String, boolean) line: 107
> DefaultClassLoader(ClassLoader).loadClass(String) line: 248
> BundleLoader.loadClass(String) line: 338
> BundleHost.loadClass(String, boolean) line: 232
> BundleHost(AbstractBundle).loadClass(String) line: 1197
> EquinoxRegistryStrategy(RegistryStrategyOSGI).createExecutab leExtension(RegistryContributor,
> String, String) line: 174
> ExtensionRegistry.createExecutableExtension(RegistryContribu tor, String,
> String) line: 904
> ConfigurationElement.createExecutableExtension(String) line: 243
> ConfigurationElementHandle.createExecutableExtension(String) line: 55
> EclipseAppHandle.run(Object) line: 191
> EclipseAppLauncher.runApplication(Object) line: 110
> EclipseAppLauncher.start(Object) line: 79
> EclipseStarter.run(Object) line: 369
> EclipseStarter.run(String[], Runnable) line: 179
> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
> available [native method]
> NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
> DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
> Method.invoke(Object, Object...) line: 597
> Main.invokeFramework(String[], URL[]) line: 619
> Main.basicRun(String[]) line: 574
> Main.run(String[]) line: 1407
> Main.main(String[]) line: 1383
>
> Daemon Thread [Framework Event Dispatcher] (Suspended)
> Object.wait(long) line: not available [native method]
> BundleHost(AbstractBundle).beginStateChange() line: 1085
> BundleHost(AbstractBundle).start(int) line: 282
> SecureAction.start(Bundle, int) line: 417
> BundleLoader.setLazyTrigger() line: 265
> EclipseLazyStarter.postFindLocalClass(String, Class, ClasspathManager)
> line: 106
> ClasspathManager.findLocalClass(String) line: 453
> DefaultClassLoader.findLocalClass(String) line: 216
> BundleLoader.findLocalClass(String) line: 393
> BundleLoader.findClassInternal(String, boolean, ClassLoader) line: 469
> BundleLoader.findClass(String, boolean) line: 422
> BundleLoader.findClass(String) line: 410
> DefaultClassLoader.loadClass(String, boolean) line: 107
> DefaultClassLoader(ClassLoader).loadClass(String) line: 248
> SysoLogListener.logged(LogEntry) line: 30
> SynchronousLogListenerAdapter.logged(LogEntry) line: 37
> ExtendedLogReaderServiceFactory.safeLogged(LogListener, LogEntry) line: 89
> ExtendedLogReaderServiceFactory.log(Bundle, String, Object, int, String,
> Throwable) line: 147
> Activator.bundleChanged(BundleEvent) line: 77
> BundleContextImpl.dispatchEvent(Object, Object, int, Object) line: 919
> EventManager.dispatchEvent(Set, EventDispatcher, int, Object) line: 227
> EventManager$EventThread.run() line: 337
>
>
> I'll turn this into a former bug report as soon as I can find the time
> (probably tomorrow).
> For now, thanks again for putting out this great piece of technology. I
> really enjoy your work.
>
> Chris
>
|
|
|
Goto Forum:
Current Time: Thu Mar 28 08:40:53 GMT 2024
Powered by FUDForum. Page generated in 0.02799 seconds
|