Repository navigation
Report the real reason a mount fails instead of a broken pipe - #2105
Tyrie Vella (tyrielv) wants to merge 5 commits into
Conversation
93cdb36 to
4e4ec42
Compare
When GVFS.Mount failed to mount, the client printed a transport error:
Could not connect to GVFS.Mount: BrokenPipeException: Unable to send: GetStatus
The real cause was written only to the mount process log. A user hitting a
ProjFS attach failure on a Dev Drive got no cause and no remedy, although
the mount process had already diagnosed it.
Two defects combined to lose the reason.
First, FailMountAndExit called fileSystemCallbacks.Dispose(), which reached
GitIndexProjection.Dispose(bool) and called Task.Dispose() on the still
running index-parsing thread. Shutdown() had not run, so the task was not in
a completion state and Task.Dispose threw InvalidOperationException. That
secondary exception killed the process before it could serve a GetStatus
response.
Second, even without the exception, FailMountAndExit called Environment.Exit
immediately after setting MountState.MountFailed. The client polls GetStatus
every 100ms, so the process usually died before the client observed the
state. MountState.MountFailed and the GetStatus.MountFailed response already
existed but were never seen.
Changes:
- GitIndexProjection.Dispose(bool) only disposes the index-parsing task once
it has completed. A Task holds no unmanaged resources, so skipping the
call is safe, and it no longer throws during a failed mount.
- FailMountAndExit keeps the named pipe answering GetStatus after a failure,
and exits once a client has read MountFailed. Callbacks are disposed after
the failure is reported, and disposal exceptions are logged instead of
terminating the process. A latch makes the first failing thread the only
one that tears down and exits.
The wait is deliberately short. Until the process exits it still holds the
mount lock and its named pipe, and a "gvfs mount" retry inside that window
hits IsExistingPipeListening and is told "The repo at ... is already
mounted" with exit code Success. So the wait is capped at 2 seconds, or
500ms when no client has polled GetStatus at all, and normally ends on the
client's next poll, about 100ms. Failures raised before the pipe server
starts do not wait; MountVerb already detects those through the mount
process exit code.
- GetStatus.Response carries a MountError field, so WaitUntilMounted prints
the mount process's own message rather than "Failed to mount at <path>".
- StartVirtualizing failures with 0x800701DE
(ERROR_FILE_SYSTEM_VIRTUALIZATION_NOT_AVAILABLE) name the cause and the
remedy: PrjFlt cannot attach to the volume, and on a Dev Drive it must be
allowed with "fsutil devdrv setfiltersallowed PrjFlt".
Tests: disposing a projection whose parsing thread is still running must not
throw, and WaitUntilMounted must surface MountError when the mount process
sends one, falling back to the generic message when it does not. Both fail
against the unfixed code.
Assisted-by: Claude Opus 5
Signed-off-by: Tyrie Vella <tyrielv@gmail.com>
4e4ec42 to
9ba27f1
Compare
Verified the original fix end-to-end on a real ReFS Dev Drive with PrjFlt not on the allowed-filter list. The baseline reproduced the reported BrokenPipeException exactly, and this branch now prints the real cause. That run, plus a multi-perspective self-review, turned up several defects in the first version of this change. Fix a second copy of the disposal bug. The repro showed the InvalidOperationException still being thrown after the GitIndexProjection fix, now from BackgroundFileSystemTaskRunner.Dispose, which disposes its own still-running Task. Only the new try/catch kept the report alive. Both classes now drop the Task.Dispose call outright rather than guarding it: a Task holds no unmanaged resources and Task.Dispose is legacy IAsyncResult cleanup. Correct the Dev Drive remedy, which was wrong and destructive. It advised "fsutil devdrv setfiltersallowed PrjFlt". Without /volume that applies to every developer volume on the machine, and setFiltersAllowed replaces the list rather than appending to it, so following the advice would drop filters the machine already requires. The message now names the enlistment's own volume, tells the user to read the current list first, and says the list is replaced. Do not let message formatting hang the mount process. FailMountAndExit formatted the message twice, and the second call was unprotected. A malformed format string threw there, and an outer catch block then re-entered FailMountAndExit on the same thread, where the latch parked it forever holding the mount lock and the pipe. Format once, and make the latch re-entrant for the thread that already owns it. Other fixes from the review: - Only count a client that actually received a status. clientPolledStatus was set before the send succeeded, so a client that connected and disconnected still extended the wait. - Raise the drain above the client's 100ms poll interval. Any client can satisfy the wait, so a concurrent "gvfs status" could consume the signal while the mounting client was still sleeping. - Trace the report timeout and the swallowed disposal exception with Keywords.Telemetry. Without it, a failure that used to be a process-fatal crash became invisible in the field. - Shorten the test's server-task wait so a failing assertion is not delayed. Adds a regression test for the BackgroundFileSystemTaskRunner disposal. Both disposal tests are mutation-checked. Assisted-by: Claude Opus 5 Signed-off-by: Tyrie Vella <tyrielv@gmail.com>
The failure-reporting change had grown to three constants, four fields and two methods inside InProcessMount, a 2158-line class that already carried 74 private fields. The state was cohesive but scattered, and it was reachable from only five places, so it moves out cleanly. MountFailureReporter now owns the handshake: the ownership latch, the published failure message, the pipe-ready and client-received flags, the bounded wait, and the safe message formatting. InProcessMount keeps the policy that belongs to it -- the MountFailed state transition, tracing, disposal, and process exit. Ownership is expressed as a MountFailureOwnership enum (Owner, Reentrant, NotOwner) rather than a bare interlocked int, so the re-entrant case is named instead of implied by a thread-id comparison at the call site. The class lives in GVFS.Common/NamedPipes beside the protocol it implements. The client half of the same handshake, GVFSEnlistment.WaitUntilMounted, is already in GVFS.Common, so both halves now sit together. Placing it there also makes the state machine testable. GVFS.UnitTests references GVFS.Common but not GVFS.Mount, so while this logic lived in InProcessMount none of it could be covered, and CI runs only GVFS.UnitTests. Adds 11 tests for ownership and re-entrancy, the wait and its two timeouts, the distinction between a status that carried the failure and one that did not, and the formatting fallback. Two are mutation-checked. No behavior change. Verified on the same ReFS Dev Drive repro: the mount still prints the real ProjFS cause, and the mount log has no disposal exception and no report timeout. Assisted-by: Claude Opus 5 Signed-off-by: Tyrie Vella <tyrielv@gmail.com>
A second self-review pass over the extraction. No defects were found -- every finding was a judgement call, and the security, async and rollout lenses were clean -- but three were worth acting on. Narrow the public surface. The three Default* timeout constants are read nowhere outside the class, so they are now internal. GVFS.Common already grants InternalsVisibleTo to GVFS.UnitTests, so the tests still see them. The class and the ownership enum stay public because GVFS.Mount consumes them across an assembly boundary. Cover the public constructor. Every test built the reporter through the internal test constructor, so nothing exercised the public one or its forwarding of the Default* constants. Swapping DefaultReportTimeoutMs and DefaultNoClientTimeoutMs would have shipped unnoticed. Two tests now close that: one drives the public constructor down the no-client path, and one asserts the ordering invariants the constants have to satisfy. Mutation-checked by swapping the two values. Cut the fixture's wall-clock cost. One test has to wait out the long timeout to prove the long timeout was selected, and the fixture's own constants made that 2000ms. They are arbitrary -- they only have to be far enough apart to tell the two paths apart -- so the long one drops to 600ms. The assertion now checks against the short timeout rather than a fixed margin below the long one, which is what actually proves the selection. Fixture time falls from ~2.9s to ~2.0s. Also: document why InProcessMount deliberately never disposes the reporter, and stop discarding the result of the stand-in server's Wait so a hung server task is reported instead of silently faulting. Measured on this machine: 977 tests pass, and the timing assertions survived six consecutive runs with all twelve cores saturated. Assisted-by: Claude Opus 5 Signed-off-by: Tyrie Vella <tyrielv@gmail.com>
Nathan Baird (ShiningMassXAcc)
left a comment
Nathan Baird (ShiningMassXAcc)
left a comment
There was a problem hiding this comment.
Review pass over this PR. 10 comment(s).
These findings concern code the diff does not touch directly, so GitHub cannot anchor them inline:
GVFS/GVFS.Mount/InProcessMount.cs (around line 746) - HIGH
I think this reintroduces the failure mode the PR exists to remove.
HandleRequest's guard short-circuits only on MountState.Mounting, deliberately leaving MountFailed unguarded so HandleUnmountRequest stays reachable. That was safe when Environment.Exit followed microseconds later. It is not safe now: WaitForClientToReadFailure holds the process in MountFailed for up to 2 seconds, and that window is wide enough to take real traffic.
HandleReleaseLockRequest has no state check at all and dereferences this.fileSystemCallbacks unconditionally at line 1030. For most mount failures that field is still null — it is not assigned until line 1581, well past where failures occur. GVFS.Hooks sends ReleaseLock at the end of every git command, so any git command running while a mount fails lands here.
The result is a NullReferenceException, rethrown at 814-822, caught by NamedPipeServer.LogErrorAndExit, which calls Environment.Exit(GenericError) — tearing down the process mid-handshake and producing exactly the broken pipe this PR is fixing, now with the real reason lost.
The same path is reachable via 1023-1027 when RequestData is null, which calls UnmountAndStopWorkingDirectoryCallbacks() concurrently with the disposal at line 694.
Suggest allowing only GetStatus and Unmount while in MountFailed and replying MountNotReadyResult to everything else, rather than enumerating states to block.
GVFS/GVFS.Mount/InProcessMount.cs (around line 1549) - MEDIUM
HandleUnmountRequest treats MountFailed as goto case Ready, which has three consequences during the new 2-second window:
- The process exits with
ReturnCode.Successafter a failed mount. - State flips to
Unmounting, so the client's nextGetStatusseesUnmountingrather thanMountFailedand polls to its full 60-second timeout instead of reporting the failure it was about to receive. UnmountAndStopWorkingDirectoryCallbacks()runs on the pipe thread while the owner thread is disposingfileSystemCallbacksat line 694.
Worth noting this overlaps directly with #2131 ("Fix GVFS.Mount exiting 0 on failure") — might be cleanest to settle the exit-code question in one place.
GVFS/GVFS.Mount/InProcessMount.cs (around line 709) - MEDIUM
Three branches that decide whether this feature works are not covered:
FailMountAndExit's dispatch on theTryTakeOwnershipresult — theReentrantandNotOwneroutcomes behave differently and neither is exercised.HandleGetStatusRequestpopulatingMountErrorand callingOnStatusDeliveredonly whenTrySendResponsesucceeded. Thesentcheck at 1512 and the block at 1520-1525 are the hinge of the whole handshake: deliver-then-release. If that inverts, the process can exit before the client reads, and the unit tests would not notice.BuildProjFsAttachRemedy— a pure static string builder with a<volume>fallback, so it is cheap to test and currently untested.
MountFailureReporter itself is thoroughly tested; it is the InProcessMount side of the contract that is not.
GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs - LOW
FormatFailureFallsBackWhenTheFormatStringIsMalformed deliberately drives a FormatException, so it needs [Category(CategoryConstants.ExceptionExpected)] per CONTRIBUTING.md — otherwise it trips exception-monitoring in CI.
A reviewer found that the failure handshake could bring back the failure it exists to remove. This commit fixes that and the other review findings. HandleRequest answered every request except GetStatus while the mount was in the MountFailed state. HandleReleaseLockRequest then read fileSystemCallbacks, which is still null when the mount fails before that field is set. The NullReferenceException ended the process through NamedPipeServer, and the client saw a broken pipe with the real reason lost. A mount that fails in ValidateHooksVersion reproduces it: a ReleaseLock sent while the process waits for the client killed it. While the state is MountFailed, the mount process now answers only GetStatus and Unmount. It answers every other request with MountNotReady, the same reply it gives while mounting. An Unmount request in the MountFailed state used to start a teardown on the pipe thread, race the thread that reports the failure, and exit with Success. The process now replies MountFailed and does not tear down, because the failing mount is already ending the process. UnmountVerb already prints "previous mount attempt failed" for that reply. gvfs service --unmount-all now skips a repo in the MountFailed state, as it already skips one that is unmounting, so the installer does not report a failure for it. Other changes: - Rename the HRESULT constant to CantAttachToDevVolume. 0x800701DE is HRESULT_FROM_WIN32(ERROR_CANT_ATTACH_TO_DEV_VOLUME), which is 478. - Remove IDisposable from MountFailureReporter. Nothing disposes it, and a Dispose during a wait would make WaitOne throw. - Inject the wait, sleep, exit, and block operations through an internal IMountFailureEnvironment. The tests assert on the timeouts that the reporter requests, so they no longer measure elapsed time or sleep. - Move the ownership dispatch into TryBeginFailure and the send-then-record step into TrySendStatus, so both can be tested. The tests cover the re-entrant and other-thread outcomes, a failed send, and both wait timeouts. - Add GVFSEnlistment.MountStatusPollIntervalMs. The client poll and the drain after the failure now derive from it. - Test BuildProjFsAttachRemedy. - Mark the malformed-format test ExceptionExpected, and use a mock: path. - Reduce the history comments to the invariants that they protect. Verified on a ReFS Dev Drive. On the old build, a ReleaseLock or Unmount sent during the failure killed the process or started a teardown, and the client printed a broken pipe. On this build, the client prints the real reason in three of three runs, with no NullReferenceException. Assisted-by: Claude Opus 5 Signed-off-by: Tyrie Vella <tyrielv@gmail.com>
|
Note 🤖 Machine-drafted reply, reviewed and approved by Tyrie Vella (@tyrielv) before posting. On the HIGH finding about I reproduced it on a real failing mount. A GVFS.Hooks binary with a different version makes I took your suggestion. While the state is The Dev Drive scenario in the PR description did not crash on the old build. There, |
|
Note 🤖 Machine-drafted reply, reviewed and approved by Tyrie Vella (@tyrielv) before posting. On the MEDIUM finding about With the same probe on the old build, an
On #2131: it touches no file in this PR, and I did not change exit codes here. I left the exit-code question to that PR. |
|
Note 🤖 Machine-drafted reply, reviewed and approved by Tyrie Vella (@tyrielv) before posting. On the MEDIUM finding about untested branches: partly addressed in d84568b.
Two things stay in |
2 participants
Problem and Context
When a mount fails,
gvfs mountprints a transport error:The message names no cause and no remedy. The mount process knows the cause and writes it only to its own log.
Example: on a ReFS Dev Drive, ProjFS returns
0x800701DE(ERROR_CANT_ATTACH_TO_DEV_VOLUME) when PrjFlt is not on the volume's allowed-filter list. The user sees the broken pipe, not this cause.Version 1.0 attached ProjFS in the client process, so the user saw the failure directly. Version 2.0 moved this work into
GVFS.Mount. The client now depends on the named pipe to carry the failure back. Two defects stop that:FailMountAndExitdisposesFileSystemCallbacks.GitIndexProjectionandBackgroundFileSystemTaskRunnercallTask.Dispose()on a task that still runs.Task.Dispose()throwsInvalidOperationExceptionunless the task is complete. The exception ends the process before it answersGetStatus.FailMountAndExitcallsEnvironment.Exitright after it setsMountFailed. The client pollsGetStatusevery 100 ms, so the process usually exits first and the pipe breaks.MountState.MountFailedand theMountFailedresponse already exist. The client never sees them.This change fixes error reporting only. It does not enable the ProjFS filter on a Dev Drive.
Changes
GitIndexProjectionandBackgroundFileSystemTaskRunnerno longer callTask.Dispose()on their background task. ATaskholds no unmanaged resources. Disposal of a failed mount no longer throws.New
MountFailureReporterinGVFS.Common/NamedPipesholds the handshake state. It stores the failure message, decides which thread owns failure handling, and waits for a client to readMountFailed. It sits next toGVFSEnlistment.WaitUntilMounted, the client half of the same protocol, andGVFS.UnitTestscan reach it. An internalIMountFailureEnvironmentsupplies the wait, sleep, exit, and block operations, so tests do not use real delays or end the test host.InProcessMount.FailMountAndExitnow runs in this order:TryBeginFailure.MountFailedand log the error.An exception from disposal is logged with the telemetry keyword and does not stop the exit. A second call on the owning thread exits at once. A call on another thread blocks until the process exits.
The wait is short and bounded:
GVFSEnlistment.MountStatusPollIntervalMs, the interval thatWaitUntilMountedsleeps on.A failure before the pipe opens does not wait.
MountVerbreads the exit code of the mount process in that case.While it waits, the failed process holds the mount lock and the pipe.
GVFS.Mountopens the pipe before authentication, cache resolution, and virtualization. The pipe therefore already answers for the whole mount attempt, and the wait adds at most 2 s to that window.While the state is
MountFailed,HandleRequestanswers onlyGetStatusandUnmount. Every other request getsMountNotReady, the reply it gives while mounting. A mount can fail beforefileSystemCallbacksexists, and a handler such asReleaseLockwould then throw and end the process.An
Unmountrequest in theMountFailedstate now repliesMountFailedand does not tear down. The failing mount is already ending the process, and a teardown on the pipe thread raced it and exited withSuccess.UnmountVerbalready prints "previous mount attempt failed" for that reply.gvfs service --unmount-allnow skips a repo in this state, as it already skips one that is unmounting.NamedPipeMessages.GetStatus.Responsehas a newMountErrorfield.WaitUntilMountedprints it. If the field is missing,WaitUntilMountedprints the previousFailed to mount at <path>message. The field is additive, so old and new versions work together.WindowsFileSystemVirtualizer.TryStartadds a remedy to the0x800701DEfailure. The message names the enlistment's volume. It tells the user to read the allowed filters withfsutil devdrv query, then set the list again with PrjFlt added.fsutil devdrv setFiltersAllowedreplaces the whole list, and without/volumeit applies to every developer volume. The message states this.Tests:
MountFailureReporterTestscovers ownership, including the re-entrant and other-thread cases, both wait timeouts, a status that carried the failure compared with one that did not, a failed send, the default timeout values, and the safe message formatting. The tests assert on the timeouts that the reporter requests. None of them measures time.ProjFsAttachRemedyTestscovers the remedy text and its fallback when no volume is known.WaitUntilMountedFailureReportingTestschecks thatWaitUntilMountedprintsMountError, and that it uses the generic message when the field is missing.GitIndexProjectionDisposeTestsandBackgroundFileSystemTaskRunnerDisposeTestscheck thatDisposedoes not throw while the background task runs.Validation
The unit tests cannot reproduce the Dev Drive failure, and they do not cover the request handling in
GVFS.Mount. Both were run on a real ReFS Dev Drive.A mount on a ReFS Dev Drive without PrjFlt in the allowed-filter list gave these results.
Release 2.0.26229.1:
This change:
The mount process log of the second run holds no
InvalidOperationException.A failure before
fileSystemCallbacksexists needs a different trigger. A GVFS.Hooks binary with a different version makesValidateHooksVersionfail. A probe sent a request every 20 ms through the named pipe while the mount failed:MountFailedReleaseLockNullReferenceExceptioninHandleReleaseLockRequest. The process ended and the client printed the broken pipe.GVFS.Hooks version (2.0.26281.1) does not match GVFS version (0.2.173.2).in 3 of 3 runs.UnmountAck. A teardown started and the client printed the broken pipe.MountFailed. The client printed the same real reason.