Bug 172524

Comment 1 Markus Keller 2007-02-01 13:08:06 EST

I've debugged this a bit, and I found that a SNAPSHOT save happens *after* the FULL_SAVE (afaics, the FULL_SAVE deletes the .snap file while the SNAPSHOT creates the file.

Here, kind is FULL_SAVE:
Thread [ModalContext] (Suspended (breakpoint at line 970 in SaveManager))	
	SaveManager.save(int, Project, IProgressMonitor) line: 970	
	Workspace.save(boolean, IProgressMonitor) line: 1825	
	IDEWorkbenchAdvisor$3.run(IProgressMonitor) line: 378	
	ModalContext$ModalContextThread.run() line: 113	

... and a little later, kind is SNAPSHOT: ...

"main" prio=6 tid=0x00037b00 nid=0xcd3c at breakpoint[0x0007e000..0x0007fc40]
        at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:970)
        at org.eclipse.core.internal.resources.DelayedSnapshotJob.run(DelayedSnapshotJob.java:44)
        at org.eclipse.core.internal.resources.SaveManager.shutdown(SaveManager.java:1176)
        at org.eclipse.core.internal.resources.Workspace.close(Workspace.java:413)
        at org.eclipse.core.resources.ResourcesPlugin.stop(ResourcesPlugin.java:341)
        at org.eclipse.osgi.framework.internal.core.BundleContextImpl$3.run(BundleContextImpl.java:1040)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.eclipse.osgi.framework.internal.core.BundleContextImpl.stop(BundleContextImpl.java:1036)
        at org.eclipse.osgi.framework.internal.core.BundleHost.stopWorker(BundleHost.java:447)
        at org.eclipse.osgi.framework.internal.core.AbstractBundle.suspend(AbstractBundle.java:526)
        at org.eclipse.osgi.framework.internal.core.Framework.suspendBundle(Framework.java:1145)
        at org.eclipse.osgi.framework.internal.core.StartLevelManager.decFWSL(StartLevelManager.java:670)
        at org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:288)
        - locked <0x1185f438> (a java.lang.Object)
        at org.eclipse.osgi.framework.internal.core.StartLevelManager.shutdown(StartLevelManager.java:258)
        at org.eclipse.osgi.framework.internal.core.SystemBundle.suspend(SystemBundle.java:190)
        at org.eclipse.osgi.framework.internal.core.Framework.shutdown(Framework.java:619)
        - locked <0x1185ae70> (a org.eclipse.osgi.framework.internal.core.Framework)
        at org.eclipse.osgi.framework.internal.core.Framework.close(Framework.java:522)
        - locked <0x1185ae70> (a org.eclipse.osgi.framework.internal.core.Framework)
        at org.eclipse.osgi.framework.internal.core.OSGi.close(OSGi.java:41)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.shutdown(EclipseStarter.java:389)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:186)
        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:585)
        at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:476)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:416)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1124)
        at org.eclipse.equinox.launcher.Main.main(Main.java:1099)
Thread [main] (Suspended (breakpoint at line 970 in SaveManager))	
	owns: Object  (id=7744)	
	owns: Framework  (id=7745)	
	SaveManager.save(int, Project, IProgressMonitor) line: 970	
	DelayedSnapshotJob.run(IProgressMonitor) line: 44	
	SaveManager.shutdown(IProgressMonitor) line: 1176	
	Workspace.close(IProgressMonitor) line: 413	
	ResourcesPlugin.stop(BundleContext) line: 341	
	BundleContextImpl$3.run() line: 1040	
	AccessController.doPrivileged(PrivilegedExceptionAction<T>) line: not available [native method]	
	BundleContextImpl.stop() line: 1036	
	BundleHost.stopWorker(int) line: 447	
	BundleHost(AbstractBundle).suspend(boolean) line: 526	
	Framework.suspendBundle(AbstractBundle, boolean) line: 1145	
	StartLevelManager.decFWSL(int, AbstractBundle[]) line: 670	
	StartLevelManager.doSetStartLevel(int, AbstractBundle) line: 288	
	StartLevelManager.shutdown() line: 258	
	SystemBundle.suspend() line: 190	
	Framework.shutdown() line: 619	
	Framework.close() line: 522	
	OSGi.close() line: 41	
	EclipseStarter.shutdown() line: 389	
	EclipseStarter.run(String[], Runnable) line: 186	
	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: 585	
	Main.invokeFramework(String[], URL[]) line: 476	
	Main.basicRun(String[]) line: 416	
	Main.run(String[]) line: 1124	
	Main.main(String[]) line: 1099	

Comment 2 John Arthorne 2007-02-01 13:23:45 EST

Sigh... this can be quite hard to track down, but I'll see if I can reproduce. It's usually caused by some bundle modifying the workspace after workspace save has occurred (for example during a bundle's shutdown code).

Comment 3 John Arthorne 2007-02-01 13:25:05 EST

I should also change the error message.  In this case "crash" simply means "some workspace changes occurred that were not saved".

Comment 4 Markus Keller 2007-02-01 13:36:53 EST

(In reply to comment #2)
> Sigh... this can be quite hard to track down, but I'll see if I can reproduce.
> It's usually caused by some bundle modifying the workspace after workspace save
> has occurred (for example during a bundle's shutdown code).

It happens every time for me, and I'm already set up to debug my development workspace, so if I can do anything to help tracking this down, please advise.

> I should also change the error message.  In this case "crash" simply means
> "some workspace changes occurred that were not saved".

Which amounts to the same for me: My CVS change sets are not saved, even though periodical snapshots must have occurred after I created the change sets.

Comment 5 John Arthorne 2007-02-01 14:18:23 EST

Here is the general technique I have used in the past:

1) Put a breakpoint inside Workspace.save, inside the "if (full) {" block.

2) Once the breakpoint is hit, add another breakpoint in Workspace.beginOperation.

Resume from the first breakpoint, and see where it stops.  There will be some false hits (such as the save implementation itself, or calls where the "createNewTree" parameter is false.  However, this will typically turn up the culprit.

Comment 6 Markus Keller 2007-02-02 05:57:21 EST

Steps in I20070201-0800:
- new workspace
- open Plug-ins view
- select all
- context menu > Add to Java Search
- shutdown & restart Eclipse

Comment 7 Markus Keller 2007-02-02 05:59:13 EST

This worked fine in M4 and needs to be fixed for M5.

Comment 8 John Arthorne 2007-02-02 09:56:21 EST

Here is the offending code.  You can't modify the workspace from your bundle stop because the workspace save has already finished at this point:

Thread [main] (Suspended (breakpoint at line 279 in Workspace))	
	Workspace.beginOperation(boolean) line: 279	
	File.create(InputStream, int, IProgressMonitor) line: 111	
	File.create(InputStream, boolean, IProgressMonitor) line: 176	
	SearchablePluginsManager.shutdown() line: 170	
	PDECore.stop(BundleContext) line: 247	
	BundleContextImpl$3.run() line: 1040	
	AccessController.doPrivileged(PrivilegedExceptionAction<T>) line: 242	
	BundleContextImpl.stop() line: 1036

Comment 9 John Arthorne 2007-02-02 09:57:49 EST

(personally I wouldn't call this a blocker - the build is still perfectly usable for me)

Comment 10 Markus Keller 2007-02-02 10:12:28 EST

OK, but it is critical, since I'm loosing work and I don't know what else is corrupted.

Comment 11 Wassim Melhem 2007-02-03 00:43:23 EST

we now register an ISaveParticipant that saves the state of the External Plug-in Libraries project upon an ISaveContext.FULL_SAVE instead of the stop() method of the bundle.