Skip to content

fix(logs): skip log collection in Asset Import Workers, allow shared-handle Clear (#855) - #967

Open
Nghaiz wants to merge 2 commits into
IvanMurzak:mainfrom
Nghaiz:fix/855-asset-import-worker-log-file-lock
Open

fix(logs): skip log collection in Asset Import Workers, allow shared-handle Clear (#855)#967
Nghaiz wants to merge 2 commits into
IvanMurzak:mainfrom
Nghaiz:fix/855-asset-import-worker-log-file-lock

Conversation

@Nghaiz

@Nghaiz Nghaiz commented Aug 25, 2026

Copy link
Copy Markdown

Fixes #855.

The other process is an Asset Import Worker

Console/ClearLogs throws The process cannot access the file '<project>/Temp/mcp-server/ai-editor-logs.txt' because it is being used by another process.

I asked Windows who the holder was, via the Restart Manager API (RmRegisterResources / RmGetList) on that exact path:

LOCK HOLDER: 51040 Unity
LOCK HOLDER: 28760 Unity

Their command lines:

Unity.exe -adb2 -batchMode -noUpm -name AssetImportWorker0 -projectPath D:/Coding/LTM/Ironfront_Reborn
          -logFile Logs/AssetImportWorker0.log -srvPort 64973 -parentPid 44868
Unity.exe -adb2 -batchMode -noUpm -name AssetImportWorker1 -projectPath D:/Coding/LTM/Ironfront_Reborn ...

Asset Import Workers are headless Editor processes on the same -projectPath. They load the Editor assemblies, so [InitializeOnLoad] Startup runs in each of them, calls AddUnityLogCollectorIfNeeded(() => new BufferedFileLogStorage()), and resolves Application.dataPath to the same folder as the main Editor. Every worker therefore opens the same ai-editor-logs.txt and holds a write handle for its whole lifetime.

Clear() disposes only the calling process's stream, then calls File.Delete. Windows refuses DeleteFile while any surviving handle omits FILE_SHARE_DELETE, and CreateWriteStream passes FileShare.ReadWrite. So the delete fails.

Not a race

The issue title says race condition. On my machine it is deterministic: 5 of 5 calls failed on a freshly opened, idle Editor. It looks intermittent because it tracks worker lifetime, not timing. Workers persist after an import finishes, so:

State Console/ClearLogs
Any worker alive fails, every time
No worker alive succeeds, every time

Killing both workers and calling the tool again is the whole repro loop:

taskkill /PID 51040 /F ; taskkill /PID 28760 /F
→ Restart Manager: no holders
→ console-clear-logs: success, 1.9 MB log file deleted, console-get-logs returns []

Before that, same Editor, same session: isError: true on every call.

The mechanism in isolation, same message byte for byte:

FileShare.ReadWrite         → "The process cannot access the file ... used by another process."
FileShare.ReadWrite|Delete  → DELETE OK

What this changes

1. AddUnityLogCollectorIfNeeded returns early in a worker.

All seven call sites (Startup, Startup.Editor ×3, MainWindowEditor, McpListWindowBase, AssistedReauthService) funnel through that one method, so a single guard covers them. This is the root-cause half: a worker serves no MCP client, so its import chatter was only diluting the cache that console-get-logs reads.

I used -name AssetImportWorker* rather than Application.isBatchMode, deliberately. isBatchMode is also true for CI and for anyone running the Editor headless on purpose, and I did not want to silently disable log collection for them. And it matches on the value of -name, not on a substring of the whole command line, so a project stored under a folder called AssetImportWorkerRepro does not disable collection in its main Editor. There is a test for exactly that.

2. The log FileStream opens with FileShare.Delete.

Defence in depth for the general case. Asset Import Workers are the common second holder, not the only possible one, and any of them wedges Clear() today. With the flag on both the write and read opens, Clear() survives a foreign handle whatever opened it.

Two things I noticed but did not change

The uniquifying retry loop in CreateWriteStream is unreachable. It renames to -2, -3, up to 1000 attempts, but only when the open throws. FileShare.ReadWrite lets the second writer straight in, so the loop has never fired. Its intent (one file per process) would fix this class of problem at the source, but tightening the share mode to force it is a design call that belongs to you, not to a bug-fix PR. SecondStorage_SharesTheSamePathRatherThanForkingANewFile pins the current behaviour so the change is visible if you ever make it.

Concurrent appenders can overwrite each other. FileMode.Append in .NET seeks to end at open, not per write, so two processes that opened the file when it was empty both write from position 0. Garbled lines are then silently dropped by the catch in DeserializeLogEntry. The guard in change 1 removes the usual source of concurrency, so I left this alone.

Verification

Ran on Unity 6000.3.21f1, Windows 11, plugin 0.90.0, server 9.2.5:

  • Restart Manager identifying the two workers as the holders
  • kill workers → console-clear-logs succeeds → console-get-logs returns [] → the 1.9 MB file is gone
  • the FileShare mechanism reproduced standalone, both directions

Not run locally: the new tests. The package's test assembly is not compiled in a consumer project without a testables entry, and I did not want to reshape a working project to get there. They are written to fail before this patch by construction (Clear_SucceedsWhileASecondStorageHoldsTheSameFile throws the reported IOException without change 2), but CI is the first place they actually execute.

…handle Clear (IvanMurzak#855)

Console/ClearLogs failed with "The process cannot access the file
'<project>/Temp/mcp-server/ai-editor-logs.txt' because it is being used by
another process."

The other process is a Unity Asset Import Worker. Workers are headless Editor
instances launched with the same -projectPath as the main Editor, so each one
runs [InitializeOnLoad] Startup, builds its own BufferedFileLogStorage, and
resolves the identical log path. Their write handles then live as long as they
do.

Two changes:

1. AddUnityLogCollectorIfNeeded returns early in a worker. All seven call sites
   funnel through it, so one guard covers them. Workers serve no MCP client, so
   their import chatter was only noise in the cache anyway.

2. The log FileStream now opens with FileShare.Delete. Windows refuses
   DeleteFile while any open handle omits FILE_SHARE_DELETE, so without this any
   second holder wedges Clear() regardless of where it came from.

Adds detection tests for the -name parsing and a fixture that pins Clear()
against a second storage on the same file.
=> IsAssetImportWorker(Environment.GetCommandLineArgs());

/// <summary>
/// Test-friendly overload. Matches only a <c>-name</c> / <c>--name</c> flag whose VALUE starts

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please explain what is going on here. Did you customize the log writing only if the project opened in the custom folder location? And it won't work for anybody else if their Unity project in a different location?

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, nothing is keyed to a folder location, and the check never reads the project path at all. That comment was badly worded and it reads exactly the way you took it. Sorry.

What IsAssetImportWorker actually reads is the -name argument Unity itself passes when it spawns a worker:

Unity.exe -adb2 -batchMode -noUpm -name AssetImportWorker0
          -projectPath <wherever that user's project happens to be> ...

The loop walks the args for a -name / --name flag and tests whether its value starts with AssetImportWorker. A main Editor is launched without a -name flag, so it returns false no matter where the project lives. No path is inspected or compared, and there is no hardcoded location in the function.

The AssetImportWorkerRepro folder in that comment was an example of a false positive the code avoids, not one it depends on. If the check were a substring scan of the whole command line, -projectPath would match too, and anyone whose project folder happened to contain that word would silently lose log collection in their main Editor. IsAssetImportWorker_FalseWhenOnlyThePathContainsTheWord is the test pinning that.

Rewritten in 9571844 to lead with what is actually read and to state outright that project location plays no part.

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you please provide a reference to the documentation about this "Unity worker" that Unity spawns with custom arguments?

On the first view it looks like an AI hallucination or some local context to a personal project.
I just want to be sure about this information, because this is the core proposition of this PR and I never heard about this workers processes earlier.

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fair challenge. The short version: the process type is documented, the argument I keyed on is not.

Import workers are a documented Unity feature

Unity Manual, "Parallel Import", present in 2022.3 and every version since:

The Parallel Import setting uses additional headless instances of the Editor, called import workers, to import assets in parallel

That same page documents the Project Settings controlling them, and one of those settings explains why #855 reads as a race:

Standby Import Worker Count: The minimum number of worker processes to keep, even if they're idle.

Unity keeps workers alive after the import finishes, deliberately. So their file handles outlive anything the user can see happening, which is exactly why the failure looks intermittent rather than tracking a visible state.

Two things you can confirm on your own machine in under a minute, without taking my word for any of it:

  • Project Settings > Editor > Asset Pipeline shows Desired Import Worker Count and Standby Import Worker Count.
  • <project>/Logs/AssetImportWorker0.log exists in any project that has imported anything. That is the worker's own Editor log, written via its -logFile argument.

Unity ships a public API for the exact check I hand-rolled

AssetDatabase.IsAssetImportWorkerProcess()

Determines whether the current process is an Asset Import Worker process.

https://docs.unity3d.com/ScriptReference/AssetDatabase.IsAssetImportWorkerProcess.html

It is public extern static in Unity's own C# reference source at 2022.3, which is this package's "unity" floor, and it is still there at 6000.3:

Unity's own editor code guards on it for the same reason this PR does, skipping work that belongs only to the main process. QuickSearch, at 2022.3:

https://github.com/Unity-Technologies/UnityCsReference/blob/a322ce5f78a82cf7ea211857a45338136ed7a22f/Modules/QuickSearch/Editor/SearchSettings.cs#L319

Where that leaves this PR

You were right to push, and here is the honest part: the -name AssetImportWorker0 argument itself is not documented anywhere I can find. I read it off the live processes on my machine. The concept is official, that particular spelling is not, and I should have looked for the API before writing a parser for an undocumented argument.

So I would rather this used AssetDatabase.IsAssetImportWorkerProcess(). It deletes the arg-parsing function outright, and the false-positive worry goes with it, because no command line is inspected at all. Concretely:

  • EnvironmentUtils.IsAssetImportWorker() becomes a #if UNITY_EDITOR call to the API, returning false in player builds, where workers cannot exist. The guard is needed because EnvironmentUtils lives in the Runtime assembly.
  • The two arg-parsing tests go away, since there is no pure function left to test.
  • The FileShare.Delete half in FileLogStorage is untouched by this and stays as is.

Since you have already approved, that swap is your call rather than mine: I can push it onto this branch, or leave this as it stands and send it as a follow-up. Either is fine by me.

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for clarifying. I see it now. And it is a good discovery, at least to me :)

…s and say plainly what the check reads

Review feedback on IvanMurzak#967.

The test fixtures carried my own drive letters (D:/UnityEditor/6000.3.21f1,
D:/Coding/Game) — the only D:/ strings in the whole test tree. They were inert
literals fed to a pure function, but nobody should have to verify that to trust
them. They now follow the convention the rest of the suite already uses
(/home/user/my-game, as in ProjectIdentityGoldenVectorTests).

The doc comment on IsAssetImportWorker read as though a folder name were being
special-cased. It was describing a false positive the code AVOIDS, not one it
relies on. Rewritten to lead with what is actually read — Unity's own -name
argument — and to state that no path is inspected, compared, or hardcoded, so
project location is irrelevant on any machine.

No behaviour change: same detection, same six assertions, all still passing.
@Nghaiz
Nghaiz requested a review from IvanMurzak August 25, 2026 08:42
@Nghaiz
Nghaiz requested a review from IvanMurzak August 27, 2026 04:06
@IvanMurzak

Copy link
Copy Markdown
Owner

I have a temporary issue with the test runners. Need to wait for a solution, then I will run the tests to verify that everything is green.

IvanMurzak added a commit that referenced this pull request Sep 3, 2026
Accuracy corrections to the fork-PR section, from two report-only review helpers
plus this pass's own verification against the GitHub API. Documentation only; no
behavioural change.

docs/claude/ci-unity-license.md
- #543 is CLOSED (state_reason=completed, 2026-03-15), so "tracked in issue #543
  and PR #971" sent a reader to a six-month-dead issue. PR #971 is the live one.
- The run-33758511822 table row said "this same workflow", whose nearest
  antecedent is row 1's test_pull_request.yml. The run actually used
  test_pull_request_manual.yml (API: path=.github/workflows/
  test_pull_request_manual.yml, head_branch=ci/p0-fork-license-repro). Named it.
- "starts and completes in the same second" is falsified by the section's own
  cited runs: 32992648441's 6000.3.1f1-editmode/windows-mono leg is
  04:58:48Z -> 04:58:49Z, and on the repro run 33758511822 one of the two legs is
  13:01:37Z -> 13:01:38Z. Restated as a bound ("within a second").
- "the whole job is 1-3 minutes" understated the measured spread; job wall clocks
  on 32992648441 run 1m23s - 3m14s. Now 1-4 minutes.
- The bad-.ulf ordering claim ("pulls the editor image first, then fails inside
  the container") was a hypothesis in declarative register - no bad-.ulf run is on
  record. Kept the diagnostic, marked it unverified, and grounded the "minutes"
  half on run 33757559794, whose licensed step takes 9-13 min per leg.
- Duration does not discriminate a fork PR from a same-repo run whose secret was
  deleted: UNITY_LICENSE is required:false, so both deliver an empty string and
  fail identically. Points at the head-repository check as the discriminator.
- "every run ... was red" was wrong for 4 of 7. All seven runs in the window are
  forks and none went green, but they are 3 failure / 2 cancelled / 2
  action_required. Corrected, and documented action_required (GitHub's
  first-time-contributor approval gate) as a second fork-PR shape with a
  different signature - conclusion is null and nothing ran.
- refs/pull/<n>/merge only exists while GitHub can compute a clean test-merge,
  neither ref is fetched by default, and workflow_dispatch takes only a branch or
  tag - so --ref refs/pull/<n>/head is rejected. That is what makes the deferral
  to #971 legible rather than unexplained.
- Gave "all 12 legs" its derivation (6 caller jobs x the 2-way platform matrix) so
  it self-corrects if the three commented-out playmode jobs are ever enabled.
- The pre-existing refresh procedure told a reader with an invalid-license run to
  re-issue the .ulf, which is the exact trap this section exists to prevent; added
  a one-clause back-pointer.

.github/workflows/test_unity_plugin.yml
- The comment blamed "secrets: inherit", a construct this file does not contain -
  it is the caller's. Attributed it to test_pull_request.yml.

NOT changed, after verification: "the same commit 91e2472 the fork PRs branched
from". One helper reported this as unverifiable and recommended weakening it. It
is exactly right - PRs #922/#967/#968 all have base.sha=91e2472a, and
`git merge-base --is-ancestor 91e2472 refs/pull/<n>/head` holds for all three
with the merge-base being 91e2472 itself. The claim stands as written.

Gates: Suite 4 (CI-surface) green - check_nuget_gate.py exit 0 ("NuGet gate OK:
15 pins, generation UNITY_MCP_DEPS_3, propagation consistent"), workflow YAML
re-parses with all three secrets keys and three inputs intact. Suites 1-3 not
applicable (nothing under Unity-MCP-Plugin/**, nothing under cli/); the
substantive verification of a CI-docs change is the PR's own CI run.
scan-pipeline-leaks.py: 0 hits over 108 added lines, controls 104/104.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Bac1LKpVobv1i1FNGCRNvM
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Race condition in FileLogStorage.Clear() / BufferedFileLogStorage.Clear() causes "file being used by another process" on Console/ClearLogs

2 participants