Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.
Bug 347907 - ResourcesPlugin#stop doesn't do a FULL_SAVE which can lead to snapshot & report of unsaved changes on next startup
Summary: ResourcesPlugin#stop doesn't do a FULL_SAVE which can lead to snapshot & repo...
Status: VERIFIED FIXED
Alias: None
Product: Platform
Classification: Eclipse Project
Component: Resources (show other bugs)
Version: 3.7   Edit
Hardware: PC All
: P3 major with 2 votes (vote)
Target Milestone: 4.5 M3   Edit
Assignee: Szymon Ptaszkiewicz CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 185968 272648 438360 (view as bug list)
Depends on:
Blocks: 444988 445223
  Show dependency tree
 
Reported: 2011-06-01 06:51 EDT by James Blackburn CLA
Modified: 2014-09-26 14:53 EDT (History)
9 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description James Blackburn CLA 2011-06-01 06:51:55 EDT
The ResourcesPlugin#shutdown doesn't correctly do a FULL_SAVE.  The result is that any subsequent IDE run may see a stale .snap file and startup in the crashed state:
!ENTRY org.eclipse.core.resources 2 10035 2011-05-31 17:17:01.250
!MESSAGE The workspace exited with unsaved changes in the previous session; refreshing workspace to recover changes.

In the IDE this usually OK because the IDE explicitly calls a Workspace#save in a ModalContext:
  ISaveContext.FULL_SAVE, keepConsistencyWhenCanceled=true, null(project)
LocalMetaArea.getSnapshotLocationFor(IResource) line: 181	
SaveManager.initSnap(IProgressMonitor) line: 495	
SaveManager.save(int, boolean, Project, IProgressMonitor) line: 1135	
Workspace.save(boolean, boolean, IProgressMonitor) line: 2375	
IDEWorkbenchAdvisor$5.run(IProgressMonitor) line: 508	
ModalContext$ModalContextThread.run() line: 121	

However any other IApplication which uses core.resources, and don't explicitly call Workspace#save, will end up with a 'crashed' workspace on each exit because #shutdown doesn't do the right thing for the resources plugin:
ISaveContext.SNAPSHOT, keepConsistencyWhenCanceled=false, null(project)
SaveManager.save(int, boolean, Project, IProgressMonitor) line: 1086	
SaveManager.save(int, Project, IProgressMonitor) line: 1082	
DelayedSnapshotJob.run(IProgressMonitor) line: 44	
SaveManager.shutdown(IProgressMonitor) line: 1363	
Workspace.close(IProgressMonitor) line: 606	
ResourcesPlugin.stop(BundleContext) line: 392	
BundleContextImpl$2.run() line: 843	

Note that there appears to be an inherent race in the above.  After the full WS save is run in the modal context, another thread can modify resources which would cause a snapshot to be created on shutdown.  This would then cause the next startup to report that the workspace had crashed.

Given that the workspace opens itself correctly on startup, it should also shutdown cleanly and not leave a snapshot lying around if eclipse exits correctly.

TLFIREPATH-2351
Comment 1 John Arthorne CLA 2011-06-01 13:58:43 EDT
It has always worked this way by design. All the "save participant" bundles will be stopped by the time the resources plugin stops, so they would not be able to save their state if the save happened during resources shutdown. Also, saving is a long running operation, so showing progress during save is important. By the time the resources bundle stops, the UI is already gone so we can't show progress.

So, perhaps we can provide some kind of protection like: if the workspace has never been saved, then print a message saying the application failed to save its state. But I would argue this is never the "correct" time to save the workspace state. If we did save at that point, then our state would not match the state of save participants since they can't possibly run at that point.
Comment 2 James Blackburn CLA 2011-06-01 14:57:45 EDT
Thanks for the comment.

(In reply to comment #1)
> Also,
> saving is a long running operation, so showing progress during save is
> important. By the time the resources bundle stops, the UI is already gone so we
> can't show progress.

In an headless app there may not be any UI at all.

> So, perhaps we can provide some kind of protection like: if the workspace has
> never been saved, then print a message saying the application failed to save
> its state. But I would argue this is never the "correct" time to save the
> workspace state. If we did save at that point, then our state would not match
> the state of save participants since they can't possibly run at that point.

Makes sense.

I think there are a few issues that arise:
 1) This contract is entirely implicit between the Workbench UI and core.resources.  AFAICS it isn't documented anywhere. The UI even downcasts IWorkspace to Workspace and calls a version of #save which isn't published through the interface
 2) Is there any guarantee that core.resources really is the last bundle to be stop()ed? In Bug 149121 where .snap files exists and the master table appears to go backwards.  If there's an outstanding Snapshot job stop() will cause a SNAPSHOT_SAVE to occur.  I clearly don't understand how bundles are stopped on shutdown...
 3) Does the partial snapshot save enough state?  In the CDT HeadlessBuilder IApp, we encountered an issue where on WS restart, the build configurations were missing from a project.  (This is, of course, without doing a full save.)

This and Bug 310793 make it hard for IApplications to correctly use the ResourcesPlugin without the Workbench.
Comment 3 John Arthorne CLA 2011-06-01 16:00:04 EDT
>  1) This contract is entirely implicit between the Workbench UI and
> core.resources.  AFAICS it isn't documented anywhere. The UI even downcasts
> IWorkspace to Workspace and calls a version of #save which isn't published
> through the interface

This is totally bogus and I hadn't noticed this before. I have entered bug 348007 to clean this up.

>  2) Is there any guarantee that core.resources really is the last bundle to be
> stop()ed? In Bug 149121 where .snap files exists and the master table appears
> to go backwards.  If there's an outstanding Snapshot job stop() will cause a
> SNAPSHOT_SAVE to occur.  I clearly don't understand how bundles are stopped on
> shutdown...

Bundles are stopped in reverse-prerequisite order. I.e., any bundle that requires core.resources will be stopped before core.resources. It is actually possible for a job from a misbehaving bundle to be running after that bundle has been shutdown. It would not be able to load classes at that point, but if its classes are already loaded it can run. The job API prints a warning in the log when this happens (if the bundle is using a bare thread you will never notice it).

>  3) Does the partial snapshot save enough state?  In the CDT HeadlessBuilder
> IApp, we encountered an issue where on WS restart, the build configurations
> were missing from a project.  (This is, of course, without doing a full save.)

I think the snapshot should have enough information so that a full workspace refresh on startup will restore all state.

> This and Bug 310793 make it hard for IApplications to correctly use the
> ResourcesPlugin without the Workbench.

Yes. People tend to mimic/copy the startup/shutdown code of IDEApplication as there are number of different things an application typically needs to do.  I agree many applications fail to do these things (locking on start and saving on shutdown).
Comment 4 James Blackburn CLA 2011-06-01 16:15:47 EDT
All sounds good. I'll have a poke to see if I can reproduce the corruption / missing data.

(In reply to comment #3)
> I agree many applications fail to do these things (locking on start and saving on
> shutdown).

It's worse that this: we can't lock on startup without a large refactoring.  

core.resources #start is called before our HeadlessBuilder (our HB class refers to ResourcesPlugin + friends). So while we can assert that the lock isn't held, by that point it's too late as core.resources will already be running in two eclipse instances.
Comment 5 Szymon Ptaszkiewicz CLA 2011-11-07 07:00:03 EST
This looks like a duplicate of bug 272648.
Comment 6 Szymon Brandys CLA 2011-11-07 08:55:30 EST
(In reply to comment #5)
> This looks like a duplicate of bug 272648.

The symptoms described in bug 272648 are similar. Though I will mark bug 272648 as a duplicate of this one because of more details provided here.
Comment 7 Szymon Brandys CLA 2011-11-07 08:56:00 EST
*** Bug 272648 has been marked as a duplicate of this bug. ***
Comment 8 Matthias Renz CLA 2012-10-10 03:45:59 EDT
Problem occurs in another way, too:
The user has a running Eclipse/RCP application and second RCP application instance is trying to lock the same workspace. This follows in a error message. Now the user closes the first running RCP app. After this, the user confirms the error message of the second RCP app ant the second instance shuts down the org.eclipse.resource-bundle which creates .snap files.
The result is that the workspace can not be reconstructed on a new eclipse startup.
Comment 9 Szymon Ptaszkiewicz CLA 2014-06-27 06:06:19 EDT
*** Bug 438360 has been marked as a duplicate of this bug. ***
Comment 10 Szymon Ptaszkiewicz CLA 2014-09-21 11:08:43 EDT
I have been getting the "workspace exited with unsaved changes" message for quite some time during almost every Eclipse start, even if all previous sessions ended without crash. This means there is some very stubborn code (somewhere in one of these: SDK, EGit, Releng Tools, API Tools) that keeps trying to modify workspace after the user asked Eclipse to close.

Since it happens only in my main workspace and never while debugging, the solution with breakpoints from bug 272648 comment 5 doesn't help. What we can do is to track all snapshot requests that happen after FULL_SAVE and then log them during ResourcesPlugin#stop. This is similar to the proposal from bug 272648 comment 6. If a plugin uses resources API, it must depend on core.resources plugin, and so the bundle.stop() will happen before ResourcesPlugin#stop (see comment 3). This will give us maximum time to catch any late workspace operation and enough information to distinguish it from a real crash.
Comment 11 Szymon Ptaszkiewicz CLA 2014-09-22 05:45:38 EDT
Fixed in master:

http://git.eclipse.org/c/platform/eclipse.platform.resources.git/commit/?id=0bb618ddd61532db5deb1f593e987e1debe88aa7

Here is an example of the entry log that will be produced during ResourcesPlugin#stop if the last workspace save is not FULL_SAVE:

!ENTRY org.eclipse.core.resources 4 10035 2014-09-22 11:15:07.471
!MESSAGE The workspace will exit with unsaved changes in this session.
!SUBENTRY 1 org.eclipse.core.resources 4 10035 2014-09-22 11:15:07.471
!MESSAGE Snapshot requestor: org.eclipse.core.tests.resources.session.TestBug347907$1(problematic job)
!STACK 0
java.lang.RuntimeException: Snapshot requested
	at org.eclipse.core.internal.resources.SaveManager.rememberSnapshotRequestor(SaveManager.java:561)
	at org.eclipse.core.internal.resources.SaveManager.snapshotIfNeeded(SaveManager.java:1476)
	at org.eclipse.core.internal.resources.Workspace.endOperation(Workspace.java:1499)
	at org.eclipse.core.internal.resources.InternalWorkspaceJob.run(InternalWorkspaceJob.java:45)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:54)
!SUBENTRY 1 org.eclipse.core.resources 4 10035 2014-09-22 11:15:07.473
!MESSAGE Snapshot requestor: org.eclipse.core.internal.jobs.ThreadJob(Implicit Job)
!STACK 0
java.lang.RuntimeException: Snapshot requested
	at org.eclipse.core.internal.resources.SaveManager.rememberSnapshotRequestor(SaveManager.java:561)
	at org.eclipse.core.internal.resources.SaveManager.snapshotIfNeeded(SaveManager.java:1476)
	at org.eclipse.core.internal.resources.Workspace.endOperation(Workspace.java:1499)
	at org.eclipse.core.internal.resources.File.create(File.java:175)
	at org.eclipse.core.internal.resources.File.create(File.java:188)
	at org.eclipse.core.tests.resources.session.TestBug347907$2.run(TestBug347907.java:64)
	at java.lang.Thread.run(Thread.java:853)
Comment 12 Szymon Ptaszkiewicz CLA 2014-09-24 04:21:27 EDT
Verified in I20140923-0800.
Comment 13 Szymon Ptaszkiewicz CLA 2014-09-26 09:19:17 EDT
*** Bug 185968 has been marked as a duplicate of this bug. ***