API analysis -> "Illegal attempt to modify an immutable tree" on deleting resources
I see sometimes (after updating to the next nightly snapshot) following error after startup & build of the workspace. The build that triggers automatically (because of changed platform) typically stumbles sometimes with this error:
!ENTRY org.eclipse.core.resources 4 2 2022-10-02 16:00:43.334
!MESSAGE Problems occurred when invoking code from plug-in: "org.eclipse.core.resources".
!STACK 0
java.lang.RuntimeException: Illegal attempt to modify an immutable tree.
at org.eclipse.core.internal.dtree.AbstractDataTree.handleImmutableTree(AbstractDataTree.java:169)
at org.eclipse.core.internal.dtree.DeltaDataTree.deleteChild(DeltaDataTree.java:374)
at org.eclipse.core.internal.watson.ElementTree.deleteElement(ElementTree.java:271)
at org.eclipse.core.internal.resources.Workspace.deleteResource(Workspace.java:1471)
at org.eclipse.core.internal.resources.Resource.deleteResource(Resource.java:865)
at org.eclipse.core.internal.resources.ResourceTree.deletedFile(ResourceTree.java:131)
at org.eclipse.core.internal.resources.ResourceTree.internalDeleteFile(ResourceTree.java:319)
at org.eclipse.core.internal.resources.ResourceTree.standardDeleteFile(ResourceTree.java:802)
at org.eclipse.core.internal.resources.Resource.unprotectedDelete(Resource.java:1798)
at org.eclipse.core.internal.resources.Resource.delete(Resource.java:771)
at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.cleanOutputFolders(BatchImageBuilder.java:140)
at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.build(BatchImageBuilder.java:65)
at org.eclipse.jdt.internal.core.builder.JavaBuilder.buildAll(JavaBuilder.java:273)
at org.eclipse.jdt.internal.core.builder.JavaBuilder.build(JavaBuilder.java:199)
at org.eclipse.core.internal.events.BuildManager$2.run(BuildManager.java:1024)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:254)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:311)
at org.eclipse.core.internal.events.BuildManager$1.run(BuildManager.java:400)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:403)
at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:514)
at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:462)
at org.eclipse.core.internal.events.BuildManager.build(BuildManager.java:544)
at org.eclipse.core.internal.events.AutoBuildJob.doBuild(AutoBuildJob.java:161)
at org.eclipse.core.internal.events.AutoBuildJob.run(AutoBuildJob.java:255)
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)
!ENTRY org.eclipse.core.resources 4 75 2022-10-02 16:02:24.553
!MESSAGE Errors occurred during the build.
!SUBENTRY 1 org.eclipse.jdt.core 4 75 2022-10-02 16:02:24.553
!MESSAGE Errors running builder 'Java Builder' on project 'org.eclipse.pde.api.tools'.
!STACK 0
java.lang.RuntimeException: Illegal attempt to modify an immutable tree.
at org.eclipse.core.internal.dtree.AbstractDataTree.handleImmutableTree(AbstractDataTree.java:169)
at org.eclipse.core.internal.dtree.DeltaDataTree.deleteChild(DeltaDataTree.java:374)
at org.eclipse.core.internal.watson.ElementTree.deleteElement(ElementTree.java:271)
at org.eclipse.core.internal.resources.Workspace.deleteResource(Workspace.java:1471)
at org.eclipse.core.internal.resources.Resource.deleteResource(Resource.java:865)
at org.eclipse.core.internal.resources.ResourceTree.deletedFile(ResourceTree.java:131)
at org.eclipse.core.internal.resources.ResourceTree.internalDeleteFile(ResourceTree.java:319)
at org.eclipse.core.internal.resources.ResourceTree.standardDeleteFile(ResourceTree.java:802)
at org.eclipse.core.internal.resources.Resource.unprotectedDelete(Resource.java:1798)
at org.eclipse.core.internal.resources.Resource.delete(Resource.java:771)
at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.cleanOutputFolders(BatchImageBuilder.java:140)
at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.build(BatchImageBuilder.java:65)
at org.eclipse.jdt.internal.core.builder.JavaBuilder.buildAll(JavaBuilder.java:273)
at org.eclipse.jdt.internal.core.builder.JavaBuilder.build(JavaBuilder.java:199)
at org.eclipse.core.internal.events.BuildManager$2.run(BuildManager.java:1024)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:254)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:311)
at org.eclipse.core.internal.events.BuildManager$1.run(BuildManager.java:400)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:403)
at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:514)
at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:462)
at org.eclipse.core.internal.events.BuildManager.build(BuildManager.java:544)
at org.eclipse.core.internal.events.AutoBuildJob.doBuild(AutoBuildJob.java:161)
at org.eclipse.core.internal.events.AutoBuildJob.run(AutoBuildJob.java:255)
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)
It seems someone operates on the tree in parallel to the build???
I wonder if the org.eclipse.core.internal.resources.DelayedSnapshotJob.run(IProgressMonitor) could be this someone? I've set workspace save interval to 1 minute, and the build after update takes usually longer.
I have otherwise no explanation why or which task is running in parallel.
i guess org.eclipse.core.internal.resources.SaveManager.restoreSnapshots(IProgressMonitor) modifies workspace.tree which could happen because BuildManager is initialies before SaveManager in org.eclipse.core.internal.resources.Workspace.startup(IProgressMonitor)
Look on comment (from https://bugs.eclipse.org/bugs/show_bug.cgi?id=44818)
/**
* Calls the move/delete hook to perform the deletion. Since this method calls
* client code, it is run "unprotected", so the workspace lock is not held.
*/
here: https://github.com/eclipse-platform/eclipse.platform/blob/8d1388e261fbffc48e46a9229effcfcbe10bdf4b/resources/bundles/org.eclipse.core.resources/src/org/eclipse/core/internal/resources/Resource.java#L1791
I haven't debugged that, but it should be possible to put breakpoint in org.eclipse.core.internal.resources.Resource.unprotectedDelete(ResourceTree, int, IProgressMonitor) and check if org.eclipse.core.internal.resources.DelayedSnapshotJob.run(IProgressMonitor) can run in parallel (or will wait on some other lock). If it doesn't wait, I wonder if the save manager should join build family jobs.
Looking on stack traces in https://bugs.eclipse.org/bugs/show_bug.cgi?id=578282 I think that this is in the fact a problem caused by "unprotected delete" change in https://bugs.eclipse.org/bugs/show_bug.cgi?id=44818 and most likely save job running in parallel.
Why would a save job run at startup? immutable tree - You could try collecting Stacktraces to AbstractDataTree.immutable()
Why would a save job run at startup?
I was not correctly explaining the case, I've updated description.
- I take new SDK build.
- Start with existing workspace.
- Because many dependencies are changed, autobuild triggers
- It builds almost all SDK projects
- At some point in time error is reported
- The error is reported during this build, and because I have set "workspace save" interval to 1 minute, it usually runs in parallel to this fist "full workspace build".
- I assume that if that save marks the tree as immutable at the point where the build is in "unprotected delete", so the build starts with "mutable" tree but ends with "immutable"
I just had no time yet to debug this, but I'm pretty sure it is something like explained above.
I just had no time yet to debug this, but I'm pretty sure it is something like explained above.
Debugging didn't reveal any problem in the "snapshot saving" code, so I've added tracing with #501 and that helped to find the problem.
It looks like PDE API analysis builder can trigger tree.immutable() (via IncrementalProjectBuilder.getDelta()) on a tree that is used by workspace build running at same time in parallel. This is because ApiAnalysisJob intentionally does no acquire workspace or project lock to be able to run in parallel to Java (auto) build (which runs using workspace rule).
To fix that one would set a project rule on the ApiAnalysisJob but this would postpone all the API analysis work after the build is done, also for all unrelated projects (currently autobuild locks entire workspace) ans also make all other jobs/tasks that use workspace blocked by API analysis execution.
Needs a deeper analysis how API analysis can be made properly working without side effects...
| Worker-20: Performing API Analysis | 2023-06-18 13:39:23.139 | org.eclipse.core.resources | /debug | org.eclipse.core.internal.utils.Policy | debug | 142 | org.eclipse.pde.api.tools.internal.builder.ApiAnalysisBuilder$ApiAnalysisJob(Performing API Analysis): java.lang.RuntimeException: immutable() called for DeltaDataTree ElementTree(582)-> ElementTree(581)-> depth 1-> ElementTree(581) / rootNode=DataDeltaNode with 1 children #196304683 (rule: org.eclipse.pde.api.tools.internal.builder.ApiAnalysisBuilder$ApiAnalysisJobRule@c5e64d2)
at org.eclipse.core.internal.dtree.AbstractDataTree.traceImmutable(AbstractDataTree.java:209)
at org.eclipse.core.internal.dtree.AbstractDataTree.immutable(AbstractDataTree.java:194)
at org.eclipse.core.internal.watson.ElementTree.immutable(ElementTree.java:528)
at org.eclipse.core.internal.events.ResourceDeltaFactory.computeDelta(ResourceDeltaFactory.java:46)
at org.eclipse.core.internal.events.BuildManager.lambda$7(BuildManager.java:972)
at org.eclipse.core.internal.events.BuildManager$DeltaCache.lambda$0(BuildManager.java:67)
at java.base/java.util.HashMap.computeIfAbsent(HashMap.java:1220)
at org.eclipse.core.internal.events.BuildManager$DeltaCache.computeIfAbsent(BuildManager.java:67)
at org.eclipse.core.internal.events.BuildManager.getDeltaCached(BuildManager.java:962)
at org.eclipse.core.internal.events.BuildManager.getDelta(BuildManager.java:954)
at org.eclipse.core.internal.events.InternalBuilder.getDelta(InternalBuilder.java:116)
at org.eclipse.core.resources.IncrementalProjectBuilder.getDelta(IncrementalProjectBuilder.java:285)
at org.eclipse.pde.api.tools.internal.builder.ApiAnalysisBuilder.getDeltas(ApiAnalysisBuilder.java:1295)
at org.eclipse.pde.api.tools.internal.builder.ApiAnalysisBuilder.work(ApiAnalysisBuilder.java:420)
at org.eclipse.pde.api.tools.internal.builder.ApiAnalysisBuilder$ApiAnalysisJob.run(ApiAnalysisBuilder.java:568)
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63) |
And that causes later following error:
| Worker-18: Building | 2023-06-18 13:39:23.143 | org.eclipse.core.resources | /debug | org.eclipse.core.internal.utils.Policy | debug | 142 | org.eclipse.core.internal.events.AutoBuildJob(Building): java.lang.RuntimeException: Illegal attempt to modify an immutable tree: DeltaDataTree ElementTree(582)-> null-> depth 0-> null / rootNode= DataTreeNode with 508 children #196304683.
at org.eclipse.core.internal.dtree.AbstractDataTree.handleImmutableTree(AbstractDataTree.java:172)
at org.eclipse.core.internal.dtree.DeltaDataTree.deleteChild(DeltaDataTree.java:374)
at org.eclipse.core.internal.watson.ElementTree.deleteElement(ElementTree.java:271)
at org.eclipse.core.internal.resources.Workspace.deleteResource(Workspace.java:1473)
at org.eclipse.core.internal.resources.Resource.deleteResource(Resource.java:865)
at org.eclipse.core.internal.resources.ResourceTree.deletedFile(ResourceTree.java:131)
at org.eclipse.core.internal.resources.ResourceTree.internalDeleteFile(ResourceTree.java:319)
at org.eclipse.core.internal.resources.ResourceTree.standardDeleteFile(ResourceTree.java:802)
at org.eclipse.core.internal.resources.Resource.unprotectedDelete(Resource.java:1798)
at org.eclipse.core.internal.resources.Resource.delete(Resource.java:771)
at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.cleanOutputFolders(BatchImageBuilder.java:140)
at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.build(BatchImageBuilder.java:65)
at org.eclipse.jdt.internal.core.builder.JavaBuilder.buildAll(JavaBuilder.java:273)
at org.eclipse.jdt.internal.core.builder.JavaBuilder.build(JavaBuilder.java:199)
at org.eclipse.core.internal.events.BuildManager$2.run(BuildManager.java:1023)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:247)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:303)
at org.eclipse.core.internal.events.BuildManager$1.run(BuildManager.java:392)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:395)
at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:506)
at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:454)
at org.eclipse.core.internal.events.BuildManager.build(BuildManager.java:536)
at org.eclipse.core.internal.events.AutoBuildJob.doBuild(AutoBuildJob.java:196)
at org.eclipse.core.internal.events.AutoBuildJob.run(AutoBuildJob.java:289)
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63) |
got it too (after enabling API analysis) eclipse.buildId=4.31.0.I20240128-1800 java.version=21.0.2
java.lang.RuntimeException: Illegal attempt to modify an immutable tree: DeltaDataTree ElementTree(9399)-> null-> depth 0-> null / rootNode= DataTreeNode with 529 children #2050256720.
at org.eclipse.core.internal.dtree.AbstractDataTree.handleImmutableTree(AbstractDataTree.java:170)
at org.eclipse.core.internal.dtree.DeltaDataTree.deleteChild(DeltaDataTree.java:374)
at org.eclipse.core.internal.watson.ElementTree.deleteElement(ElementTree.java:278)
at org.eclipse.core.internal.resources.Workspace.deleteResource(Workspace.java:1543)
at org.eclipse.core.internal.resources.Resource.deleteResource(Resource.java:897)
at org.eclipse.core.internal.localstore.RefreshLocalVisitor.deleteResource(RefreshLocalVisitor.java:107)
at org.eclipse.core.internal.localstore.RefreshLocalVisitor.synchronizeExistence(RefreshLocalVisitor.java:195)
at org.eclipse.core.internal.localstore.RefreshLocalVisitor.visit(RefreshLocalVisitor.java:302)
at org.eclipse.core.internal.localstore.UnifiedTree.accept(UnifiedTree.java:119)
at org.eclipse.core.internal.localstore.FileSystemResourceManager.refreshResource(FileSystemResourceManager.java:1021)
at org.eclipse.core.internal.localstore.FileSystemResourceManager.refresh(FileSystemResourceManager.java:1004)
at org.eclipse.core.internal.resources.AliasManager.updateAliases(AliasManager.java:632)
at org.eclipse.core.internal.resources.Resource.delete(Resource.java:820)
at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.cleanOutputFolders(BatchImageBuilder.java:140)
at org.eclipse.jdt.internal.core.builder.BatchImageBuilder.build(BatchImageBuilder.java:65)
at org.eclipse.jdt.internal.core.builder.JavaBuilder.buildAll(JavaBuilder.java:289)
at org.eclipse.jdt.internal.core.builder.JavaBuilder.build(JavaBuilder.java:205)
at org.eclipse.core.internal.events.BuildManager$2.run(BuildManager.java:1077)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:47)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:296)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:352)
at org.eclipse.core.internal.events.BuildManager$1.run(BuildManager.java:441)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:47)
at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:444)
at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:555)
at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:503)
at org.eclipse.core.internal.events.BuildManager.build(BuildManager.java:585)
at org.eclipse.core.internal.events.AutoBuildJob.doBuild(AutoBuildJob.java:207)
at org.eclipse.core.internal.events.AutoBuildJob.run(AutoBuildJob.java:300)
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)
regression from RUN_API_ANALYSIS_AS_JOB=true https://github.com/eclipse-pde/eclipse.pde/pull/1083
See my comment above: https://github.com/eclipse-platform/eclipse.platform/issues/200#issuecomment-1596125989
please consider disabling parallel until problem solved. To solve the issue it might work to synchronous read the delta and further process it in parallel.
closing as parallel analysis is not default anymore