eclipse.platform icon indicating copy to clipboard operation
eclipse.platform copied to clipboard

API analysis -> "Illegal attempt to modify an immutable tree" on deleting resources

Open iloveeclipse opened this issue 3 years ago • 10 comments

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.

iloveeclipse avatar Oct 03 '22 18:10 iloveeclipse

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)

jukzi avatar Oct 03 '22 19:10 jukzi

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.

iloveeclipse avatar Oct 03 '22 19:10 iloveeclipse

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.

iloveeclipse avatar Oct 06 '22 15:10 iloveeclipse

Why would a save job run at startup? immutable tree - You could try collecting Stacktraces to AbstractDataTree.immutable()

jukzi avatar Oct 06 '22 16:10 jukzi

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.

iloveeclipse avatar Oct 06 '22 16:10 iloveeclipse

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) |

iloveeclipse avatar Jun 18 '23 12:06 iloveeclipse

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)

jukzi avatar Jan 29 '24 10:01 jukzi

regression from RUN_API_ANALYSIS_AS_JOB=true https://github.com/eclipse-pde/eclipse.pde/pull/1083

jukzi avatar Feb 01 '24 06:02 jukzi

See my comment above: https://github.com/eclipse-platform/eclipse.platform/issues/200#issuecomment-1596125989

iloveeclipse avatar Feb 01 '24 07:02 iloveeclipse

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.

jukzi avatar Feb 01 '24 07:02 jukzi

closing as parallel analysis is not default anymore

jukzi avatar Jan 08 '25 14:01 jukzi