From 9ba27f1c52d3db76e64e837a98d73809e5acf41e Mon Sep 17 00:00:00 2001 From: Tyrie Vella Date: Tue, 1 Sep 2026 11:05:20 -0700 Subject: [PATCH 1/4] Report the real reason a mount fails instead of a broken pipe 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 ". - 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 --- GVFS/GVFS.Common/GVFSEnlistment.cs | 4 +- .../NamedPipes/NamedPipeMessages.cs | 8 ++ GVFS/GVFS.Mount/InProcessMount.cs | 125 +++++++++++++++++- .../HResultExtensions.cs | 6 + .../WindowsFileSystemVirtualizer.cs | 8 ++ .../WaitUntilMountedFailureReportingTests.cs | 98 ++++++++++++++ .../GitIndexProjectionDisposeTests.cs | 59 +++++++++ .../Projection/GitIndexProjection.cs | 21 ++- 8 files changed, 322 insertions(+), 7 deletions(-) create mode 100644 GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs create mode 100644 GVFS/GVFS.UnitTests/Virtualization/Projection/GitIndexProjectionDisposeTests.cs diff --git a/GVFS/GVFS.Common/GVFSEnlistment.cs b/GVFS/GVFS.Common/GVFSEnlistment.cs index 7cd441aadb..51779cb385 100644 --- a/GVFS/GVFS.Common/GVFSEnlistment.cs +++ b/GVFS/GVFS.Common/GVFSEnlistment.cs @@ -281,7 +281,9 @@ public static bool WaitUntilMounted( } else if (getStatusResponse.MountStatus == NamedPipeMessages.GetStatus.MountFailed) { - errorMessage = string.Format("Failed to mount at {0}", enlistmentRoot); + errorMessage = !string.IsNullOrWhiteSpace(getStatusResponse.MountError) + ? getStatusResponse.MountError + : string.Format("Failed to mount at {0}", enlistmentRoot); tracer.RelatedError($"{nameof(WaitUntilMounted)}: Mount failed: {errorMessage}"); return false; } diff --git a/GVFS/GVFS.Common/NamedPipes/NamedPipeMessages.cs b/GVFS/GVFS.Common/NamedPipes/NamedPipeMessages.cs index 62447659ee..5d1e4794a4 100644 --- a/GVFS/GVFS.Common/NamedPipes/NamedPipeMessages.cs +++ b/GVFS/GVFS.Common/NamedPipes/NamedPipeMessages.cs @@ -36,6 +36,14 @@ public class Response { public string MountStatus { get; set; } public string MountProgress { get; set; } + + /// + /// Why the mount failed. Set only when is + /// , so the client can report the real cause + /// instead of a generic failure message. + /// + public string MountError { get; set; } + public string EnlistmentRoot { get; set; } public string LocalCacheRoot { get; set; } public string RepoUrl { get; set; } diff --git a/GVFS/GVFS.Mount/InProcessMount.cs b/GVFS/GVFS.Mount/InProcessMount.cs index 629be66138..b13863f6e1 100644 --- a/GVFS/GVFS.Mount/InProcessMount.cs +++ b/GVFS/GVFS.Mount/InProcessMount.cs @@ -41,6 +41,19 @@ public class InProcessMount // reliably trigger a commit pack download. private const int TrackedTreeCapacity = MissingTreeThresholdForDownloadingCommitPack * 20; + // Bounds how long a failed mount stays alive so a client can read the reason. + // Kept short on purpose: until the process exits it still holds the mount lock + // and its named pipe, so a user retrying "gvfs mount" would be told the repo is + // already mounted. The wait normally ends on the client's next poll (~100ms). + private const int MountFailureReportTimeoutMs = 2000; + + // Used instead when no client has polled GetStatus yet. It only has to cover the + // narrow window between the pipe opening and MountVerb's first poll. + private const int MountFailureNoClientTimeoutMs = 500; + + // Lets the response drain to the client before the pipe goes away. + private const int MountFailureDrainMs = 50; + private readonly bool showDebugWindow; private FileSystemCallbacks fileSystemCallbacks; @@ -59,6 +72,24 @@ public class InProcessMount private volatile MountState currentState; private volatile string mountProgressMessage; + // Why the mount failed. Sent to the client in the GetStatus response so it can + // report the real cause rather than a generic "failed to mount" message. + private volatile string mountFailureMessage; + + // Set once the named pipe server is accepting requests. Failures before that + // point cannot be reported over the pipe, so they must not wait for a reader. + private volatile bool namedPipeReady; + + // Set once a client has polled GetStatus, which means somebody is waiting for + // the mount result and is worth holding the process open for. + private volatile bool clientPolledStatus; + + // Signaled after a GetStatus response carrying MountFailed is written to a client. + private ManualResetEvent mountFailureReported; + + // Ensures only the first thread to fail the mount tears down and exits. + private int mountFailureLatch; + // When false (default), the mount process does not surface progress phase // strings over the named pipe, so the CLI falls back to its static spinner. // This gates only the display layer; the early-pipe reliability infrastructure @@ -82,6 +113,7 @@ public InProcessMount(ITracer tracer, GVFSEnlistment enlistment, CacheServerInfo this.enlistment = enlistment; this.showDebugWindow = showDebugWindow; this.unmountEvent = new ManualResetEvent(false); + this.mountFailureReported = new ManualResetEvent(false); this.missingTreeTracker = new MissingTreeTracker(tracer, TrackedTreeCapacity); } @@ -258,6 +290,8 @@ private void MountWithLockAcquired(EventLevel verbosity, Keywords keywords) this.mountProgressMessage = "Authenticating and validating"; using (NamedPipeServer pipeServer = this.StartNamedPipe()) { + this.namedPipeReady = true; + this.tracer.RelatedEvent( EventLevel.Informational, $"{nameof(this.Mount)}_StartedNamedPipe", @@ -633,6 +667,24 @@ private bool ShouldReportMountProgress() } } + private static string FormatMountFailure(string error, object[] args) + { + if (args == null || args.Length == 0) + { + return error; + } + + try + { + return string.Format(error, args); + } + catch (FormatException) + { + // Never let message formatting mask the failure we are reporting. + return error; + } + } + private void FailMountAndExit(string error, params object[] args) { this.FailMountAndExit(ReturnCode.GenericError, error, args); @@ -640,6 +692,15 @@ private void FailMountAndExit(string error, params object[] args) private void FailMountAndExit(ReturnCode returnCode, string error, params object[] args) { + if (Interlocked.CompareExchange(ref this.mountFailureLatch, 1, 0) != 0) + { + // Another thread already owns the failure path and will exit the process. + // Block rather than return: every caller of FailMountAndExit assumes it + // never returns and would otherwise run on with a half-initialized mount. + Thread.Sleep(Timeout.Infinite); + } + + this.mountFailureMessage = FormatMountFailure(error, args); this.currentState = MountState.MountFailed; this.tracer.RelatedError(error, args); @@ -649,15 +710,58 @@ private void FailMountAndExit(ReturnCode returnCode, string error, params object Console.ReadLine(); } - if (this.fileSystemCallbacks != null) + // Report the failure before tearing anything down. Disposal can be slow, and a + // secondary exception thrown from it would kill the process before the client + // ever reads the reason -- which is what made mount failures surface as + // BrokenPipeException instead of the real cause. + this.WaitForMountFailureToBeReported(); + + try { - this.fileSystemCallbacks.Dispose(); - this.fileSystemCallbacks = null; + if (this.fileSystemCallbacks != null) + { + this.fileSystemCallbacks.Dispose(); + this.fileSystemCallbacks = null; + } + } + catch (Exception e) + { + this.tracer.RelatedWarning($"{nameof(this.FailMountAndExit)}: Exception while disposing file system callbacks: {e}"); } Environment.Exit((int)returnCode); } + /// + /// Blocks until a client has read the MountFailed status, or until a short + /// timeout elapses. The process keeps the mount lock and the named pipe until it + /// exits, so this wait must stay short or it blocks the user's next mount attempt. + /// + private void WaitForMountFailureToBeReported() + { + if (!this.namedPipeReady) + { + // The pipe is not serving requests yet, so no client can read the + // failure. MountVerb detects this case by watching the mount process + // exit code instead. + return; + } + + int timeoutMs = this.clientPolledStatus + ? MountFailureReportTimeoutMs + : MountFailureNoClientTimeoutMs; + + if (this.mountFailureReported.WaitOne(timeoutMs)) + { + Thread.Sleep(MountFailureDrainMs); + } + else + { + this.tracer.RelatedWarning( + $"{nameof(this.WaitForMountFailureToBeReported)}: No client read the mount failure within {timeoutMs}ms. Exiting anyway."); + } + } + private T CreateOrReportAndExit(Func factory, string reportMessage) { try @@ -1418,6 +1522,10 @@ private void HandlePrefetchBlobsRequest(NamedPipeMessages.Message message, Named private void HandleGetStatusRequest(NamedPipeServer.Connection connection) { + this.clientPolledStatus = true; + + MountState state = this.currentState; + NamedPipeMessages.GetStatus.Response response = new NamedPipeMessages.GetStatus.Response(); response.EnlistmentRoot = this.enlistment.WorkingDirectoryRoot; response.LocalCacheRoot = !string.IsNullOrWhiteSpace(this.enlistment.LocalCacheRoot) ? this.enlistment.LocalCacheRoot : this.enlistment.GitObjectsRoot; @@ -1426,7 +1534,7 @@ private void HandleGetStatusRequest(NamedPipeServer.Connection connection) response.LockStatus = this.context?.Repository?.GVFSLock != null ? this.context.Repository.GVFSLock.GetStatus() : "Unavailable"; response.DiskLayoutVersion = $"{GVFSPlatform.Instance.DiskLayoutUpgrade.Version.CurrentMajorVersion}.{GVFSPlatform.Instance.DiskLayoutUpgrade.Version.CurrentMinorVersion}"; - switch (this.currentState) + switch (state) { case MountState.Mounting: response.MountStatus = NamedPipeMessages.GetStatus.Mounting; @@ -1448,6 +1556,7 @@ private void HandleGetStatusRequest(NamedPipeServer.Connection connection) case MountState.MountFailed: response.MountStatus = NamedPipeMessages.GetStatus.MountFailed; + response.MountError = this.mountFailureMessage; break; default: @@ -1455,7 +1564,13 @@ private void HandleGetStatusRequest(NamedPipeServer.Connection connection) break; } - connection.TrySendResponse(response.ToJson()); + bool sent = connection.TrySendResponse(response.ToJson()); + + if (sent && state == MountState.MountFailed) + { + // The client now has the reason, so FailMountAndExit can stop waiting. + this.mountFailureReported.Set(); + } } private void HandleUnmountRequest(NamedPipeServer.Connection connection) diff --git a/GVFS/GVFS.Platform.Windows/HResultExtensions.cs b/GVFS/GVFS.Platform.Windows/HResultExtensions.cs index 96df7ae84b..64b7ecf31d 100644 --- a/GVFS/GVFS.Platform.Windows/HResultExtensions.cs +++ b/GVFS/GVFS.Platform.Windows/HResultExtensions.cs @@ -6,6 +6,12 @@ public class HResultExtensions { public const int GenericProjFSError = -2147024579; // returned by ProjFS::DeleteFile() on Win server 2016 while deleting a partial file + // HRESULT_FROM_WIN32(ERROR_FILE_SYSTEM_VIRTUALIZATION_NOT_AVAILABLE (478)): + // "The file system minifilter cannot attach to the developer volume." Returned by + // StartVirtualizing when PrjFlt is not on the volume's allowed-filter list, which + // is the default on a ReFS Dev Drive. + public const int FileSystemVirtualizationNotAvailable = unchecked((int)0x800701DE); + private const int FacilityNtBit = 0x10000000; // FACILITY_NT_BIT private const int FacilityWin32 = 7; // FACILITY_WIN32 diff --git a/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs b/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs index cc4ff66863..6bc8dca583 100644 --- a/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs +++ b/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs @@ -836,6 +836,14 @@ public override bool TryStart(out string error) { this.Context.Tracer.RelatedError($"{nameof(this.virtualizationInstance.StartVirtualizing)} failed: " + result.ToString("X") + "(" + result.ToString("G") + ")"); error = "Failed to start virtualization instance (" + result.ToString() + ")"; + + if ((int)result == HResultExtensions.FileSystemVirtualizationNotAvailable) + { + error += ". The ProjFS filter (PrjFlt) cannot attach to this volume. " + + "If the enlistment is on a Dev Drive, allow the filter on that volume from an elevated command prompt: " + + "fsutil devdrv setfiltersallowed PrjFlt"; + } + return false; } diff --git a/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs b/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs new file mode 100644 index 0000000000..c8d771dc75 --- /dev/null +++ b/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs @@ -0,0 +1,98 @@ +using GVFS.Common; +using GVFS.Common.NamedPipes; +using GVFS.Tests.Should; +using GVFS.UnitTests.Mock.Common; +using NUnit.Framework; +using System; +using System.IO.Pipes; +using System.Threading.Tasks; + +namespace GVFS.UnitTests.Common +{ + [TestFixture] + public class WaitUntilMountedFailureReportingTests + { + private const string EnlistmentRoot = "C:\\fake\\root"; + + [TestCase] + public void ReportsTheMountErrorSentByTheMountProcess() + { + const string MountError = + "Error: Failed to start virtualization instance (-2147024418). " + + "The ProjFS filter (PrjFlt) cannot attach to this volume."; + + string errorMessage = RunAgainstMountFailedServer(MountError); + + errorMessage.ShouldEqual(MountError); + } + + [TestCase] + public void FallsBackToGenericMessageWhenNoMountErrorIsSent() + { + string errorMessage = RunAgainstMountFailedServer(mountError: null); + + errorMessage.ShouldEqual("Failed to mount at " + EnlistmentRoot); + } + + /// + /// Stands in for GVFS.Mount: answers a single GetStatus request with MountFailed, + /// then returns the error message WaitUntilMounted produced. + /// + /// + /// Uses a raw rather than + /// , because the latter goes through + /// GVFSPlatform.CreatePipeByName, which the unit-test mock platform does not + /// support. + /// + private static string RunAgainstMountFailedServer(string mountError) + { + string pipeName = "GVFS_test_mount_failed_" + Guid.NewGuid().ToString("N"); + + NamedPipeMessages.GetStatus.Response response = new NamedPipeMessages.GetStatus.Response + { + MountStatus = NamedPipeMessages.GetStatus.MountFailed, + MountError = mountError, + EnlistmentRoot = EnlistmentRoot, + }; + + string responseJson = response.ToJson(); + + using (NamedPipeServerStream serverStream = new NamedPipeServerStream( + pipeName, + PipeDirection.InOut, + maxNumberOfServerInstances: 1)) + { + Task serverTask = Task.Run(() => + { + serverStream.WaitForConnection(); + + NamedPipeStreamReader reader = new NamedPipeStreamReader(serverStream); + NamedPipeStreamWriter writer = new NamedPipeStreamWriter(serverStream); + + // WaitUntilMounted sends GetStatus and stops on the first + // MountFailed response, so one exchange is enough. + reader.ReadMessage(); + writer.WriteMessage(responseJson); + }); + + try + { + string errorMessage; + bool result = GVFSEnlistment.WaitUntilMounted( + new MockTracer(), + pipeName, + EnlistmentRoot, + unattended: false, + out errorMessage); + + result.ShouldBeFalse(); + return errorMessage; + } + finally + { + serverTask.Wait(TimeSpan.FromSeconds(30)); + } + } + } + } +} diff --git a/GVFS/GVFS.UnitTests/Virtualization/Projection/GitIndexProjectionDisposeTests.cs b/GVFS/GVFS.UnitTests/Virtualization/Projection/GitIndexProjectionDisposeTests.cs new file mode 100644 index 0000000000..c5b1cf9f54 --- /dev/null +++ b/GVFS/GVFS.UnitTests/Virtualization/Projection/GitIndexProjectionDisposeTests.cs @@ -0,0 +1,59 @@ +using GVFS.Virtualization.Projection; +using NUnit.Framework; +using System.Threading; +using System.Threading.Tasks; + +namespace GVFS.UnitTests.Virtualization.Projection +{ + [TestFixture] + public class GitIndexProjectionDisposeTests + { + [TestCase] + public void DisposeDoesNotThrowWhenIndexParsingThreadIsStillRunning() + { + using (ManualResetEventSlim releaseParsingThread = new ManualResetEventSlim(false)) + { + Task parsingThread = Task.Factory.StartNew( + () => releaseParsingThread.Wait(), + TaskCreationOptions.LongRunning); + + try + { + TestableGitIndexProjection projection = new TestableGitIndexProjection(); + projection.SetIndexParsingThreadForTests(parsingThread); + + // A failed mount disposes the projection without calling Shutdown, so + // the parsing thread is still running here. Disposing a Task that has + // not completed throws InvalidOperationException, and that secondary + // exception used to kill GVFS.Mount before it could report why the + // mount failed -- leaving the client with a broken pipe. + Assert.DoesNotThrow(() => projection.Dispose()); + } + finally + { + releaseParsingThread.Set(); + parsingThread.Wait(); + parsingThread.Dispose(); + } + } + } + + [TestCase] + public void DisposeDisposesIndexParsingThreadOnceItHasCompleted() + { + // Never use Task.CompletedTask here: it is a runtime-wide singleton, and + // disposing it breaks every later await in the process. + Task parsingThread = Task.Factory.StartNew(() => { }, TaskCreationOptions.LongRunning); + parsingThread.Wait(); + + TestableGitIndexProjection projection = new TestableGitIndexProjection(); + projection.SetIndexParsingThreadForTests(parsingThread); + + Assert.DoesNotThrow(() => projection.Dispose()); + } + + private class TestableGitIndexProjection : GitIndexProjection + { + } + } +} diff --git a/GVFS/GVFS.Virtualization/Projection/GitIndexProjection.cs b/GVFS/GVFS.Virtualization/Projection/GitIndexProjection.cs index 3b8301b125..4c5d377a8d 100644 --- a/GVFS/GVFS.Virtualization/Projection/GitIndexProjection.cs +++ b/GVFS/GVFS.Virtualization/Projection/GitIndexProjection.cs @@ -706,6 +706,15 @@ public void Dispose() GC.SuppressFinalize(this); } + /// + /// Test seam. Puts the projection into the "index parsing thread is still + /// running" state that a failed mount produces, without needing a real repo. + /// + internal void SetIndexParsingThreadForTests(Task indexParsingTask) + { + this.indexParsingThread = indexParsingTask; + } + protected virtual void Dispose(bool disposing) { if (disposing) @@ -730,7 +739,17 @@ protected virtual void Dispose(bool disposing) if (this.indexParsingThread != null) { - this.indexParsingThread.Dispose(); + // Task.Dispose throws InvalidOperationException unless the task has + // reached a completion state. A failed mount disposes the projection + // without calling Shutdown first, so the parsing thread is still + // running here. Skip the Dispose in that case: a Task owns no + // unmanaged resources, and throwing would kill the mount process + // before it can report why the mount failed. + if (this.indexParsingThread.IsCompleted) + { + this.indexParsingThread.Dispose(); + } + this.indexParsingThread = null; } } From d4ddf6bf8277e7283f7da2e61db635f58ef785d1 Mon Sep 17 00:00:00 2001 From: Tyrie Vella Date: Tue, 1 Sep 2026 12:39:39 -0700 Subject: [PATCH 2/4] Address self-review findings on the mount failure reporting fix 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 --- GVFS/GVFS.Mount/InProcessMount.cs | 87 +++++++++++++++---- .../WindowsFileSystemVirtualizer.cs | 46 +++++++++- .../WaitUntilMountedFailureReportingTests.cs | 2 +- ...kgroundFileSystemTaskRunnerDisposeTests.cs | 45 ++++++++++ .../GitIndexProjectionDisposeTests.cs | 23 ++--- .../BackgroundFileSystemTaskRunner.cs | 16 +++- .../Projection/GitIndexProjection.cs | 18 ++-- 7 files changed, 185 insertions(+), 52 deletions(-) create mode 100644 GVFS/GVFS.UnitTests/Virtualization/Background/BackgroundFileSystemTaskRunnerDisposeTests.cs diff --git a/GVFS/GVFS.Mount/InProcessMount.cs b/GVFS/GVFS.Mount/InProcessMount.cs index b13863f6e1..07f0b82299 100644 --- a/GVFS/GVFS.Mount/InProcessMount.cs +++ b/GVFS/GVFS.Mount/InProcessMount.cs @@ -51,8 +51,11 @@ public class InProcessMount // narrow window between the pipe opening and MountVerb's first poll. private const int MountFailureNoClientTimeoutMs = 500; - // Lets the response drain to the client before the pipe goes away. - private const int MountFailureDrainMs = 50; + // Lets the response drain, and covers the case where a different client (a + // concurrent "gvfs status") consumed the report signal. It must exceed the + // client's 100ms GetStatus poll interval so the mounting client still gets its + // answer on the next poll. + private const int MountFailureDrainMs = 150; private readonly bool showDebugWindow; @@ -87,8 +90,9 @@ public class InProcessMount // Signaled after a GetStatus response carrying MountFailed is written to a client. private ManualResetEvent mountFailureReported; - // Ensures only the first thread to fail the mount tears down and exits. - private int mountFailureLatch; + // Identifies the thread that owns the mount-failure path, so a re-entrant call on + // that same thread exits instead of waiting on itself. 0 means no owner yet. + private int mountFailureOwnerThreadId; // When false (default), the mount process does not surface progress phase // strings over the named pipe, so the CLI falls back to its static spinner. @@ -692,18 +696,39 @@ private void FailMountAndExit(string error, params object[] args) private void FailMountAndExit(ReturnCode returnCode, string error, params object[] args) { - if (Interlocked.CompareExchange(ref this.mountFailureLatch, 1, 0) != 0) + // Format before taking the latch. RelatedError would otherwise format a second + // time without protection, and a throw there would re-enter this method from an + // outer catch block. + string failureMessage = FormatMountFailure(error, args); + + int currentThreadId = Environment.CurrentManagedThreadId; + int owningThreadId = Interlocked.CompareExchange(ref this.mountFailureOwnerThreadId, currentThreadId, 0); + + if (owningThreadId == currentThreadId) + { + // Re-entered on the reporting thread, because something below threw and an + // outer catch called back in. The failure was already reported, so exit + // rather than wait again -- waiting here would block forever on a signal + // this thread is itself responsible for observing. + this.tracer.RelatedWarning( + null, + $"{nameof(this.FailMountAndExit)}: Re-entered while reporting a mount failure: {failureMessage}", + Keywords.Telemetry); + Environment.Exit((int)returnCode); + } + + if (owningThreadId != 0) { - // Another thread already owns the failure path and will exit the process. - // Block rather than return: every caller of FailMountAndExit assumes it - // never returns and would otherwise run on with a half-initialized mount. - Thread.Sleep(Timeout.Infinite); + // Another thread owns the failure path and will exit the process. Block + // rather than return: every caller of FailMountAndExit assumes it never + // returns and would otherwise run on with a half-initialized mount. + BlockUntilProcessExits(); } - this.mountFailureMessage = FormatMountFailure(error, args); + this.mountFailureMessage = failureMessage; this.currentState = MountState.MountFailed; - this.tracer.RelatedError(error, args); + this.tracer.RelatedError(failureMessage); if (this.showDebugWindow) { Console.WriteLine("\nPress Enter to Exit"); @@ -726,12 +751,26 @@ private void FailMountAndExit(ReturnCode returnCode, string error, params object } catch (Exception e) { - this.tracer.RelatedWarning($"{nameof(this.FailMountAndExit)}: Exception while disposing file system callbacks: {e}"); + // Traced with Telemetry because this used to be a process-fatal crash. Without + // the keyword the failure it replaced would become invisible in the field. + this.tracer.RelatedWarning( + null, + $"{nameof(this.FailMountAndExit)}: Exception while disposing file system callbacks: {e}", + Keywords.Telemetry); } Environment.Exit((int)returnCode); } + /// + /// Parks the calling thread until another thread exits the process. Used where a + /// method must not return but is not the thread that owns the exit. + /// + private static void BlockUntilProcessExits() + { + Thread.Sleep(Timeout.Infinite); + } + /// /// Blocks until a client has read the MountFailed status, or until a short /// timeout elapses. The process keeps the mount lock and the named pipe until it @@ -753,12 +792,18 @@ private void WaitForMountFailureToBeReported() if (this.mountFailureReported.WaitOne(timeoutMs)) { + // Any client can satisfy the wait, and the one that read the failure is not + // necessarily the one that is mounting -- a concurrent "gvfs status" polls + // the same pipe. Staying alive for longer than the client's poll interval + // means the mounting client still gets its answer on its next poll. Thread.Sleep(MountFailureDrainMs); } else { this.tracer.RelatedWarning( - $"{nameof(this.WaitForMountFailureToBeReported)}: No client read the mount failure within {timeoutMs}ms. Exiting anyway."); + null, + $"{nameof(this.WaitForMountFailureToBeReported)}: No client read the mount failure within {timeoutMs}ms. Exiting anyway.", + Keywords.Telemetry); } } @@ -1522,8 +1567,6 @@ private void HandlePrefetchBlobsRequest(NamedPipeMessages.Message message, Named private void HandleGetStatusRequest(NamedPipeServer.Connection connection) { - this.clientPolledStatus = true; - MountState state = this.currentState; NamedPipeMessages.GetStatus.Response response = new NamedPipeMessages.GetStatus.Response(); @@ -1566,10 +1609,18 @@ private void HandleGetStatusRequest(NamedPipeServer.Connection connection) bool sent = connection.TrySendResponse(response.ToJson()); - if (sent && state == MountState.MountFailed) + if (sent) { - // The client now has the reason, so FailMountAndExit can stop waiting. - this.mountFailureReported.Set(); + // Only count a client that actually received a status. Setting this on + // entry would let a client that connected and then disconnected extend the + // post-failure wait. + this.clientPolledStatus = true; + + if (state == MountState.MountFailed) + { + // The client now has the reason, so FailMountAndExit can stop waiting. + this.mountFailureReported.Set(); + } } } diff --git a/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs b/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs index 6bc8dca583..357f77c3c5 100644 --- a/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs +++ b/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs @@ -839,9 +839,7 @@ public override bool TryStart(out string error) if ((int)result == HResultExtensions.FileSystemVirtualizationNotAvailable) { - error += ". The ProjFS filter (PrjFlt) cannot attach to this volume. " - + "If the enlistment is on a Dev Drive, allow the filter on that volume from an elevated command prompt: " - + "fsutil devdrv setfiltersallowed PrjFlt"; + error += ". " + BuildProjFsAttachRemedy(this.Context.Enlistment.WorkingDirectoryRoot); } return false; @@ -855,6 +853,48 @@ protected override void OnPossibleTombstoneFolderCreated(string relativePath) this.FileSystemCallbacks.OnPossibleTombstoneFolderCreated(relativePath); } + /// + /// Builds the user-facing remedy for + /// ERROR_FILE_SYSTEM_VIRTUALIZATION_NOT_AVAILABLE, which a Dev Drive returns when + /// PrjFlt is not on its allowed-filter list. + /// + /// + /// "fsutil devdrv setFiltersAllowed" REPLACES the allowed list, and without + /// /volume it replaces the list for every developer volume on the machine. So the + /// message must tell the user to read the current list first and include it, or + /// following this advice would drop filters the machine already requires (an + /// anti-malware filter, for example). + /// + private static string BuildProjFsAttachRemedy(string enlistmentRoot) + { + string volume; + try + { + volume = Path.GetPathRoot(enlistmentRoot)?.TrimEnd(Path.DirectorySeparatorChar); + } + catch (ArgumentException) + { + volume = null; + } + + if (string.IsNullOrEmpty(volume)) + { + volume = ""; + } + + return "The ProjFS filter (PrjFlt) cannot attach to this volume. " + + $"If {volume} is a Dev Drive, PrjFlt must be on its allowed-filter list. " + + "From an elevated command prompt, list the filters that are already allowed:" + + Environment.NewLine + + $" fsutil devdrv query {volume}" + + Environment.NewLine + + "then set the list again with PrjFlt added to it:" + + Environment.NewLine + + $" fsutil devdrv setFiltersAllowed /f /volume {volume} \",PrjFlt\"" + + Environment.NewLine + + "setFiltersAllowed replaces the list, so keep the existing entries"; + } + private static void StreamCopyBlockTo(Stream input, Stream destination, long numBytes, byte[] buffer) { int read; diff --git a/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs b/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs index c8d771dc75..2f89013c88 100644 --- a/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs +++ b/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs @@ -90,7 +90,7 @@ private static string RunAgainstMountFailedServer(string mountError) } finally { - serverTask.Wait(TimeSpan.FromSeconds(30)); + serverTask.Wait(TimeSpan.FromSeconds(5)); } } } diff --git a/GVFS/GVFS.UnitTests/Virtualization/Background/BackgroundFileSystemTaskRunnerDisposeTests.cs b/GVFS/GVFS.UnitTests/Virtualization/Background/BackgroundFileSystemTaskRunnerDisposeTests.cs new file mode 100644 index 0000000000..8a390510fc --- /dev/null +++ b/GVFS/GVFS.UnitTests/Virtualization/Background/BackgroundFileSystemTaskRunnerDisposeTests.cs @@ -0,0 +1,45 @@ +using GVFS.Virtualization.Background; +using NUnit.Framework; +using System.Threading; +using System.Threading.Tasks; + +namespace GVFS.UnitTests.Virtualization.Background +{ + [TestFixture] + public class BackgroundFileSystemTaskRunnerDisposeTests + { + [TestCase] + public void DisposeDoesNotThrowWhenBackgroundThreadIsStillRunning() + { + using (ManualResetEventSlim releaseBackgroundThread = new ManualResetEventSlim(false)) + { + Task backgroundThread = Task.Factory.StartNew( + () => releaseBackgroundThread.Wait(), + TaskCreationOptions.LongRunning); + + try + { + TestableBackgroundFileSystemTaskRunner runner = new TestableBackgroundFileSystemTaskRunner(); + runner.SetBackgroundThreadForTests(backgroundThread); + + // FileSystemCallbacks.Dispose() disposes this runner on the failed-mount + // path, without calling Shutdown first, so the background thread is still + // running. Calling Task.Dispose on a task that has not completed throws + // InvalidOperationException, which stopped GVFS.Mount from reporting why + // the mount failed. This guards against reintroducing that call. + Assert.DoesNotThrow(() => runner.Dispose()); + } + finally + { + releaseBackgroundThread.Set(); + backgroundThread.Wait(); + backgroundThread.Dispose(); + } + } + } + + private class TestableBackgroundFileSystemTaskRunner : BackgroundFileSystemTaskRunner + { + } + } +} diff --git a/GVFS/GVFS.UnitTests/Virtualization/Projection/GitIndexProjectionDisposeTests.cs b/GVFS/GVFS.UnitTests/Virtualization/Projection/GitIndexProjectionDisposeTests.cs index c5b1cf9f54..68ae38b29f 100644 --- a/GVFS/GVFS.UnitTests/Virtualization/Projection/GitIndexProjectionDisposeTests.cs +++ b/GVFS/GVFS.UnitTests/Virtualization/Projection/GitIndexProjectionDisposeTests.cs @@ -23,10 +23,11 @@ public void DisposeDoesNotThrowWhenIndexParsingThreadIsStillRunning() projection.SetIndexParsingThreadForTests(parsingThread); // A failed mount disposes the projection without calling Shutdown, so - // the parsing thread is still running here. Disposing a Task that has - // not completed throws InvalidOperationException, and that secondary - // exception used to kill GVFS.Mount before it could report why the - // mount failed -- leaving the client with a broken pipe. + // the parsing thread is still running here. Calling Task.Dispose on a + // task that has not completed throws InvalidOperationException, and + // that secondary exception used to kill GVFS.Mount before it could + // report why the mount failed -- leaving the client with a broken pipe. + // This guards against reintroducing that call. Assert.DoesNotThrow(() => projection.Dispose()); } finally @@ -38,20 +39,6 @@ public void DisposeDoesNotThrowWhenIndexParsingThreadIsStillRunning() } } - [TestCase] - public void DisposeDisposesIndexParsingThreadOnceItHasCompleted() - { - // Never use Task.CompletedTask here: it is a runtime-wide singleton, and - // disposing it breaks every later await in the process. - Task parsingThread = Task.Factory.StartNew(() => { }, TaskCreationOptions.LongRunning); - parsingThread.Wait(); - - TestableGitIndexProjection projection = new TestableGitIndexProjection(); - projection.SetIndexParsingThreadForTests(parsingThread); - - Assert.DoesNotThrow(() => projection.Dispose()); - } - private class TestableGitIndexProjection : GitIndexProjection { } diff --git a/GVFS/GVFS.Virtualization/Background/BackgroundFileSystemTaskRunner.cs b/GVFS/GVFS.Virtualization/Background/BackgroundFileSystemTaskRunner.cs index 88ea897098..21316fbf6d 100644 --- a/GVFS/GVFS.Virtualization/Background/BackgroundFileSystemTaskRunner.cs +++ b/GVFS/GVFS.Virtualization/Background/BackgroundFileSystemTaskRunner.cs @@ -122,13 +122,27 @@ public void Dispose() GC.SuppressFinalize(this); } + /// + /// Test seam. Puts the runner into the "background thread is still running" state + /// that a failed mount produces, without needing a real repo. + /// + internal void SetBackgroundThreadForTests(Task backgroundTask) + { + this.backgroundThread = backgroundTask; + } + protected void Dispose(bool disposing) { if (disposing) { if (this.backgroundThread != null) { - this.backgroundThread.Dispose(); + // Deliberately not calling Task.Dispose. A Task holds no unmanaged + // resources, and Task.Dispose throws InvalidOperationException unless + // the task has reached a completion state. A failed mount disposes the + // callbacks without calling Shutdown first, so this thread is still + // running and that throw would prevent the mount process from + // reporting why the mount failed. this.backgroundThread = null; } if (this.backgroundTasks != null) diff --git a/GVFS/GVFS.Virtualization/Projection/GitIndexProjection.cs b/GVFS/GVFS.Virtualization/Projection/GitIndexProjection.cs index 4c5d377a8d..131449e640 100644 --- a/GVFS/GVFS.Virtualization/Projection/GitIndexProjection.cs +++ b/GVFS/GVFS.Virtualization/Projection/GitIndexProjection.cs @@ -739,17 +739,13 @@ protected virtual void Dispose(bool disposing) if (this.indexParsingThread != null) { - // Task.Dispose throws InvalidOperationException unless the task has - // reached a completion state. A failed mount disposes the projection - // without calling Shutdown first, so the parsing thread is still - // running here. Skip the Dispose in that case: a Task owns no - // unmanaged resources, and throwing would kill the mount process - // before it can report why the mount failed. - if (this.indexParsingThread.IsCompleted) - { - this.indexParsingThread.Dispose(); - } - + // Deliberately not calling Task.Dispose. A Task holds no unmanaged + // resources, Task.Dispose is legacy IAsyncResult wait-handle cleanup, + // and it throws InvalidOperationException unless the task has reached + // a completion state. A failed mount disposes the projection without + // calling Shutdown first, so the parsing thread is still running here + // and that throw would kill the mount process before it can report + // why the mount failed. this.indexParsingThread = null; } } From 14cdfdf935b0fc4c2c37d71091f2593dad8ca248 Mon Sep 17 00:00:00 2001 From: Tyrie Vella Date: Wed, 2 Sep 2026 09:53:45 -0700 Subject: [PATCH 3/4] Extract the mount-failure handshake into MountFailureReporter 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 --- .../NamedPipes/MountFailureReporter.cs | 222 ++++++++++++++++++ GVFS/GVFS.Mount/InProcessMount.cs | 151 ++---------- .../Common/MountFailureReporterTests.cs | 205 ++++++++++++++++ 3 files changed, 453 insertions(+), 125 deletions(-) create mode 100644 GVFS/GVFS.Common/NamedPipes/MountFailureReporter.cs create mode 100644 GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs diff --git a/GVFS/GVFS.Common/NamedPipes/MountFailureReporter.cs b/GVFS/GVFS.Common/NamedPipes/MountFailureReporter.cs new file mode 100644 index 0000000000..a1260d2cac --- /dev/null +++ b/GVFS/GVFS.Common/NamedPipes/MountFailureReporter.cs @@ -0,0 +1,222 @@ +using GVFS.Common.Tracing; +using System; +using System.Threading; + +namespace GVFS.Common.NamedPipes +{ + /// + /// The result of a thread trying to take ownership of the mount-failure path. + /// + public enum MountFailureOwnership + { + /// + /// The calling thread now owns reporting and must drive it to process exit. + /// + Owner, + + /// + /// The calling thread already owned reporting and has re-entered, because + /// something threw while it was reporting and an outer catch block called back + /// in. It must not wait again: it would block forever on a signal that it is + /// itself responsible for observing. + /// + Reentrant, + + /// + /// Another thread owns reporting and will exit the process. The calling thread + /// must not continue with a half-initialized mount. + /// + NotOwner, + } + + /// + /// Server half of the mount-failure handshake: keeps a failed mount process alive + /// just long enough for a client to read the reason over the named pipe. + /// + /// + /// Without this, the mount process sets MountFailed and exits immediately. + /// The client polls GetStatus every 100ms, so it usually loses the race, the pipe + /// breaks mid-request, and the user sees a transport error instead of the cause. + /// + /// The wait is deliberately short. Until the process exits it still holds the mount + /// lock and the named pipe, so a longer wait delays the user's next mount attempt. + /// + /// + /// This type owns only the handshake state. Process-exit policy stays with the + /// caller. The client half of the same protocol is + /// . + /// + /// + public sealed class MountFailureReporter : IDisposable + { + /// + /// Cap on how long to wait once a client is known to be polling. + /// + public const int DefaultReportTimeoutMs = 2000; + + /// + /// Cap used when no client has received a status yet. It only has to cover the + /// gap between the pipe opening and the client's first poll. + /// + public const int DefaultNoClientTimeoutMs = 500; + + /// + /// Grace period after a client reads the failure. Any client can satisfy the + /// wait, and it is not necessarily the one that is mounting -- a concurrent + /// "gvfs status" polls the same pipe. Keeping this above the client's 100ms poll + /// interval means the mounting client still gets its answer on its next poll. + /// + public const int DefaultDrainMs = 150; + + private readonly ITracer tracer; + private readonly int reportTimeoutMs; + private readonly int noClientTimeoutMs; + private readonly int drainMs; + private readonly ManualResetEvent failureReported; + + private volatile string failureMessage; + private volatile bool namedPipeReady; + private volatile bool clientReceivedStatus; + + // 0 means no thread owns the failure path yet. + private int owningThreadId; + + public MountFailureReporter(ITracer tracer) + : this(tracer, DefaultReportTimeoutMs, DefaultNoClientTimeoutMs, DefaultDrainMs) + { + } + + /// + /// Test constructor. Lets unit tests use short timeouts so they do not pay the + /// production waits. + /// + internal MountFailureReporter(ITracer tracer, int reportTimeoutMs, int noClientTimeoutMs, int drainMs) + { + this.tracer = tracer; + this.reportTimeoutMs = reportTimeoutMs; + this.noClientTimeoutMs = noClientTimeoutMs; + this.drainMs = drainMs; + this.failureReported = new ManualResetEvent(false); + } + + /// + /// The reason the mount failed, or null if the mount has not failed. Sent to the + /// client in the GetStatus response. + /// + public string FailureMessage + { + get { return this.failureMessage; } + } + + /// + /// Formats a failure message without letting the formatting itself throw. + /// + /// + /// Callers pass messages built from external text (exception strings, server + /// responses) that can contain unbalanced braces. A FormatException here would + /// mask the failure being reported, so fall back to the unformatted string. + /// + public static string FormatFailure(string error, object[] args) + { + if (args == null || args.Length == 0) + { + return error; + } + + try + { + return string.Format(error, args); + } + catch (FormatException) + { + return error; + } + } + + /// + /// Records that the named pipe server is accepting requests. Failures before this + /// point cannot be reported over the pipe and must not wait for a reader. + /// + public void OnNamedPipeReady() + { + this.namedPipeReady = true; + } + + /// + /// Attempts to take ownership of the mount-failure path, publishing + /// as the reason if this call wins. + /// + public MountFailureOwnership TryTakeOwnership(string message) + { + int currentThreadId = Environment.CurrentManagedThreadId; + int previousOwner = Interlocked.CompareExchange(ref this.owningThreadId, currentThreadId, 0); + + if (previousOwner == currentThreadId) + { + return MountFailureOwnership.Reentrant; + } + + if (previousOwner != 0) + { + return MountFailureOwnership.NotOwner; + } + + this.failureMessage = message; + return MountFailureOwnership.Owner; + } + + /// + /// Records that a GetStatus response reached a client, and releases + /// when that response carried the + /// failure. + /// + /// + /// True when the delivered response reported MountFailed. + /// + public void OnStatusDelivered(bool carriedMountFailure) + { + // Only count a client that actually received a status. Recording this before + // the send succeeds would let a client that connected and then disconnected + // extend the post-failure wait. + this.clientReceivedStatus = true; + + if (carriedMountFailure) + { + this.failureReported.Set(); + } + } + + /// + /// Blocks until a client has read the failure, or until a short timeout elapses. + /// Returns immediately when no client could possibly read it. + /// + public void WaitForClientToReadFailure() + { + if (!this.namedPipeReady) + { + // No client can read the failure. The caller detects this case by + // watching the mount process exit code instead. + return; + } + + int timeoutMs = this.clientReceivedStatus ? this.reportTimeoutMs : this.noClientTimeoutMs; + + if (this.failureReported.WaitOne(timeoutMs)) + { + Thread.Sleep(this.drainMs); + } + else + { + this.tracer.RelatedWarning( + null, + $"{nameof(this.WaitForClientToReadFailure)}: No client read the mount failure within {timeoutMs}ms. Exiting anyway.", + Keywords.Telemetry); + } + } + + public void Dispose() + { + this.failureReported.Dispose(); + } + } +} diff --git a/GVFS/GVFS.Mount/InProcessMount.cs b/GVFS/GVFS.Mount/InProcessMount.cs index 07f0b82299..d1e5815966 100644 --- a/GVFS/GVFS.Mount/InProcessMount.cs +++ b/GVFS/GVFS.Mount/InProcessMount.cs @@ -41,22 +41,6 @@ public class InProcessMount // reliably trigger a commit pack download. private const int TrackedTreeCapacity = MissingTreeThresholdForDownloadingCommitPack * 20; - // Bounds how long a failed mount stays alive so a client can read the reason. - // Kept short on purpose: until the process exits it still holds the mount lock - // and its named pipe, so a user retrying "gvfs mount" would be told the repo is - // already mounted. The wait normally ends on the client's next poll (~100ms). - private const int MountFailureReportTimeoutMs = 2000; - - // Used instead when no client has polled GetStatus yet. It only has to cover the - // narrow window between the pipe opening and MountVerb's first poll. - private const int MountFailureNoClientTimeoutMs = 500; - - // Lets the response drain, and covers the case where a different client (a - // concurrent "gvfs status") consumed the report signal. It must exceed the - // client's 100ms GetStatus poll interval so the mounting client still gets its - // answer on the next poll. - private const int MountFailureDrainMs = 150; - private readonly bool showDebugWindow; private FileSystemCallbacks fileSystemCallbacks; @@ -75,24 +59,9 @@ public class InProcessMount private volatile MountState currentState; private volatile string mountProgressMessage; - // Why the mount failed. Sent to the client in the GetStatus response so it can - // report the real cause rather than a generic "failed to mount" message. - private volatile string mountFailureMessage; - - // Set once the named pipe server is accepting requests. Failures before that - // point cannot be reported over the pipe, so they must not wait for a reader. - private volatile bool namedPipeReady; - - // Set once a client has polled GetStatus, which means somebody is waiting for - // the mount result and is worth holding the process open for. - private volatile bool clientPolledStatus; - - // Signaled after a GetStatus response carrying MountFailed is written to a client. - private ManualResetEvent mountFailureReported; - - // Identifies the thread that owns the mount-failure path, so a re-entrant call on - // that same thread exits instead of waiting on itself. 0 means no owner yet. - private int mountFailureOwnerThreadId; + // Keeps the pipe answering GetStatus after a failure so the client can read the + // reason, instead of racing this process to exit and seeing a broken pipe. + private readonly MountFailureReporter mountFailureReporter; // When false (default), the mount process does not surface progress phase // strings over the named pipe, so the CLI falls back to its static spinner. @@ -117,7 +86,7 @@ public InProcessMount(ITracer tracer, GVFSEnlistment enlistment, CacheServerInfo this.enlistment = enlistment; this.showDebugWindow = showDebugWindow; this.unmountEvent = new ManualResetEvent(false); - this.mountFailureReported = new ManualResetEvent(false); + this.mountFailureReporter = new MountFailureReporter(tracer); this.missingTreeTracker = new MissingTreeTracker(tracer, TrackedTreeCapacity); } @@ -294,7 +263,7 @@ private void MountWithLockAcquired(EventLevel verbosity, Keywords keywords) this.mountProgressMessage = "Authenticating and validating"; using (NamedPipeServer pipeServer = this.StartNamedPipe()) { - this.namedPipeReady = true; + this.mountFailureReporter.OnNamedPipeReady(); this.tracer.RelatedEvent( EventLevel.Informational, @@ -671,24 +640,6 @@ private bool ShouldReportMountProgress() } } - private static string FormatMountFailure(string error, object[] args) - { - if (args == null || args.Length == 0) - { - return error; - } - - try - { - return string.Format(error, args); - } - catch (FormatException) - { - // Never let message formatting mask the failure we are reporting. - return error; - } - } - private void FailMountAndExit(string error, params object[] args) { this.FailMountAndExit(ReturnCode.GenericError, error, args); @@ -696,36 +647,31 @@ private void FailMountAndExit(string error, params object[] args) private void FailMountAndExit(ReturnCode returnCode, string error, params object[] args) { - // Format before taking the latch. RelatedError would otherwise format a second + // Format before taking ownership. RelatedError would otherwise format a second // time without protection, and a throw there would re-enter this method from an // outer catch block. - string failureMessage = FormatMountFailure(error, args); - - int currentThreadId = Environment.CurrentManagedThreadId; - int owningThreadId = Interlocked.CompareExchange(ref this.mountFailureOwnerThreadId, currentThreadId, 0); + string failureMessage = MountFailureReporter.FormatFailure(error, args); - if (owningThreadId == currentThreadId) + switch (this.mountFailureReporter.TryTakeOwnership(failureMessage)) { - // Re-entered on the reporting thread, because something below threw and an - // outer catch called back in. The failure was already reported, so exit - // rather than wait again -- waiting here would block forever on a signal - // this thread is itself responsible for observing. - this.tracer.RelatedWarning( - null, - $"{nameof(this.FailMountAndExit)}: Re-entered while reporting a mount failure: {failureMessage}", - Keywords.Telemetry); - Environment.Exit((int)returnCode); - } + case MountFailureOwnership.Reentrant: + // Something below threw and an outer catch called back in. The failure + // was already reported, so exit rather than wait on ourselves. + this.tracer.RelatedWarning( + null, + $"{nameof(this.FailMountAndExit)}: Re-entered while reporting a mount failure: {failureMessage}", + Keywords.Telemetry); + Environment.Exit((int)returnCode); + break; - if (owningThreadId != 0) - { - // Another thread owns the failure path and will exit the process. Block - // rather than return: every caller of FailMountAndExit assumes it never - // returns and would otherwise run on with a half-initialized mount. - BlockUntilProcessExits(); + case MountFailureOwnership.NotOwner: + // Another thread owns the failure path and will exit the process. Block + // rather than return: every caller of FailMountAndExit assumes it never + // returns and would otherwise run on with a half-initialized mount. + BlockUntilProcessExits(); + break; } - this.mountFailureMessage = failureMessage; this.currentState = MountState.MountFailed; this.tracer.RelatedError(failureMessage); @@ -739,7 +685,7 @@ private void FailMountAndExit(ReturnCode returnCode, string error, params object // secondary exception thrown from it would kill the process before the client // ever reads the reason -- which is what made mount failures surface as // BrokenPipeException instead of the real cause. - this.WaitForMountFailureToBeReported(); + this.mountFailureReporter.WaitForClientToReadFailure(); try { @@ -771,42 +717,6 @@ private static void BlockUntilProcessExits() Thread.Sleep(Timeout.Infinite); } - /// - /// Blocks until a client has read the MountFailed status, or until a short - /// timeout elapses. The process keeps the mount lock and the named pipe until it - /// exits, so this wait must stay short or it blocks the user's next mount attempt. - /// - private void WaitForMountFailureToBeReported() - { - if (!this.namedPipeReady) - { - // The pipe is not serving requests yet, so no client can read the - // failure. MountVerb detects this case by watching the mount process - // exit code instead. - return; - } - - int timeoutMs = this.clientPolledStatus - ? MountFailureReportTimeoutMs - : MountFailureNoClientTimeoutMs; - - if (this.mountFailureReported.WaitOne(timeoutMs)) - { - // Any client can satisfy the wait, and the one that read the failure is not - // necessarily the one that is mounting -- a concurrent "gvfs status" polls - // the same pipe. Staying alive for longer than the client's poll interval - // means the mounting client still gets its answer on its next poll. - Thread.Sleep(MountFailureDrainMs); - } - else - { - this.tracer.RelatedWarning( - null, - $"{nameof(this.WaitForMountFailureToBeReported)}: No client read the mount failure within {timeoutMs}ms. Exiting anyway.", - Keywords.Telemetry); - } - } - private T CreateOrReportAndExit(Func factory, string reportMessage) { try @@ -1599,7 +1509,7 @@ private void HandleGetStatusRequest(NamedPipeServer.Connection connection) case MountState.MountFailed: response.MountStatus = NamedPipeMessages.GetStatus.MountFailed; - response.MountError = this.mountFailureMessage; + response.MountError = this.mountFailureReporter.FailureMessage; break; default: @@ -1611,16 +1521,7 @@ private void HandleGetStatusRequest(NamedPipeServer.Connection connection) if (sent) { - // Only count a client that actually received a status. Setting this on - // entry would let a client that connected and then disconnected extend the - // post-failure wait. - this.clientPolledStatus = true; - - if (state == MountState.MountFailed) - { - // The client now has the reason, so FailMountAndExit can stop waiting. - this.mountFailureReported.Set(); - } + this.mountFailureReporter.OnStatusDelivered(carriedMountFailure: state == MountState.MountFailed); } } diff --git a/GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs b/GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs new file mode 100644 index 0000000000..18964f174c --- /dev/null +++ b/GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs @@ -0,0 +1,205 @@ +using GVFS.Common.NamedPipes; +using GVFS.Tests.Should; +using GVFS.UnitTests.Mock.Common; +using NUnit.Framework; +using System; +using System.Diagnostics; +using System.Threading; +using System.Threading.Tasks; + +namespace GVFS.UnitTests.Common +{ + /// + /// Covers the server half of the mount-failure handshake. Before this state machine + /// was extracted from InProcessMount it lived in GVFS.Mount, which GVFS.UnitTests + /// cannot reference, so none of it was covered. + /// + [TestFixture] + public class MountFailureReporterTests + { + private const int ReportTimeoutMs = 2000; + private const int NoClientTimeoutMs = 200; + private const int DrainMs = 20; + + [TestCase] + public void FirstThreadTakesOwnershipAndPublishesTheMessage() + { + using (MountFailureReporter reporter = CreateReporter()) + { + reporter.FailureMessage.ShouldBeNull(); + + reporter.TryTakeOwnership("the real reason").ShouldEqual(MountFailureOwnership.Owner); + reporter.FailureMessage.ShouldEqual("the real reason"); + } + } + + [TestCase] + public void SameThreadCallingTwiceIsReentrantRatherThanBlocked() + { + using (MountFailureReporter reporter = CreateReporter()) + { + reporter.TryTakeOwnership("first").ShouldEqual(MountFailureOwnership.Owner); + + // A throw inside the reporting path can make an outer catch block call + // back in on the same thread. That must not be treated as a second thread, + // or the caller would park forever holding the mount lock and the pipe. + reporter.TryTakeOwnership("second").ShouldEqual(MountFailureOwnership.Reentrant); + + // The re-entrant call must not overwrite the reason already published. + reporter.FailureMessage.ShouldEqual("first"); + } + } + + [TestCase] + public void SecondThreadIsNotTheOwner() + { + using (MountFailureReporter reporter = CreateReporter()) + { + reporter.TryTakeOwnership("first").ShouldEqual(MountFailureOwnership.Owner); + + MountFailureOwnership fromOtherThread = MountFailureOwnership.Owner; + Task other = Task.Run(() => fromOtherThread = reporter.TryTakeOwnership("second")); + other.Wait(TimeSpan.FromSeconds(5)).ShouldBeTrue(); + + fromOtherThread.ShouldEqual(MountFailureOwnership.NotOwner); + reporter.FailureMessage.ShouldEqual("first"); + } + } + + [TestCase] + public void WaitReturnsImmediatelyWhenThePipeNeverOpened() + { + using (MountFailureReporter reporter = CreateReporter()) + { + reporter.TryTakeOwnership("failed before the pipe opened"); + + // No client can read the failure, so the process must not linger holding + // the mount lock. The caller falls back to the process exit code. + Stopwatch elapsed = Stopwatch.StartNew(); + reporter.WaitForClientToReadFailure(); + elapsed.Stop(); + + Assert.That(elapsed.ElapsedMilliseconds, Is.LessThan(NoClientTimeoutMs)); + } + } + + [TestCase] + public void WaitUsesTheShortTimeoutWhenNoClientHasReceivedAStatus() + { + using (MountFailureReporter reporter = CreateReporter()) + { + reporter.OnNamedPipeReady(); + reporter.TryTakeOwnership("nobody is listening"); + + Stopwatch elapsed = Stopwatch.StartNew(); + reporter.WaitForClientToReadFailure(); + elapsed.Stop(); + + // Should give up after the no-client timeout, well short of the full one. + Assert.That(elapsed.ElapsedMilliseconds, Is.GreaterThanOrEqualTo(NoClientTimeoutMs - 50)); + Assert.That(elapsed.ElapsedMilliseconds, Is.LessThan(ReportTimeoutMs)); + } + } + + [TestCase] + public void WaitReturnsOnceAClientReadsTheFailure() + { + using (MountFailureReporter reporter = CreateReporter()) + { + reporter.OnNamedPipeReady(); + reporter.TryTakeOwnership("the real reason"); + reporter.OnStatusDelivered(carriedMountFailure: true); + + Stopwatch elapsed = Stopwatch.StartNew(); + reporter.WaitForClientToReadFailure(); + elapsed.Stop(); + + // Returns as soon as the failure was delivered, plus the drain. + Assert.That(elapsed.ElapsedMilliseconds, Is.LessThan(NoClientTimeoutMs)); + } + } + + [TestCase] + public void DeliveringANonFailureStatusDoesNotReleaseTheWait() + { + using (MountFailureReporter reporter = CreateReporter()) + { + reporter.OnNamedPipeReady(); + + // A client polled while the mount was still in progress. That proves + // somebody is listening, but it did not carry the failure. + reporter.OnStatusDelivered(carriedMountFailure: false); + reporter.TryTakeOwnership("the real reason"); + + Stopwatch elapsed = Stopwatch.StartNew(); + reporter.WaitForClientToReadFailure(); + elapsed.Stop(); + + // Must wait for the failure itself to be read, using the longer timeout + // because a client is known to be polling. + Assert.That(elapsed.ElapsedMilliseconds, Is.GreaterThanOrEqualTo(ReportTimeoutMs - 100)); + } + } + + [TestCase] + public void WaitIsReleasedByAClientThatReadsTheFailureLater() + { + using (MountFailureReporter reporter = CreateReporter()) + { + reporter.OnNamedPipeReady(); + reporter.OnStatusDelivered(carriedMountFailure: false); + reporter.TryTakeOwnership("the real reason"); + + Task client = Task.Run(() => + { + Thread.Sleep(100); + reporter.OnStatusDelivered(carriedMountFailure: true); + }); + + Stopwatch elapsed = Stopwatch.StartNew(); + reporter.WaitForClientToReadFailure(); + elapsed.Stop(); + + client.Wait(TimeSpan.FromSeconds(5)).ShouldBeTrue(); + + // Released by the delivery, not by the timeout. + Assert.That(elapsed.ElapsedMilliseconds, Is.LessThan(ReportTimeoutMs - 100)); + } + } + + [TestCase] + public void FormatFailureAppliesArguments() + { + MountFailureReporter.FormatFailure("Error: {0}", new object[] { "boom" }) + .ShouldEqual("Error: boom"); + } + + [TestCase] + public void FormatFailureLeavesTheMessageAloneWhenThereAreNoArguments() + { + // A pre-built message can legitimately contain braces, so it must not be run + // through string.Format when there is nothing to substitute. + MountFailureReporter.FormatFailure("a message with {braces} in it", null) + .ShouldEqual("a message with {braces} in it"); + + MountFailureReporter.FormatFailure("a message with {braces} in it", new object[0]) + .ShouldEqual("a message with {braces} in it"); + } + + [TestCase] + public void FormatFailureFallsBackWhenTheFormatStringIsMalformed() + { + // Failure text is built from exception messages and server responses, which + // can contain unbalanced braces. Formatting must never throw and mask the + // failure being reported. + string result = MountFailureReporter.FormatFailure("unbalanced {0} and {", new object[] { "value" }); + + result.ShouldEqual("unbalanced {0} and {"); + } + + private static MountFailureReporter CreateReporter() + { + return new MountFailureReporter(new MockTracer(), ReportTimeoutMs, NoClientTimeoutMs, DrainMs); + } + } +} From 974b651c71ccd189974d3a1f4910a659883e6644 Mon Sep 17 00:00:00 2001 From: Tyrie Vella Date: Wed, 2 Sep 2026 10:19:55 -0700 Subject: [PATCH 4/4] Tighten the MountFailureReporter surface and its test coverage 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 --- .../NamedPipes/MountFailureReporter.cs | 10 +++- .../Common/MountFailureReporterTests.cs | 58 +++++++++++++++++-- .../WaitUntilMountedFailureReportingTests.cs | 6 +- 3 files changed, 64 insertions(+), 10 deletions(-) diff --git a/GVFS/GVFS.Common/NamedPipes/MountFailureReporter.cs b/GVFS/GVFS.Common/NamedPipes/MountFailureReporter.cs index a1260d2cac..07d417059d 100644 --- a/GVFS/GVFS.Common/NamedPipes/MountFailureReporter.cs +++ b/GVFS/GVFS.Common/NamedPipes/MountFailureReporter.cs @@ -52,13 +52,13 @@ public sealed class MountFailureReporter : IDisposable /// /// Cap on how long to wait once a client is known to be polling. /// - public const int DefaultReportTimeoutMs = 2000; + internal const int DefaultReportTimeoutMs = 2000; /// /// Cap used when no client has received a status yet. It only has to cover the /// gap between the pipe opening and the client's first poll. /// - public const int DefaultNoClientTimeoutMs = 500; + internal const int DefaultNoClientTimeoutMs = 500; /// /// Grace period after a client reads the failure. Any client can satisfy the @@ -66,7 +66,7 @@ public sealed class MountFailureReporter : IDisposable /// "gvfs status" polls the same pipe. Keeping this above the client's 100ms poll /// interval means the mounting client still gets its answer on its next poll. /// - public const int DefaultDrainMs = 150; + internal const int DefaultDrainMs = 150; private readonly ITracer tracer; private readonly int reportTimeoutMs; @@ -216,6 +216,10 @@ public void WaitForClientToReadFailure() public void Dispose() { + // InProcessMount deliberately does not call this: it holds the reporter for + // the life of the process and leaves through Environment.Exit, which reclaims + // the handle. Do not dispose while a thread is inside + // WaitForClientToReadFailure -- WaitOne on a disposed handle throws. this.failureReported.Dispose(); } } diff --git a/GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs b/GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs index 18964f174c..eff6091bdd 100644 --- a/GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs +++ b/GVFS/GVFS.UnitTests/Common/MountFailureReporterTests.cs @@ -17,7 +17,10 @@ namespace GVFS.UnitTests.Common [TestFixture] public class MountFailureReporterTests { - private const int ReportTimeoutMs = 2000; + // Deliberately much smaller than the production defaults: these only have to be + // far enough apart to tell the two timeout paths apart, and one test has to wait + // the long one out in real time. + private const int ReportTimeoutMs = 600; private const int NoClientTimeoutMs = 200; private const int DrainMs = 20; @@ -96,7 +99,7 @@ public void WaitUsesTheShortTimeoutWhenNoClientHasReceivedAStatus() elapsed.Stop(); // Should give up after the no-client timeout, well short of the full one. - Assert.That(elapsed.ElapsedMilliseconds, Is.GreaterThanOrEqualTo(NoClientTimeoutMs - 50)); + Assert.That(elapsed.ElapsedMilliseconds, Is.GreaterThan(NoClientTimeoutMs / 2)); Assert.That(elapsed.ElapsedMilliseconds, Is.LessThan(ReportTimeoutMs)); } } @@ -136,8 +139,9 @@ public void DeliveringANonFailureStatusDoesNotReleaseTheWait() elapsed.Stop(); // Must wait for the failure itself to be read, using the longer timeout - // because a client is known to be polling. - Assert.That(elapsed.ElapsedMilliseconds, Is.GreaterThanOrEqualTo(ReportTimeoutMs - 100)); + // because a client is known to be polling. Asserting above the SHORT + // timeout is what proves the long path was selected. + Assert.That(elapsed.ElapsedMilliseconds, Is.GreaterThan(NoClientTimeoutMs * 2)); } } @@ -152,7 +156,7 @@ public void WaitIsReleasedByAClientThatReadsTheFailureLater() Task client = Task.Run(() => { - Thread.Sleep(100); + Thread.Sleep(50); reporter.OnStatusDelivered(carriedMountFailure: true); }); @@ -163,10 +167,52 @@ public void WaitIsReleasedByAClientThatReadsTheFailureLater() client.Wait(TimeSpan.FromSeconds(5)).ShouldBeTrue(); // Released by the delivery, not by the timeout. - Assert.That(elapsed.ElapsedMilliseconds, Is.LessThan(ReportTimeoutMs - 100)); + Assert.That(elapsed.ElapsedMilliseconds, Is.LessThan(ReportTimeoutMs)); + } + } + + [TestCase] + public void ProductionDefaultsSelectTheShorterTimeoutWhenNoClientIsListening() + { + // Everything else builds the reporter through the internal test constructor, + // so this is the only cover for the public constructor and its forwarding of + // the Default* constants. Without it, swapping DefaultReportTimeoutMs and + // DefaultNoClientTimeoutMs would ship unnoticed. + using (MountFailureReporter reporter = new MountFailureReporter(new MockTracer())) + { + reporter.OnNamedPipeReady(); + reporter.TryTakeOwnership("nobody is listening"); + + Stopwatch elapsed = Stopwatch.StartNew(); + reporter.WaitForClientToReadFailure(); + elapsed.Stop(); + + // The no-client timeout must be the one used, and it must be meaningfully + // shorter than the timeout used once a client is known to be polling. + Assert.That(elapsed.ElapsedMilliseconds, Is.GreaterThan(MountFailureReporter.DefaultNoClientTimeoutMs / 2)); + Assert.That(elapsed.ElapsedMilliseconds, Is.LessThan(MountFailureReporter.DefaultReportTimeoutMs)); } } + [TestCase] + public void ProductionDefaultsAreOrderedSensibly() + { + // A failed mount holds the mount lock and the named pipe until it exits, so + // these bound how long a user's next "gvfs mount" is delayed. + Assert.That( + MountFailureReporter.DefaultNoClientTimeoutMs, + Is.LessThan(MountFailureReporter.DefaultReportTimeoutMs), + "Waiting for a client that has never polled must not take longer than waiting for one that has."); + + // The drain has to outlast the client's 100ms GetStatus poll interval, or a + // concurrent "gvfs status" can consume the report signal and the mounting + // client never gets its answer. + Assert.That( + MountFailureReporter.DefaultDrainMs, + Is.GreaterThan(100), + "The drain must exceed the client's GetStatus poll interval."); + } + [TestCase] public void FormatFailureAppliesArguments() { diff --git a/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs b/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs index 2f89013c88..cbe6288222 100644 --- a/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs +++ b/GVFS/GVFS.UnitTests/Common/WaitUntilMountedFailureReportingTests.cs @@ -90,7 +90,11 @@ private static string RunAgainstMountFailedServer(string mountError) } finally { - serverTask.Wait(TimeSpan.FromSeconds(5)); + // Surfaces a hung server task instead of silently disposing the stream + // out from under it, which would fault an unobserved task and hide the + // real cause of a failure. + serverTask.Wait(TimeSpan.FromSeconds(5)).ShouldBeTrue( + "The stand-in mount server should have answered and completed."); } } }