Bug 352867 - NPE in ElementTreeWriter.sortTrees when shutting down Eclipse
Summary: NPE in ElementTreeWriter.sortTrees when shutting down Eclipse
Status: REOPENED
Alias: None
Product: Platform
Classification: Eclipse Project
Component: Resources (show other bugs)
Version: 3.7   Edit
Hardware: All All
: P3 normal with 1 vote (vote)
Target Milestone: ---   Edit
Assignee: Platform-Resources-Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 367444 (view as bug list)
Depends on:
Blocks:
 
Reported: 2011-07-22 10:17 EDT by Martin Oberhuber CLA
Modified: 2023-06-27 21:44 EDT (History)
16 users (show)

See Also:


Attachments
error before (4.98 KB, text/plain)
2019-06-27 11:41 EDT, Paul Pazderski CLA
no flags Details
Screenshot oldest ElementTree (19.33 KB, image/png)
2022-02-03 10:50 EST, Jörg Kubitz CLA
no flags Details
ErrorMsg from 2022-04-09.txt (3.51 MB, text/plain)
2022-04-29 09:26 EDT, Jörg Kubitz CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Martin Oberhuber CLA 2011-07-22 10:17:37 EDT
Build ID: Eclipse 3.7 (Indigo) + lots of addon plugins
Host: Win7-64 (with 32-bit jdk1.7.0_b147 since yesterday)

Found an error dialog, and this (below) in the log when shutting down Eclipse. I hadn't done anything unsual... switch-workspace, checkout / edit / checkin 2 files with CCRC, perform a WR proprietary plugin action, quit workbench. I've never seen such an exception before, today was the first time. I don't think I performed a build in this session.

I immediately zipped up my entire .metadata and can make it available on request (though I'm  a bit unsure about remnants of proprietary data in the local history).

Here's the stacktrace, I found something related in bug 5365 as well as 2 other really old bugs. Maybe Java7 is the culprit? Bug 317785 was also related to sorting.

!MESSAGE Could not write workspace metadata 'D:/Workspaces/wb331/ws/.metadata/.plugins/org.eclipse.core.resources/.root/146.tree'.
!STACK 0
java.lang.NullPointerException
	at org.eclipse.core.internal.watson.ElementTreeWriter.sortTrees(ElementTreeWriter.java:121)
	at org.eclipse.core.internal.watson.ElementTreeWriter.writeDeltaChain(ElementTreeWriter.java:191)
	at org.eclipse.core.internal.resources.SaveManager.writeTree(SaveManager.java:1923)
	at org.eclipse.core.internal.resources.SaveManager.saveTree(SaveManager.java:1352)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1133)
	at org.eclipse.core.internal.resources.Workspace.save(Workspace.java:2375)
	at org.eclipse.ui.internal.ide.application.IDEWorkbenchAdvisor$5.run(IDEWorkbenchAdvisor.java:508)
	at org.eclipse.jface.operation.ModalContext$ModalContextThread.run(ModalContext.java:121)
Comment 1 John Arthorne CLA 2011-07-25 14:04:29 EDT
(In reply to comment #0)
> Here's the stacktrace, I found something related in bug 5365 as well as 2 other
> really old bugs. Maybe Java7 is the culprit? Bug 317785 was also related to
> sorting.

I don't think it is related to bug 317785. In this case we are not using Java class library sorting routines at all, so the JVM shouldn't matter here. This is a situation where the trees don't form a simple linear ancestral chain.  I have no idea what could be causing this. Is the error reproducible on the workspace you zipped up? i.e., if you reopen that workspace and shutdown again do you get the same error?
Comment 2 Martin Oberhuber CLA 2011-11-07 07:23:24 EST
I didn't get the same error for a while, but today I did.

So I guess it's not reproducable but it does occur sporadically. One interesting thing is that in my session today, I didn't edit any file in my workspace ... just performed CCRC update twice but very few files were modified.
Comment 3 Martin Oberhuber CLA 2011-11-07 07:25:52 EST
Another data point, I found 4 messages like this in the log, which seem to originate from the current session:

null parent found while collapsing trees
Comment 4 Szymon Ptaszkiewicz CLA 2012-04-02 13:49:53 EDT
*** Bug 367444 has been marked as a duplicate of this bug. ***
Comment 5 Markus Junginger CLA 2012-04-15 09:25:22 EDT
I had the same issue. It occurred every time I closed Eclipse. After "eclipse -clean" the issue is gone.
Comment 6 Szymon Brandys CLA 2012-04-16 09:11:09 EDT
(In reply to comment #5)
> I had the same issue. It occurred every time I closed Eclipse. After "eclipse
> -clean" the issue is gone.

I saw that Martin O. had a zipped workspace at some point, but I have no access to it to investigate. Maybe you Markus have a workspace to test?
Comment 7 Markus Junginger CLA 2012-04-16 15:18:43 EDT
Szymon, I'm sorry because I did not make a backup of the workspace before trying out the clean. Stupid me. Just thought it might still be an evidence that cleaning helps.
Comment 8 Markus Junginger CLA 2012-05-09 05:51:36 EDT
It's back. Let me know if you are interested in any particular file from the workspace.
Comment 9 Markus Keller CLA 2016-05-20 10:31:02 EDT
Current log entries. I cannot reproduce. The workspace now starts and shuts down without problems.

I started the workspace, pulled all Git repos, inspected some of the incoming changes, and then closed the workbench window.

!SESSION 2016-05-20 15:04:08.859 -----------------------------------------------
eclipse.buildId=4.6.0.I20160519-1730
java.version=1.8.0_60
java.vendor=Oracle Corporation
BootLoader constants: OS=win32, ARCH=x86_64, WS=win32, NL=en_US
Framework arguments:  -showlocation
Command-line arguments:  -os win32 -ws win32 -arch x86_64 -data C:\e\w\master -clean -consolelog -showlocation -console -debug C:\e\w\debug-options.properties

!ENTRY org.eclipse.core.resources 2 566 2016-05-20 15:15:28.567
!MESSAGE null parent found while collapsing trees

!ENTRY org.eclipse.core.resources 2 566 2016-05-20 15:20:31.436
!MESSAGE null parent found while collapsing trees

!ENTRY org.eclipse.core.resources 2 566 2016-05-20 15:25:31.973
!MESSAGE null parent found while collapsing trees

!ENTRY org.eclipse.ui.ide 4 4 2016-05-20 15:27:41.236
!MESSAGE Problems saving workspace

!ENTRY org.eclipse.ui.ide 4 1 2016-05-20 15:27:41.236
!MESSAGE Problems occurred while trying to save the state of the workbench.
!SUBENTRY 1 org.eclipse.core.resources 4 568 2016-05-20 15:27:41.252
!MESSAGE Could not write workspace metadata 'C:/e/w/master/.metadata/.plugins/org.eclipse.core.resources/.root/2303.tree'.
!STACK 0
java.lang.NullPointerException
	at org.eclipse.core.internal.watson.ElementTreeWriter.sortTrees(ElementTreeWriter.java:125)
	at org.eclipse.core.internal.watson.ElementTreeWriter.writeDeltaChain(ElementTreeWriter.java:195)
	at org.eclipse.core.internal.resources.SaveManager.writeTree(SaveManager.java:2011)
	at org.eclipse.core.internal.resources.SaveManager.saveTree(SaveManager.java:1411)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1190)
	at org.eclipse.core.internal.resources.Workspace.save(Workspace.java:2283)
	at org.eclipse.ui.internal.ide.application.IDEWorkbenchAdvisor$4.run(IDEWorkbenchAdvisor.java:456)
	at org.eclipse.jface.operation.ModalContext$ModalContextThread.run(ModalContext.java:119)

!ENTRY org.eclipse.core.resources 2 10035 2016-05-20 15:27:43.015
!MESSAGE The workspace will exit with unsaved changes in this session.
Comment 10 Markus Duft CLA 2017-06-28 02:53:03 EDT
Seeing the exact same issue:

Caused by: java.lang.NullPointerException
	at org.eclipse.core.internal.watson.ElementTreeWriter.sortTrees(ElementTreeWriter.java:125)
	at org.eclipse.core.internal.watson.ElementTreeWriter.writeDeltaChain(ElementTreeWriter.java:195)
	at org.eclipse.core.internal.resources.SaveManager.writeTree(SaveManager.java:2011)
	at org.eclipse.core.internal.resources.SaveManager.saveTree(SaveManager.java:1411)
	... 35 more

This is totally reproducible for me, but I must admit that I implemented some IDE extensions that manually do this:

 ElementTree currentTree = workspace.getElementTree();
 currentTree.immutable();

and later on at some point:

 Method setTree = InternalBuilder.class.getDeclaredMethod("setLastBuiltTree", ElementTree.class);
 setTree.setAccessible(true);
 setTree.invoke(b, elementTree);
 setTree.setAccessible(false);

I do know that this is neither supported nor recommended. just saying that this seems to (for unknown reason) trigger this bug reproducibly on a completely fresh setup workspace (open eclipse, clone repo, build workspace, setLastTree on all built projects to avoid autobuild, close eclipse -> boom). All this is running headlessly for me. We are calling ResourcesPlugin.getWorkspace().save(true, null); explicitly at the end of the application)
Comment 11 Markus Duft CLA 2017-06-28 02:53:28 EDT
Oh, and we're seeing this on Mars.3 - forgot to mention :)
Comment 12 Ed Willink CLA 2019-03-05 11:54:41 EST
Same issue 2019-03RC1. Occurred after I installed a (QVTo) update and hit OK to restart after update. Got a errors during save pop-up, with inadequate details. Full details from the new log after the restart.

Looking at the code 

	while (table.get(parent) == null) {
		parent = parent.getParent();
	}

it would seem that parent.getParent() can return null, for which table.get(parent) will likely be null giving the NPE. 

Seems like straightforward bad code. Only puzzle is why it isn't catastrophic.

---

Could not write workspace metadata 'E:/Development/Rusa/Workspace/.metadata/.plugins/org.eclipse.core.resources/.root/1611.tree'.

java.lang.NullPointerException
	at org.eclipse.core.internal.watson.ElementTreeWriter.sortTrees(ElementTreeWriter.java:128)
	at org.eclipse.core.internal.watson.ElementTreeWriter.writeDeltaChain(ElementTreeWriter.java:198)
	at org.eclipse.core.internal.resources.SaveManager.writeTree(SaveManager.java:2013)
	at org.eclipse.core.internal.resources.SaveManager.saveTree(SaveManager.java:1392)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1176)
	at org.eclipse.core.internal.resources.Workspace.save(Workspace.java:2338)
	at org.eclipse.ui.internal.ide.application.IDEWorkbenchAdvisor.lambda$1(IDEWorkbenchAdvisor.java:509)
	at org.eclipse.jface.operation.ModalContext$ModalContextThread.run(ModalContext.java:122)
Comment 13 Eclipse Genie CLA 2019-06-24 04:06:02 EDT
New Gerrit change created: https://git.eclipse.org/r/144699
Comment 15 Andrey Loskutov CLA 2019-06-24 04:59:59 EDT
(In reply to Eclipse Genie from comment #14)
> Gerrit change https://git.eclipse.org/r/144699 was merged to [master].
> Commit:
> http://git.eclipse.org/c/platform/eclipse.platform.resources.git/commit/
> ?id=aea444e0ebf5594b82657dac23457204d21b2395

This is not a fix, it just improves diagnostics around the error case, so that we probably could have more details next time it happens.
Comment 16 Paul Pazderski CLA 2019-06-27 11:25:06 EDT
Just got this stacktrace with I20190627-0135

java.lang.NullPointerException: null parent found while collapsing trees
	at org.eclipse.core.internal.resources.SaveManager.sortTrees(SaveManager.java:1544)
	at org.eclipse.core.internal.resources.SaveManager.collapseTrees(SaveManager.java:320)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1208)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1143)
	at org.eclipse.core.internal.resources.DelayedSnapshotJob.run(DelayedSnapshotJob.java:55)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)

Not sure but I think I was closing some projects in Package Explorer at the moment.
Comment 17 Andrey Loskutov CLA 2019-06-27 11:29:31 EDT
(In reply to Paul Pazderski from comment #16)
> Just got this stacktrace with I20190627-0135
> 
> java.lang.NullPointerException: null parent found while collapsing trees
> 	at
> org.eclipse.core.internal.resources.SaveManager.sortTrees(SaveManager.java:
> 1544)
> 	at
> org.eclipse.core.internal.resources.SaveManager.collapseTrees(SaveManager.
> java:320)
> 	at
> org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1208)
> 	at
> org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1143)
> 	at
> org.eclipse.core.internal.resources.DelayedSnapshotJob.
> run(DelayedSnapshotJob.java:55)
> 	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)
> 
> Not sure but I think I was closing some projects in Package Explorer at the
> moment.

Was there any other error before/after in the log? Was the Eclipse session properly terminated, and the next time you started there were no errors in the log?
Comment 18 Paul Pazderski CLA 2019-06-27 11:41:02 EDT
Created attachment 279111 [details]
error before

For the (I think unrelated) error before see attachment.

There was no eclipse termination involved. After I now restarted eclipse no new errors appeared.
Comment 19 Paul Pazderski CLA 2019-06-27 11:42:11 EDT
After a second look on the stacktrace. Maybe it is not so unrelated as i thought.
Comment 20 Andrey Loskutov CLA 2019-06-27 11:52:52 EDT
(In reply to Paul Pazderski from comment #19)
> After a second look on the stacktrace. Maybe it is not so unrelated as i
> thought.

Not sure where the stack shows cycle (as supposed by the code, we should see .compute() call on the stack but there is no one), but this all is in UI and most likely unrelated to the resources tree error.
Comment 21 Eclipse Genie CLA 2021-06-17 13:35:56 EDT
This bug hasn't had any activity in quite some time. Maybe the problem got resolved, was a duplicate of something else, or became less pressing for some reason - or maybe it's still relevant but just hasn't been looked at yet. As such, we're closing this bug.

If you have further information on the current state of the bug, please add it and reopen this bug. The information can be, for example, that the problem still occurs, that you still want the feature, that more information is needed, or that the bug is (for whatever reason) no longer relevant.

--
The automated Eclipse Genie.
Comment 22 Ed Willink CLA 2021-06-17 14:27:31 EDT
Given that repros and partial fixes have been discussed, it surely requires a relevant committer rather than a Genie to declare CLOSED?
Comment 23 Jörg Kubitz CLA 2022-01-18 07:30:19 EST
(In reply to Andrey Loskutov from comment #15)
> This is not a fix, it just improves diagnostics around the error case, so
> that we probably could have more details next time it happens.

Happened to me several times in a row that i got multiple errors which may be somehow connected:

The project description file (.project) for 'disclosed projectname' was missing.  This file contains important information about the project.  A new project description file has been created, but some information about the project may have been lost.

----

null parent found while collapsing trees

eclipse.buildId=4.22.0.I20211124-1800

java.lang.NullPointerException: null parent found while collapsing trees
	at org.eclipse.core.internal.resources.SaveManager.sortTrees(SaveManager.java:1542)
	at org.eclipse.core.internal.resources.SaveManager.collapseTrees(SaveManager.java:320)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1208)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1143)
	at org.eclipse.core.internal.resources.DelayedSnapshotJob.run(DelayedSnapshotJob.java:55)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)


----
Could not write workspace metadata 'C:/wamas/workspace/w5_14_target/.metadata/.plugins/org.eclipse.core.resources/.root/71.tree'.

java.io.IOException: null parent found while sorting trees
	at org.eclipse.core.internal.watson.ElementTreeWriter.sortTrees(ElementTreeWriter.java:129)
	at org.eclipse.core.internal.watson.ElementTreeWriter.writeDeltaChain(ElementTreeWriter.java:201)
	at org.eclipse.core.internal.resources.SaveManager.writeTree(SaveManager.java:2000)
	at org.eclipse.core.internal.resources.SaveManager.saveTree(SaveManager.java:1384)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1168)
	at org.eclipse.core.internal.resources.Workspace.save(Workspace.java:2354)
	at org.eclipse.ui.internal.ide.application.IDEWorkbenchAdvisor.lambda$1(IDEWorkbenchAdvisor.java:554)
	at org.eclipse.jface.operation.ModalContext$ModalContextThread.run(ModalContext.java:122)


----
null parent found while collapsing trees

java.lang.NullPointerException: null parent found while collapsing trees
	at org.eclipse.core.internal.resources.SaveManager.sortTrees(SaveManager.java:1542)
	at org.eclipse.core.internal.resources.SaveManager.collapseTrees(SaveManager.java:320)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1208)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1143)
	at org.eclipse.core.internal.resources.DelayedSnapshotJob.run(DelayedSnapshotJob.java:55)
	at org.eclipse.core.internal.resources.SaveManager.shutdown(SaveManager.java:1418)
	at org.eclipse.core.internal.resources.Workspace.close(Workspace.java:621)
	at org.eclipse.core.resources.ResourcesPlugin.stop(ResourcesPlugin.java:451)
	at org.eclipse.osgi.internal.framework.BundleContextImpl.lambda$3(BundleContextImpl.java:862)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at org.eclipse.osgi.internal.framework.BundleContextImpl.stop(BundleContextImpl.java:856)
	at org.eclipse.osgi.internal.framework.EquinoxBundle.stopWorker0(EquinoxBundle.java:1033)
	at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.stopWorker(EquinoxBundle.java:370)
	at org.eclipse.osgi.container.Module.doStop(Module.java:660)
	at org.eclipse.osgi.container.Module.stop(Module.java:521)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.decStartLevel(ModuleContainer.java:1874)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1757)
	at org.eclipse.osgi.container.SystemModule.stopWorker(SystemModule.java:275)
	at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle$EquinoxSystemModule.stopWorker(EquinoxBundle.java:208)
	at org.eclipse.osgi.container.Module.doStop(Module.java:660)
	at org.eclipse.osgi.container.Module.stop(Module.java:521)
	at org.eclipse.osgi.container.SystemModule.stop(SystemModule.java:207)
	at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle$EquinoxSystemModule.lambda$0(EquinoxBundle.java:224)
	at java.base/java.lang.Thread.run(Thread.java:829)
Comment 24 Jörg Kubitz CLA 2022-02-03 10:50:46 EST
Created attachment 287974 [details]
Screenshot oldest ElementTree

i just hit it again in Thread [Worker-43: Periodic workspace save.] (Suspended (breakpoint at line 1542 in org.eclipse.core.internal.resources.SaveManager))	
	org.eclipse.core.internal.resources.SaveManager.sortTrees(org.eclipse.core.internal.watson.ElementTree[]) line: 1542	
	org.eclipse.core.internal.resources.SaveManager.collapseTrees(java.util.Map<java.lang.String,org.eclipse.core.internal.resources.SaveContext>) line: 320	
	org.eclipse.core.internal.resources.SaveManager.save(int, boolean, org.eclipse.core.internal.resources.Project, org.eclipse.core.runtime.IProgressMonitor) line: 1208	
	org.eclipse.core.internal.resources.SaveManager.save(int, org.eclipse.core.internal.resources.Project, org.eclipse.core.runtime.IProgressMonitor) line: 1143	
	org.eclipse.core.internal.resources.DelayedSnapshotJob.run(org.eclipse.core.runtime.IProgressMonitor) line: 55	
	org.eclipse.core.internal.jobs.Worker.run() line: 63	

trees was something like (element->parent):
ElementTree(8528)->ElementTree(8531)
ElementTree(9000)->ElementTree(9003)
ElementTree(9000)->ElementTree(9003)
ElementTree(9000)->ElementTree(9003)
ElementTree(9000)->ElementTree(9003)
ElementTree(9000)->ElementTree(9003)
ElementTree(9046)->ElementTree(9049)
ElementTree(9046)->ElementTree(9049)
ElementTree(9046)->ElementTree(9049)
ElementTree(9046)->ElementTree(9049)
ElementTree(9046)->ElementTree(9049)
...
ElementTree(11853)->null

so the trees contained a lot of duplicate elements, but that last element was distinct. there was not a single element where e1.getParent()==e2.
ElementTree.findOldest(trees) was some element in the middle of trees.
oldest.parent() was null (see "Screenshot oldest ElementTree")
"i" was somewhere in the middle
and oldest == trees[trees.length-1]


System.out.println("x"+Arrays.stream(trees).map(et->{ElementTree e=et;while (e.getParent()!=null) {e=e.getParent();} return e.toString();} ).distinct().collect(Collectors.joining("\n")));

was ElementTree(11853) .

I do not know what this code is about, but that oldest.parent() may be null is pretty allowed. (i got a 250MB heap dump if that helps)
I do not understand the javadoc expecially not that one for findOldest; what is meant with THE oldest tree? Only the root of a tree is uniquely defined by the parent relationship.
Comment 25 Jörg Kubitz CLA 2022-04-29 09:26:59 EDT
Created attachment 288491 [details]
ErrorMsg from 2022-04-09.txt

Got an event with enhanced logging - unfortunately quiet long - attached. 
The bugnumber in the error message is wrong though;-)

java.lang.NullPointerException: Given trees not in unambiguous order (Bug 35286): 
... (see file)

35577
	at org.eclipse.core.internal.resources.SaveManager.sortTrees(SaveManager.java:1557)
	at org.eclipse.core.internal.resources.SaveManager.collapseTrees(SaveManager.java:323)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1211)
	at org.eclipse.core.internal.resources.SaveManager.save(SaveManager.java:1146)
	at org.eclipse.core.internal.resources.DelayedSnapshotJob.run(DelayedSnapshotJob.java:55)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)
Comment 26 Jörg Kubitz CLA 2022-04-29 09:33:06 EDT
there are (at least) two different trees with same parent:
34814->34823->..
34820->34823->..
Comment 27 Jörg Kubitz CLA 2022-04-29 09:50:33 EDT
And even complete different trees of trees emerged from 34730 like
34715->34719->34720->34721->34724->34725->34726->34730
34694->34697->34698->34699->34702->34703->34704->34730
Comment 28 Michael Haubenwallner CLA 2023-03-28 10:19:49 EDT
For an idea of what could cause this issue:

Imagine a number of bundles with some particular build order, having some (evil) builder in a bundle built later updating some content in a bundle built earlier.

To me, this would explain whatever ambiguous state of delta trees, because:

The change to the earlier built bundle would require another build iteration there. If that build iteration is not executed for whatever reason, but another bundle depending on that one actually is built, some last-built trees refer to different versions of the same content in the early bundle, which indeed feels ambiguous - with additional auto build iterations being able to resolve.

Does this make sense at all?