Eclipse Community Forums
Forum Search:

Search      Help    Register    Login    Home
Home » Eclipse Projects » Riena » Riena vs. Equinox Log Nuisance(Dependency problems during start-up?)
icon5.gif  Riena vs. Equinox Log Nuisance [message #539707] Fri, 11 June 2010 20:32 Go to next message
Christian Kesselheim is currently offline 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 08:47 Go to previous messageGo to next message
Christian Campo is currently offline Christian Campo
Messages: 590
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 13:26 Go to previous messageGo to next message
Christian Kesselheim is currently offline 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 16:56]

Report message to a moderator

Re: Riena vs. Equinox Log Nuisance [message #542289 is a reply to message #541381] Thu, 24 June 2010 08:45 Go to previous message
Stefan Liebig is currently offline 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
>
Previous Topic:Riena vs. Equinox Log Nuisance
Next Topic:Export the Server Module
Goto Forum:
  


Current Time: Thu Jul 24 23:55:15 EDT 2014

Powered by FUDForum. Page generated in 0.01641 seconds