diff --git a/GVFS/GVFS.CommandLine.Tests/GVFSMountExitCodeTests.cs b/GVFS/GVFS.CommandLine.Tests/GVFSMountExitCodeTests.cs new file mode 100644 index 000000000..ce440fbdb --- /dev/null +++ b/GVFS/GVFS.CommandLine.Tests/GVFSMountExitCodeTests.cs @@ -0,0 +1,41 @@ +using System; +using System.CommandLine; +using System.IO; +using GVFS.Common; +using GVFS.PlatformLoader; +using NUnit.Framework; + +namespace GVFS.CommandLine.Tests +{ + /// + /// Regression coverage for the GVFS.Mount exit code: the background mount + /// process must exit with the real ReturnCode when a mount attempt fails, + /// not with 0. System.CommandLine's Invoke() never rethrows an exception + /// that escapes the root command's action, so the action itself must catch + /// MountAbortedException and return its ReturnCode for Invoke() to report. + /// + [SetUpFixture] + public class GVFSMountExitCodeTestsSetup + { + [OneTimeSetUp] + public void SetUp() + { + GVFSPlatformLoader.Initialize(); + } + } + + [TestFixture] + public class GVFSMountExitCodeTests + { + [Test] + public void InvalidEnlistment_ReturnsGenericErrorExitCode() + { + RootCommand rootCommand = GVFS.Mount.Program.BuildRootCommand(); + string nonExistentPath = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString()); + + int exitCode = rootCommand.Parse(new[] { nonExistentPath }).Invoke(); + + Assert.That(exitCode, Is.EqualTo((int)ReturnCode.GenericError)); + } + } +} diff --git a/GVFS/GVFS.Hooks/Program.Worktree.cs b/GVFS/GVFS.Hooks/Program.Worktree.cs index 40c768ce0..a3d42b83b 100644 --- a/GVFS/GVFS.Hooks/Program.Worktree.cs +++ b/GVFS/GVFS.Hooks/Program.Worktree.cs @@ -91,7 +91,9 @@ private static void RunWorktreePostCommand(string[] args) /// /// Attempts to mount GVFS for a worktree, retrying on transient failures. - /// The first attempt shows output to the console; retries are quiet. + /// The first attempt shows output to the console; retries capture output + /// quietly but still print it to stderr on failure, so the hook never hides + /// why gvfs mount failed. /// Returns true if mount succeeded. /// private static bool TryMountWithRetry(string fullPath) @@ -112,6 +114,18 @@ private static bool TryMountWithRetry(string fullPath) { return true; } + + Console.Error.WriteLine( + $"warning: gvfs mount retry {retry + 1} for '{fullPath}' failed with exit code {result.ExitCode}."); + if (!string.IsNullOrWhiteSpace(result.Output)) + { + Console.Error.WriteLine($" stdout: {result.Output.Trim()}"); + } + + if (!string.IsNullOrWhiteSpace(result.Errors)) + { + Console.Error.WriteLine($" stderr: {result.Errors.Trim()}"); + } } return false; diff --git a/GVFS/GVFS.Mount/InProcessMountVerb.cs b/GVFS/GVFS.Mount/InProcessMountVerb.cs index 16328f60d..8fbb65307 100644 --- a/GVFS/GVFS.Mount/InProcessMountVerb.cs +++ b/GVFS/GVFS.Mount/InProcessMountVerb.cs @@ -82,7 +82,22 @@ public static RootCommand BuildRootCommand() verb.ShowDebugWindow = result.GetValue(debugWindowOption); verb.StartedByService = result.GetValue(startedByServiceOption) ?? "false"; verb.StartedByVerb = result.GetValue(startedByVerbOption); - verb.Execute(); + + // System.CommandLine's Invoke() does not rethrow exceptions that + // escape this action; it reports them and returns 1 without giving + // the caller access to the specific ReturnCode. Catch + // MountAbortedException here so its ReturnCode (e.g. + // MountAlreadyRunning) is preserved as the process exit code instead + // of being collapsed into a generic 1. + try + { + verb.Execute(); + return (int)ReturnCode.Success; + } + catch (MountAbortedException e) + { + return (int)e.Verb.ReturnCode; + } }); return rootCommand; @@ -112,48 +127,65 @@ public void Execute() JsonTracer tracer = this.CreateTracer(enlistment, verbosity, keywords); - CacheServerInfo cacheServer = CacheServerResolver.GetCacheServerFromConfig(enlistment); + // Everything below this point has a live tracer (and therefore a log + // file on disk), so wrap it in a catch-all: any exception that isn't + // already a MountAbortedException (e.g. a transient failure reading + // git config from CacheServerResolver.GetCacheServerFromConfig) must + // still be traced and reported instead of escaping silently and + // leaving behind an empty log with no explanation. + try + { + CacheServerInfo cacheServer = CacheServerResolver.GetCacheServerFromConfig(enlistment); + + tracer.WriteStartEvent( + enlistment.WorkingDirectoryRoot, + enlistment.RepoUrl, + cacheServer.Url, + new EventMetadata + { + { "IsElevated", GVFSPlatform.Instance.IsElevated() }, + { nameof(this.EnlistmentRootPathParameter), this.EnlistmentRootPathParameter }, + { nameof(this.StartedByService), this.StartedByService }, + { nameof(this.StartedByVerb), this.StartedByVerb }, + }); + + AppDomain.CurrentDomain.UnhandledException += (object sender, UnhandledExceptionEventArgs e) => + { + this.UnhandledGVFSExceptionHandler(tracer, sender, e); + }; - tracer.WriteStartEvent( - enlistment.WorkingDirectoryRoot, - enlistment.RepoUrl, - cacheServer.Url, - new EventMetadata + string error; + RetryConfig retryConfig; + if (!RetryConfig.TryLoadFromGitConfig(tracer, enlistment, out retryConfig, out error)) { - { "IsElevated", GVFSPlatform.Instance.IsElevated() }, - { nameof(this.EnlistmentRootPathParameter), this.EnlistmentRootPathParameter }, - { nameof(this.StartedByService), this.StartedByService }, - { nameof(this.StartedByVerb), this.StartedByVerb }, - }); + this.ReportErrorAndExit(tracer, "Failed to determine GVFS timeout and max retries: " + error); + } - AppDomain.CurrentDomain.UnhandledException += (object sender, UnhandledExceptionEventArgs e) => - { - this.UnhandledGVFSExceptionHandler(tracer, sender, e); - }; + GitStatusCacheConfig gitStatusCacheConfig; + if (!GitStatusCacheConfig.TryLoadFromGitConfig(tracer, enlistment, out gitStatusCacheConfig, out error)) + { + tracer.RelatedWarning("Failed to determine GVFS status cache backoff time: " + error); + gitStatusCacheConfig = GitStatusCacheConfig.DefaultConfig; + } - string error; - RetryConfig retryConfig; - if (!RetryConfig.TryLoadFromGitConfig(tracer, enlistment, out retryConfig, out error)) - { - this.ReportErrorAndExit(tracer, "Failed to determine GVFS timeout and max retries: " + error); - } + InProcessMount mountHelper = new InProcessMount(tracer, enlistment, cacheServer, retryConfig, gitStatusCacheConfig, this.ShowDebugWindow); - GitStatusCacheConfig gitStatusCacheConfig; - if (!GitStatusCacheConfig.TryLoadFromGitConfig(tracer, enlistment, out gitStatusCacheConfig, out error)) - { - tracer.RelatedWarning("Failed to determine GVFS status cache backoff time: " + error); - gitStatusCacheConfig = GitStatusCacheConfig.DefaultConfig; + try + { + mountHelper.Mount(verbosity, keywords); + } + catch (Exception ex) + { + this.ReportErrorAndExit(tracer, "Failed to mount: {0}", ex.Message); + } } - - InProcessMount mountHelper = new InProcessMount(tracer, enlistment, cacheServer, retryConfig, gitStatusCacheConfig, this.ShowDebugWindow); - - try + catch (MountAbortedException) { - mountHelper.Mount(verbosity, keywords); + throw; } catch (Exception ex) { - this.ReportErrorAndExit(tracer, "Failed to mount: {0}", ex.Message); + this.ReportErrorAndExit(tracer, "Mount failed unexpectedly: {0}", ex.Message); } } diff --git a/GVFS/GVFS.Mount/Program.cs b/GVFS/GVFS.Mount/Program.cs index 96584e113..e687ada58 100644 --- a/GVFS/GVFS.Mount/Program.cs +++ b/GVFS/GVFS.Mount/Program.cs @@ -1,5 +1,6 @@ using System.CommandLine; using System.Runtime.CompilerServices; +using GVFS.Common; using GVFS.PlatformLoader; using System; @@ -9,19 +10,26 @@ namespace GVFS.Mount { public class Program { - public static void Main(string[] args) + public static int Main(string[] args) { GVFSPlatformLoader.Initialize(); - try - { - RootCommand rootCommand = BuildRootCommand(); - rootCommand.Parse(args).Invoke(); - } - catch (MountAbortedException e) + + RootCommand rootCommand = BuildRootCommand(); + + // The root command's action catches MountAbortedException and maps it to + // its ReturnCode. Any other exception that escapes the action is caught + // by System.CommandLine itself, which still returns a nonzero code (1). + // Either way, Invoke()'s result is the real outcome of the mount attempt, + // so it must become our process exit code instead of being discarded. + int exitCode = rootCommand.Parse(args).Invoke(); + + if (exitCode != (int)ReturnCode.Success) { // Calling Environment.Exit() is required, to force all background threads to exit as well - Environment.Exit((int)e.Verb.ReturnCode); + Environment.Exit(exitCode); } + + return exitCode; } internal static RootCommand BuildRootCommand() => InProcessMountVerb.BuildRootCommand(); diff --git a/GVFS/GVFS.UnitTests/Common/WaitUntilMountedProcessTrackingTests.cs b/GVFS/GVFS.UnitTests/Common/WaitUntilMountedProcessTrackingTests.cs index cf04194eb..25304c795 100644 --- a/GVFS/GVFS.UnitTests/Common/WaitUntilMountedProcessTrackingTests.cs +++ b/GVFS/GVFS.UnitTests/Common/WaitUntilMountedProcessTrackingTests.cs @@ -46,6 +46,36 @@ public void ReturnsImmediatelyWhenMountProcessSnapshotReportsExited() Assert.That(elapsed.TotalSeconds, Is.LessThan(5), "WaitUntilMounted should bail out quickly when the snapshot reports the mount process exited"); } + [TestCase] + public void ReportsFailureWhenMountProcessExitsWithCodeZero() + { + // A mount process that exits before its named pipe is ready has + // failed even if its exit code happens to be 0 (Success). This + // can occur when an exception escapes the mount process after it + // has already been marked as exited but before it reports a + // non-zero ReturnCode. + const int FakePid = 11111; + const int FakeExitCode = 0; + Func snapshot = () => + { + return new GVFSEnlistment.MountProcessSnapshot(FakePid, hasExited: true, exitCode: FakeExitCode); + }; + + string errorMessage; + bool result = GVFSEnlistment.WaitUntilMounted( + new MockTracer(), + pipeName: "GVFS_no_such_pipe_for_test_" + Guid.NewGuid().ToString("N"), + enlistmentRoot: "C:\\fake\\root", + unattended: false, + mountProcessStatus: snapshot, + out errorMessage); + + result.ShouldBeFalse(); + errorMessage.ShouldNotBeNull(); + errorMessage.ShouldContain(FakePid.ToString()); + errorMessage.ShouldContain(FakeExitCode.ToString()); + } + [TestCase] public void DetectsLateProcessExitWhilePipeNeverAppears() { diff --git a/GVFS/GVFS/CommandLine/MountVerb.cs b/GVFS/GVFS/CommandLine/MountVerb.cs index 5ea8c5781..643ffb8d5 100644 --- a/GVFS/GVFS/CommandLine/MountVerb.cs +++ b/GVFS/GVFS/CommandLine/MountVerb.cs @@ -214,7 +214,17 @@ protected override void Execute(GVFSEnlistment enlistment) if (this.mountProcess.HasExited) { - mountExitCode = (ReturnCode)this.mountProcess.ExitCode; + // TryMount already reported a failure, so a child exit + // code of Success (0) is itself abnormal (e.g. the + // mount process exited before its named pipe was + // ready). Reporting Success here would make gvfs + // mount's own exit code say the mount worked when it + // did not, so keep the GenericError default instead. + ReturnCode childExitCode = (ReturnCode)this.mountProcess.ExitCode; + if (childExitCode != ReturnCode.Success) + { + mountExitCode = childExitCode; + } } } catch (InvalidOperationException)