Community
Participate
Working Groups
I20070606-0010 I got the following already twice today in I20070606-0010 when starting my develop workspace (64 Java projects in the workspace): !ENTRY org.eclipse.osgi 2 0 2007-06-06 10:27:40.534 !MESSAGE While loading class "org.eclipse.jdt.internal.ui.InitializeAfterLoadJob$RealJob", thread "Thread[main,6,main]" timed out waiting (5000ms) for thread "Thread[Worker-3,5,main]" to finish starting bundle "update@plugins/org.eclipse.jdt.ui_3.3.0.v20070606-0010.jar [102]". To avoid deadlock, thread "Thread[main,6,main]" is proceeding but "org.eclipse.jdt.internal.ui.InitializeAfterLoadJob$RealJob" may not be fully initialized. !STACK 0 org.osgi.framework.BundleException: State change in progress for bundle "update@plugins/org.eclipse.jdt.ui_3.3.0.v20070606-0010.jar" by thread "Worker -3". at org.eclipse.osgi.framework.internal.core.AbstractBundle.beginStateChange(AbstractBundle.java:1141) at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:258) at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:400) at org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:111) at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(ClasspathManager.java:417) at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(DefaultClassLoader.java:189) at org.eclipse.osgi.framework.internal.core.BundleLoader.findLocalClass(BundleLoader.java:340) at org.eclipse.osgi.framework.internal.core.BundleLoader.findClassInternal(BundleLoader.java:408) at org.eclipse.osgi.framework.internal.core.BundleLoader.findClass(BundleLoader.java:369) at org.eclipse.osgi.framework.internal.core.BundleLoader.findClass(BundleLoader.java:357) at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:83) at java.lang.ClassLoader.loadClass(ClassLoader.java:251) at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319) at org.eclipse.jdt.internal.ui.InitializeAfterLoadJob.runInUIThread(InitializeAfterLoadJob.java:53) at org.eclipse.ui.progress.UIJob$1.run(UIJob.java:94) at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35) at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:123) at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:3659) at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3296) at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2389) at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2353) at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2219) at org.eclipse.ui.internal.Workbench$4.run(Workbench.java:466) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:289) at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:461) at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149) at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:106) at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:153) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:106) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:76) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:363) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:176) 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.eclipse.equinox.launcher.Main.invokeFramework(Main.java:504) at org.eclipse.equinox.launcher.Main.basicRun(Main.java:443) at org.eclipse.equinox.launcher.Main.run(Main.java:1169) at org.eclipse.equinox.launcher.Main.main(Main.java:1144) at org.eclipse.core.launcher.Main.main(Main.java:30) Caused by: org.eclipse.osgi.framework.internal.core.AbstractBundle$BundleStatusException ... 41 more Root exception: org.eclipse.osgi.framework.internal.core.AbstractBundle$BundleStatusException at org.eclipse.osgi.framework.internal.core.AbstractBundle.beginStateChange(AbstractBundle.java:1141) at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:258) at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:400) at org.eclipse.core.runtime.internal.adaptor.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:111) at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(ClasspathManager.java:417) at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(DefaultClassLoader.java:189) at org.eclipse.osgi.framework.internal.core.BundleLoader.findLocalClass(BundleLoader.java:340) at org.eclipse.osgi.framework.internal.core.BundleLoader.findClassInternal(BundleLoader.java:408) at org.eclipse.osgi.framework.internal.core.BundleLoader.findClass(BundleLoader.java:369) at org.eclipse.osgi.framework.internal.core.BundleLoader.findClass(BundleLoader.java:357) at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:83) at java.lang.ClassLoader.loadClass(ClassLoader.java:251) at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319) at org.eclipse.jdt.internal.ui.InitializeAfterLoadJob.runInUIThread(InitializeAfterLoadJob.java:53) at org.eclipse.ui.progress.UIJob$1.run(UIJob.java:94) at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35) at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:123) at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:3659) at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3296) at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2389) at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2353) at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2219) at org.eclipse.ui.internal.Workbench$4.run(Workbench.java:466) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:289) at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:461) at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149) at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:106) at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:153) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:106) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:76) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:363) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:176) 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.eclipse.equinox.launcher.Main.invokeFramework(Main.java:504) at org.eclipse.equinox.launcher.Main.basicRun(Main.java:443) at org.eclipse.equinox.launcher.Main.run(Main.java:1169) at org.eclipse.equinox.launcher.Main.main(Main.java:1144) at org.eclipse.core.launcher.Main.main(Main.java:30) This is on a Intel Core2 2.33GHz with 2GB RAM, WinXP
Created attachment 70292 [details] dump This is a thread dump taken immediately after eclipse has been started.
According to the trace, the timeout happens while loading one of the class referenced on line 53: Job job = new RealJob(JavaUIMessages.JavaPlugin_initializing_ui); Since these are JDT/UI class, moving to JDT/UI to investigate.
We don't understand this exception, we haven't change anything in this area since 3.2. Is it possible that this is caused because the InitializeAfterLoadJob is run before start has been finished? Is there a way to ensure that the async exec is executed after the bundle has started?
What VM are you using? It looks like the infamous VM classloader lock from the call to ClassLoader.loadClassInternal. This can cause dead lock if one thread is attempting to activate the bundle while another thread has locked the classloader object attempting to load a class from the bundle that is activating. If the activating thread needs to load another class then it will block on the classloader object. Meanwhile the other thread is blocked waiting for the bundle to finish starting. This is an issue on the Sun VM where the classloader object is locked natively and out of our control. To avoid endless deadlock we timeout waiting for the bundle to start so that things can continue. Can the following call be moved to the last line of the JavaPlugin.start method? new InitializeAfterLoadJob().schedule(); This should ensure that the starting thread does not need to load any more classes before it is allowed to finish activation. If that is not possible then you will have to use a SynchronousBundleListener to listen for when your bundle has finished loading before allowing the job to start. I can help with a patch if that is required. See bug 86713 and bug 121737 for more details on the VM bug.
Hi Thomas My VM is java.runtime.version=1.6.0_01-b06 Moving the line down to the end is no problem, and I think we should do that for RC4. But isn't it still possible that the job runs before start finished (unlikely but possible)?. Maybe for 3.4 we should use the listener approach, or I thought maybe something like: InitializeAfterLoadJob.RealJob.class.toString(); new InitializeAfterLoadJob().schedule(); could also work since it forces to load the class certainly before the job is executed. Would that work?
Created attachment 70470 [details] fix
(In reply to comment #5) > Hi Thomas > My VM is java.runtime.version=1.6.0_01-b06 That is the a Sun VM, right? Your patch should do the trick because once the job is scheduled the thread which is activating the bundle does not need to load any more classes before your JavaPlugin.start method returns. This will allow it to finish without having to obtain the classloader lock. The job thread may wait for a very short time for your start method to return but this should not cause deadlock as long as your start method is not doing any real work after the schedule.
(In reply to comment #7) > That is the a Sun VM, right? Yes, Sun. > Your patch should do the trick because once the job is scheduled the thread > which is activating the bundle does not need to load any more classes before > your JavaPlugin.start method returns. This will allow it to finish without > having to obtain the classloader lock. The job thread may wait for a very > short time for your start method to return but this should not cause deadlock > as long as your start method is not doing any real work after the schedule. I see, we'll do that for 3.3.1 then. Thanks
The VM bug is http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=4670071
Changing target to 3.4 as we haven't seen this anymore and we should avoid risky fixes for 3.3.1 if there no urge for it.
fixed > 20070827
start verification...
verified that new InitializeAfterLoadJob().schedule(); is the last stmt in start method.
