diff --git a/GVFS/GVFS.Common/GVFSConstants.cs b/GVFS/GVFS.Common/GVFSConstants.cs index 3dd946bff..fd97ed375 100644 --- a/GVFS/GVFS.Common/GVFSConstants.cs +++ b/GVFS/GVFS.Common/GVFSConstants.cs @@ -58,6 +58,13 @@ public static class GitConfig public const string MaxHttpConnectionsConfig = GVFSPrefix + "max-http-connections"; + /// + /// Overrides how long a runtime credential fetch may block waiting on the + /// credential manager, in seconds. 0 or negative restores the pre-bound + /// behavior of waiting indefinitely. Read once into . + /// + public const string CredentialTimeoutSeconds = GVFSPrefix + "credential-timeout-seconds"; + public const string PrefetchUseIdx = GVFSPrefix + "prefetch-use-idx"; public const bool PrefetchUseIdxDefault = false; diff --git a/GVFS/GVFS.Common/Git/GitAuthentication.cs b/GVFS/GVFS.Common/Git/GitAuthentication.cs index 37c3563b5..b395b3ad6 100644 --- a/GVFS/GVFS.Common/Git/GitAuthentication.cs +++ b/GVFS/GVFS.Common/Git/GitAuthentication.cs @@ -16,6 +16,13 @@ public class GitAuthentication public const int DefaultCredentialTimeoutMs = 30_000; public const int BackgroundCredentialTimeoutMs = 120_000; + /// + /// Minimum time to wait for an in-flight credential fetch before giving up on + /// serialization. The effective wait is never shorter than the fetch timeout + /// itself, so a slow but legitimate prompt cannot cause a second prompt. + /// + private const int DefaultCredentialGateWaitMs = 60_000; + private readonly Lock gitAuthLock = new Lock(); private readonly SemaphoreSlim credentialGate = new SemaphoreSlim(1, 1); private readonly ICredentialStore credentialStore; @@ -68,7 +75,7 @@ public bool IsBackingOff private GitSsl GitSsl { get; } - public void ApproveCredentials(ITracer tracer, string credentialString) + public void ApproveCredentials(ITracer tracer, string credentialString, int credentialTimeoutMs = DefaultCredentialTimeoutMs) { lock (this.gitAuthLock) { @@ -86,7 +93,7 @@ public void ApproveCredentials(ITracer tracer, string credentialString) string password; if (TryParseCredentialString(this.cachedCredentialString, out username, out password)) { - if (!this.credentialStore.TryStoreCredential(tracer, this.repoUrl, username, password, out string error)) + if (!this.credentialStore.TryStoreCredential(tracer, this.repoUrl, username, password, out string error, credentialTimeoutMs)) { // Storing credentials is best effort attempt - log failure, but do not fail tracer.RelatedWarning("Failed to store credential string: {0}", error); @@ -107,7 +114,7 @@ public void ApproveCredentials(ITracer tracer, string credentialString) } } - public void RejectCredentials(ITracer tracer, string credentialString) + public void RejectCredentials(ITracer tracer, string credentialString, int credentialTimeoutMs = DefaultCredentialTimeoutMs) { lock (this.gitAuthLock) { @@ -118,7 +125,7 @@ public void RejectCredentials(ITracer tracer, string credentialString) // We can't assume that the credential store's cached credential is the same as the one we have. // Reload the credential from the store to ensure we're rejecting the correct one. int attemptsBeforeCheckingExistingCredential = this.numberOfAttempts; - if (this.TryCallGitCredential(tracer, out string getCredentialError)) + if (this.TryCallGitCredential(tracer, out string getCredentialError, out _, credentialTimeoutMs)) { if (this.cachedCredentialString != cachedCredentialAtStartOfReject) { @@ -139,7 +146,7 @@ public void RejectCredentials(ITracer tracer, string credentialString) string password; if (TryParseCredentialString(this.cachedCredentialString, out username, out password)) { - if (!this.credentialStore.TryDeleteCredential(tracer, this.repoUrl, username, password, out string error)) + if (!this.credentialStore.TryDeleteCredential(tracer, this.repoUrl, username, password, out string error, credentialTimeoutMs)) { // Deleting credentials is best effort attempt - log failure, but do not fail tracer.RelatedWarning("Failed to delete credential string: {0}", error); @@ -154,7 +161,7 @@ public void RejectCredentials(ITracer tracer, string credentialString) ["RepoUrl"] = this.repoUrl, }); tracer.RelatedWarning(metadata, "Failed to parse credential string for rejection. Rejecting any credential for this repo URL."); - this.credentialStore.TryDeleteCredential(tracer, this.repoUrl, username: null, password: null, error: out string error); + this.credentialStore.TryDeleteCredential(tracer, this.repoUrl, username: null, password: null, error: out string error, timeoutMs: credentialTimeoutMs); } this.cachedCredentialString = null; @@ -169,8 +176,20 @@ public void RejectCredentials(ITracer tracer, string credentialString) } } - public bool TryGetCredentials(ITracer tracer, out string credentialString, out string errorMessage) + public bool TryGetCredentials(ITracer tracer, out string credentialString, out string errorMessage, int credentialTimeoutMs = DefaultCredentialTimeoutMs) { + return this.TryGetCredentials(tracer, out credentialString, out errorMessage, out _, credentialTimeoutMs); + } + + /// + /// Fetches credentials, reporting via whether the failure was + /// the credential manager exceeding its bound rather than a genuine auth failure. Callers + /// use this to avoid immediately retrying, which would re-prompt the user. + /// + public bool TryGetCredentials(ITracer tracer, out string credentialString, out string errorMessage, out bool timedOut, int credentialTimeoutMs = DefaultCredentialTimeoutMs) + { + timedOut = false; + if (!this.isInitialized) { // Initialization may still be running in the background (mount can @@ -199,7 +218,7 @@ public bool TryGetCredentials(ITracer tracer, out string credentialString, out s return false; } - if (!this.TryCallGitCredential(tracer, out errorMessage)) + if (!this.TryCallGitCredential(tracer, out errorMessage, out timedOut, credentialTimeoutMs)) { return false; } @@ -285,7 +304,7 @@ public bool TryInitializeAndQueryGVFSConfig( // Server requires authentication — fetch credentials this.IsAnonymous = false; - if (!this.TryCallGitCredential(tracer, out errorMessage, credentialTimeoutMs)) + if (!this.TryCallGitCredential(tracer, out errorMessage, out _, credentialTimeoutMs)) { isAuthFailure = true; // Mark initialized even on failure so TryGetCredentials can @@ -327,7 +346,7 @@ internal bool TryInitializeAndRequireAuth(ITracer tracer, out string errorMessag throw new InvalidOperationException("Already initialized"); } - if (this.TryCallGitCredential(tracer, out errorMessage)) + if (this.TryCallGitCredential(tracer, out errorMessage, out _)) { this.MarkInitialized(); return true; @@ -419,20 +438,24 @@ private void MarkInitialized() this.initializationComplete.Set(); } - private bool TryCallGitCredential(ITracer tracer, out string errorMessage, int timeoutMs = -1) + private bool TryCallGitCredential(ITracer tracer, out string errorMessage, out bool timedOut, int timeoutMs = -1) { // Serialize credential fetches so only one git-credential-fill // process runs at a time. Without this, a background auth task // and a foreground object download could both spawn GCM prompts. - // Wait up to 60s for an in-flight fetch; if the gate is still - // held (e.g., background GCM prompt), fall through and let this - // caller spawn its own credential fetch. - bool acquired = this.credentialGate.Wait(60_000); + // Wait at least as long as the fetch itself may take; otherwise the + // gate would expire while the in-flight fetch is still legitimately + // waiting on the user, and we would fall through and spawn a second + // competing GCM prompt in exactly the slow-prompt case this bound + // exists to tolerate. + int gateTimeoutMs = timeoutMs < 0 ? DefaultCredentialGateWaitMs : Math.Max(DefaultCredentialGateWaitMs, timeoutMs); + bool acquired = this.credentialGate.Wait(gateTimeoutMs); + timedOut = false; try { string gitUsername; string gitPassword; - if (!this.credentialStore.TryGetCredential(tracer, this.repoUrl, out gitUsername, out gitPassword, out errorMessage, timeoutMs)) + if (!this.credentialStore.TryGetCredential(tracer, this.repoUrl, out gitUsername, out gitPassword, out errorMessage, out timedOut, timeoutMs)) { this.UpdateBackoff(); return false; diff --git a/GVFS/GVFS.Common/Git/GitProcess.cs b/GVFS/GVFS.Common/Git/GitProcess.cs index 03cc27b41..e0d7366e7 100644 --- a/GVFS/GVFS.Common/Git/GitProcess.cs +++ b/GVFS/GVFS.Common/Git/GitProcess.cs @@ -1,4 +1,4 @@ -using GVFS.Common.FileSystem; +using GVFS.Common.FileSystem; using GVFS.Common.Tracing; using System; using System.Collections.Generic; @@ -37,6 +37,12 @@ public class GitProcess : ICredentialStore /// private const int MaxCapturedStdOutChars = 128 * 1024 * 1024; // ~256 MB of UTF-16 + /// + /// How long to wait for a killed process tree to actually exit before we give up + /// and read whatever the async stdout/stderr readers have captured so far. + /// + private const int ProcessKillTimeoutMs = 5_000; + private static readonly Encoding UTF8NoBOM = new UTF8Encoding(false); private static bool failedToSetEncoding = false; private static string expireTimeDateString; @@ -192,7 +198,7 @@ public bool TryKillRunningProcess(out string processName, out int exitCode, out } } - public virtual bool TryDeleteCredential(ITracer tracer, string repoUrl, string username, string password, out string errorMessage) + public virtual bool TryDeleteCredential(ITracer tracer, string repoUrl, string username, string password, out string errorMessage, int timeoutMs = -1) { StringBuilder sb = new StringBuilder(); sb.AppendFormat("url={0}\n", repoUrl); @@ -214,7 +220,8 @@ public virtual bool TryDeleteCredential(ITracer tracer, string repoUrl, string u GenerateCredentialVerbCommand("reject"), stdin => stdin.Write(stdinConfig), null, - usePreCommandHook: false); + usePreCommandHook: false, + timeoutMs: timeoutMs); if (result.ExitCodeIsFailure) { @@ -228,7 +235,7 @@ public virtual bool TryDeleteCredential(ITracer tracer, string repoUrl, string u return true; } - public virtual bool TryStoreCredential(ITracer tracer, string repoUrl, string username, string password, out string errorMessage) + public virtual bool TryStoreCredential(ITracer tracer, string repoUrl, string username, string password, out string errorMessage, int timeoutMs = -1) { StringBuilder sb = new StringBuilder(); sb.AppendFormat("url={0}\n", repoUrl); @@ -242,7 +249,8 @@ public virtual bool TryStoreCredential(ITracer tracer, string repoUrl, string us GenerateCredentialVerbCommand("approve"), stdin => stdin.Write(stdinConfig), null, - usePreCommandHook: false); + usePreCommandHook: false, + timeoutMs: timeoutMs); if (result.ExitCodeIsFailure) { @@ -320,11 +328,13 @@ public virtual bool TryGetCredential( out string username, out string password, out string errorMessage, + out bool timedOut, int timeoutMs = -1) { username = null; password = null; errorMessage = null; + timedOut = false; using (ITracer activity = tracer.StartActivity(nameof(this.TryGetCredential), EventLevel.Informational)) { @@ -343,10 +353,21 @@ public virtual bool TryGetCredential( if (gitCredentialOutput.Errors.StartsWith("Operation timed out")) { + timedOut = true; errorMessage = "Credential manager did not respond within " + (timeoutMs / 1000) + " seconds"; - tracer.RelatedWarning( + + // Structured fields (not just message text) so the rate of this bound + // firing can be measured, and so a timeout can be correlated with a + // later successful fetch to tell "prevented a hang" apart from + // "cut off a prompt the user was about to answer". + errorData.Add("Area", nameof(GitProcess)); + errorData.Add("Method", nameof(this.TryGetCredential)); + errorData.Add("timeoutMs", timeoutMs); + errorData.Add("RepoUrl", repoUrl); + tracer.RelatedEvent( + EventLevel.Warning, + "CredentialFetchTimedOut", errorData, - "Git credential fill timed out after " + timeoutMs + "ms", Keywords.Network | Keywords.Telemetry); } else @@ -1051,7 +1072,14 @@ protected virtual Result InvokeGitImpl( if (!this.executingProcess.WaitForExit(timeoutMs)) { - this.executingProcess.Kill(); + // Kill the entire process tree. Killing only git.exe would leave + // helper children (e.g. an interactive credential manager prompt) + // running, holding the credential store and showing orphaned UI. + this.executingProcess.Kill(entireProcessTree: true); + + // Give the tree a bounded chance to actually exit so the async + // stdout/stderr readers flush before we read their buffers. + this.executingProcess.WaitForExit(ProcessKillTimeoutMs); return new Result(output.ToString(), "Operation timed out: " + errors.ToString(), Result.GenericFailureCode, output.Truncated, errors.Truncated); } diff --git a/GVFS/GVFS.Common/Git/ICredentialStore.cs b/GVFS/GVFS.Common/Git/ICredentialStore.cs index 9ab38e13d..1a578418e 100644 --- a/GVFS/GVFS.Common/Git/ICredentialStore.cs +++ b/GVFS/GVFS.Common/Git/ICredentialStore.cs @@ -4,10 +4,10 @@ namespace GVFS.Common.Git { public interface ICredentialStore { - bool TryGetCredential(ITracer tracer, string url, out string username, out string password, out string error, int timeoutMs = -1); + bool TryGetCredential(ITracer tracer, string url, out string username, out string password, out string error, out bool timedOut, int timeoutMs = -1); - bool TryStoreCredential(ITracer tracer, string url, string username, string password, out string error); + bool TryStoreCredential(ITracer tracer, string url, string username, string password, out string error, int timeoutMs = -1); - bool TryDeleteCredential(ITracer tracer, string url, string username, string password, out string error); + bool TryDeleteCredential(ITracer tracer, string url, string username, string password, out string error, int timeoutMs = -1); } } diff --git a/GVFS/GVFS.Common/Http/HttpRequestor.cs b/GVFS/GVFS.Common/Http/HttpRequestor.cs index 0f9767dde..a73b38660 100644 --- a/GVFS/GVFS.Common/Http/HttpRequestor.cs +++ b/GVFS/GVFS.Common/Http/HttpRequestor.cs @@ -84,6 +84,17 @@ protected HttpRequestor(ITracer tracer, RetryConfig retryConfig, Enlistment enli protected ITracer Tracer { get; } + // Runtime credential fetches (object/pack downloads, incl. background + // maintenance prefetch) are bounded so a missed/ignored credential prompt + // can't hang forever. The bound is generous (RetryConfig's 120s default) + // rather than the 30s default: this same requestor is shared by interactive + // on-demand hydration and by the user-initiated prefetch/clone verbs, where + // a human may legitimately take longer than 30s to answer a GCM cold-start / + // MFA / smartcard prompt. 120s still bounds the hang while being long enough + // that a noticed prompt is not cut off spuriously. The value comes from the + // already-loaded RetryConfig so no config read happens per requestor. + protected virtual int CredentialTimeoutMs => this.RetryConfig.CredentialTimeoutMs; + public static long GetNewRequestId() { return Interlocked.Increment(ref requestCount); @@ -109,12 +120,17 @@ protected GitEndPointResponseData SendRequest( string authString = null; string errorMessage; if (!this.authentication.IsAnonymous && - !this.authentication.TryGetCredentials(this.Tracer, out authString, out errorMessage)) + !this.authentication.TryGetCredentials(this.Tracer, out authString, out errorMessage, out bool credentialFetchTimedOut, this.CredentialTimeoutMs)) { return new GitEndPointResponseData( HttpStatusCode.Unauthorized, new GitObjectsHttpException(HttpStatusCode.Unauthorized, errorMessage), - shouldRetry: true, + + // A timed-out credential fetch means nobody answered the prompt. Retrying + // immediately just spawns another prompt and burns the retry budget on a + // human-response bound (up to MaxAttempts x CredentialTimeoutMs), so give up + // and let backoff decide when another attempt is worthwhile. + shouldRetry: !credentialFetchTimedOut, message: null, onResponseDisposed: null); } @@ -207,7 +223,7 @@ protected GitEndPointResponseData SendRequest( if (!this.authentication.IsAnonymous) { - this.authentication.ApproveCredentials(this.Tracer, authString); + this.authentication.ApproveCredentials(this.Tracer, authString, this.CredentialTimeoutMs); } Stream responseStream = response.Content.ReadAsStreamAsync().GetAwaiter().GetResult(); @@ -234,7 +250,7 @@ protected GitEndPointResponseData SendRequest( } else if (response.StatusCode == HttpStatusCode.Unauthorized || response.StatusCode == HttpStatusCode.BadRequest || response.StatusCode == HttpStatusCode.Redirect) { - this.authentication.RejectCredentials(this.Tracer, authString); + this.authentication.RejectCredentials(this.Tracer, authString, this.CredentialTimeoutMs); if (!this.authentication.IsBackingOff) { errorMessage = string.Format("Server returned error code {0} ({1}). Your PAT may be expired and we are asking for a new one. Original error message from server: {2}", statusInt, response.StatusCode, errorMessage); diff --git a/GVFS/GVFS.Common/RetryConfig.cs b/GVFS/GVFS.Common/RetryConfig.cs index 4462a18bc..c4e8b5ca2 100644 --- a/GVFS/GVFS.Common/RetryConfig.cs +++ b/GVFS/GVFS.Common/RetryConfig.cs @@ -11,6 +11,15 @@ public class RetryConfig public const int DefaultTimeoutSeconds = 30; public const int FetchAndCloneTimeoutMinutes = 10; + /// + /// Default bound for a runtime credential fetch. Deliberately generous: the mount's + /// requestor is shared by the background maintenance prefetch, interactive on-demand + /// hydration, and the user-initiated prefetch/clone verbs, where a human may take + /// longer than the 30s request timeout to answer a GCM cold-start / MFA / smartcard + /// prompt. It still bounds the indefinite hang. + /// + public const int DefaultCredentialTimeoutSeconds = 120; + private const string EtwArea = nameof(RetryConfig); private const int MinRetries = 0; @@ -23,9 +32,15 @@ public RetryConfig(int maxRetries = DefaultMaxRetries) } public RetryConfig(int maxRetries, TimeSpan timeout) + : this(maxRetries, timeout, DefaultCredentialTimeoutSeconds * 1000) + { + } + + public RetryConfig(int maxRetries, TimeSpan timeout, int credentialTimeoutMs) { this.MaxRetries = maxRetries; this.Timeout = timeout; + this.CredentialTimeoutMs = credentialTimeoutMs; } public int MaxRetries { get; } @@ -36,6 +51,13 @@ public int MaxAttempts public TimeSpan Timeout { get; set; } + /// + /// How long a runtime credential fetch may block waiting on the credential manager. + /// A negative value waits indefinitely, which is the historical behavior and reopens + /// the hang this bound was added to prevent. + /// + public int CredentialTimeoutMs { get; } + public static bool TryLoadFromGitConfig(ITracer tracer, Enlistment enlistment, out RetryConfig retryConfig, out string error) { return TryLoadFromGitConfig(tracer, new GitProcess(enlistment), out retryConfig, out error); @@ -80,7 +102,25 @@ public static bool TryLoadFromGitConfig(ITracer tracer, GitProcess git, out Retr return false; } - retryConfig = new RetryConfig(maxRetries, timeout); + int credentialTimeoutMs; + if (!TryLoadCredentialTimeoutMs(git, out credentialTimeoutMs, out error)) + { + if (tracer != null) + { + tracer.RelatedError( + new EventMetadata + { + { "Area", EtwArea }, + { "maxRetries", maxRetries }, + { "error", error } + }, + "TryLoadConfig: TryLoadCredentialTimeoutMs failed"); + } + + return false; + } + + retryConfig = new RetryConfig(maxRetries, timeout, credentialTimeoutMs); if (tracer != null) { @@ -92,6 +132,7 @@ public static bool TryLoadFromGitConfig(ITracer tracer, GitProcess git, out Retr { "Area", EtwArea }, { "Timeout", retryConfig.Timeout }, { "MaxRetries", retryConfig.MaxRetries }, + { "CredentialTimeoutMs", retryConfig.CredentialTimeoutMs }, { TracingConstants.MessageKey.InfoMessage, "RetryConfigLoaded" } }); } @@ -99,8 +140,7 @@ public static bool TryLoadFromGitConfig(ITracer tracer, GitProcess git, out Retr return true; } - private static bool TryLoadMaxRetries(GitProcess git, out int attempts, out string error) - { + private static bool TryLoadMaxRetries(GitProcess git, out int attempts, out string error) { return TryGetFromGitConfig( git, GVFSConstants.GitConfig.MaxRetriesConfig, @@ -129,6 +169,31 @@ private static bool TryLoadTimeout(GitProcess git, out TimeSpan timeout, out str return true; } + /// + /// Reads the credential-fetch bound, in seconds, from git config. A configured value of + /// 0 or less selects an unbounded wait, so this deliberately allows non-positive values + /// rather than treating them as out of range. + /// + private static bool TryLoadCredentialTimeoutMs(GitProcess git, out int credentialTimeoutMs, out string error) + { + credentialTimeoutMs = DefaultCredentialTimeoutSeconds * 1000; + + int credentialTimeoutSeconds; + if (!TryGetFromGitConfig( + git, + GVFSConstants.GitConfig.CredentialTimeoutSeconds, + DefaultCredentialTimeoutSeconds, + int.MinValue, + out credentialTimeoutSeconds, + out error)) + { + return false; + } + + credentialTimeoutMs = credentialTimeoutSeconds <= 0 ? -1 : credentialTimeoutSeconds * 1000; + return true; + } + private static bool TryGetFromGitConfig(GitProcess git, string configName, int defaultValue, int minValue, out int value, out string error) { GitProcess.ConfigResult result = git.GetFromConfig(configName); diff --git a/GVFS/GVFS.UnitTests/Common/RetryConfigTests.cs b/GVFS/GVFS.UnitTests/Common/RetryConfigTests.cs index 0f8c45b26..c418ff74e 100644 --- a/GVFS/GVFS.UnitTests/Common/RetryConfigTests.cs +++ b/GVFS/GVFS.UnitTests/Common/RetryConfigTests.cs @@ -33,6 +33,7 @@ public void TryLoadConfigUsesDefaultValuesWhenEntriesNotInConfig() MockGitProcess gitProcess = new MockGitProcess(); gitProcess.SetExpectedCommandResult("config gvfs.max-retries", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.GenericFailureCode)); gitProcess.SetExpectedCommandResult("config gvfs.timeout-seconds", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.GenericFailureCode)); + gitProcess.SetExpectedCommandResult("config gvfs.credential-timeout-seconds", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.GenericFailureCode)); RetryConfig config; string error; @@ -41,6 +42,7 @@ public void TryLoadConfigUsesDefaultValuesWhenEntriesNotInConfig() config.MaxRetries.ShouldEqual(RetryConfig.DefaultMaxRetries); config.MaxAttempts.ShouldEqual(config.MaxRetries + 1); config.Timeout.ShouldEqual(TimeSpan.FromSeconds(RetryConfig.DefaultTimeoutSeconds)); + config.CredentialTimeoutMs.ShouldEqual(RetryConfig.DefaultCredentialTimeoutSeconds * 1000); } [TestCase] @@ -50,6 +52,7 @@ public void TryLoadConfigUsesDefaultValuesWhenEntriesAreBlank() MockGitProcess gitProcess = new MockGitProcess(); gitProcess.SetExpectedCommandResult("config gvfs.max-retries", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); gitProcess.SetExpectedCommandResult("config gvfs.timeout-seconds", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + gitProcess.SetExpectedCommandResult("config gvfs.credential-timeout-seconds", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); RetryConfig config; string error; @@ -58,6 +61,7 @@ public void TryLoadConfigUsesDefaultValuesWhenEntriesAreBlank() config.MaxRetries.ShouldEqual(RetryConfig.DefaultMaxRetries); config.MaxAttempts.ShouldEqual(config.MaxRetries + 1); config.Timeout.ShouldEqual(TimeSpan.FromSeconds(RetryConfig.DefaultTimeoutSeconds)); + config.CredentialTimeoutMs.ShouldEqual(RetryConfig.DefaultCredentialTimeoutSeconds * 1000); } [TestCase] @@ -93,11 +97,13 @@ public void TryLoadConfigUsesConfiguredValues() { int maxRetries = RetryConfig.DefaultMaxRetries + 1; int timeoutSeconds = RetryConfig.DefaultTimeoutSeconds + 1; + int credentialTimeoutSeconds = RetryConfig.DefaultCredentialTimeoutSeconds + 1; MockTracer tracer = new MockTracer(); MockGitProcess gitProcess = new MockGitProcess(); gitProcess.SetExpectedCommandResult("config gvfs.max-retries", () => new GitProcess.Result(maxRetries.ToString(), string.Empty, GitProcess.Result.SuccessCode)); gitProcess.SetExpectedCommandResult("config gvfs.timeout-seconds", () => new GitProcess.Result(timeoutSeconds.ToString(), string.Empty, GitProcess.Result.SuccessCode)); + gitProcess.SetExpectedCommandResult("config gvfs.credential-timeout-seconds", () => new GitProcess.Result(credentialTimeoutSeconds.ToString(), string.Empty, GitProcess.Result.SuccessCode)); RetryConfig config; string error; @@ -106,6 +112,33 @@ public void TryLoadConfigUsesConfiguredValues() config.MaxRetries.ShouldEqual(maxRetries); config.MaxAttempts.ShouldEqual(config.MaxRetries + 1); config.Timeout.ShouldEqual(TimeSpan.FromSeconds(timeoutSeconds)); + config.CredentialTimeoutMs.ShouldEqual(credentialTimeoutSeconds * 1000); + } + + [TestCase] + public void TryLoadConfigTreatsNonPositiveCredentialTimeoutAsUnbounded() + { + // A non-positive value is a deliberate escape hatch selecting the historical + // unbounded wait, so it must be accepted rather than rejected as out of range. + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = new MockGitProcess(); + gitProcess.SetExpectedCommandResult("config gvfs.max-retries", () => new GitProcess.Result("3", string.Empty, GitProcess.Result.SuccessCode)); + gitProcess.SetExpectedCommandResult("config gvfs.timeout-seconds", () => new GitProcess.Result("30", string.Empty, GitProcess.Result.SuccessCode)); + gitProcess.SetExpectedCommandResult("config gvfs.credential-timeout-seconds", () => new GitProcess.Result("0", string.Empty, GitProcess.Result.SuccessCode)); + + RetryConfig config; + string error; + RetryConfig.TryLoadFromGitConfig(tracer, gitProcess, out config, out error).ShouldEqual(true); + config.CredentialTimeoutMs.ShouldEqual(-1, "0 seconds should select an unbounded wait"); + } + + [TestCase] + public void RetryConfigDefaultsCredentialTimeoutWhenNotLoadedFromConfig() + { + // Requestors constructed with a hand-built RetryConfig (tests, FastFetch, profiling) + // must still get a bounded credential fetch rather than an unbounded default. + new RetryConfig().CredentialTimeoutMs.ShouldEqual(RetryConfig.DefaultCredentialTimeoutSeconds * 1000); + new RetryConfig(3, TimeSpan.FromSeconds(30)).CredentialTimeoutMs.ShouldEqual(RetryConfig.DefaultCredentialTimeoutSeconds * 1000); } } } diff --git a/GVFS/GVFS.UnitTests/Git/GitAuthenticationTests.cs b/GVFS/GVFS.UnitTests/Git/GitAuthenticationTests.cs index 25aa675b7..b388f61da 100644 --- a/GVFS/GVFS.UnitTests/Git/GitAuthenticationTests.cs +++ b/GVFS/GVFS.UnitTests/Git/GitAuthenticationTests.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.Linq; using System.Threading; using System.Threading.Tasks; @@ -342,6 +342,125 @@ public void TryGetCredentialsWaitsForBackgroundInitializationThenSucceeds() authString.ShouldNotBeNull("A credential string should be returned"); } + [TestCase] + public void TryGetCredentialsTimesOutWhenCredentialManagerDoesNotRespond() + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = this.GetGitProcess(); + + GitAuthentication dut = new GitAuthentication(gitProcess, "mock://repoUrl"); + dut.TryInitializeAndRequireAuth(tracer, out _); + + string authString; + string err; + dut.TryGetCredentials(tracer, out authString, out err).ShouldEqual(true, "Initial credential fetch should succeed: " + err); + + // Override the fill command to simulate a credential manager timeout + gitProcess.SetExpectedCommandResult( + $"{AzureDevOpsUseHttpPathString} credential fill", + () => new GitProcess.Result(string.Empty, "Operation timed out: git credential fill", GitProcess.Result.GenericFailureCode), + matchPrefix: true); + + // Reject clears the cache so the next TryGetCredentials must refetch + dut.RejectCredentials(tracer, authString); + + // The re-fetch should time out + dut.TryGetCredentials(tracer, out authString, out err, credentialTimeoutMs: 1000).ShouldEqual(false, "Expected timeout to cause failure"); + err.ShouldContain("did not respond"); + + // Assert the bound was actually plumbed all the way down to the git invocation. + // Without this the test would still pass with the timeout plumbing reverted, because + // GitProcess maps any "Operation timed out" stderr to a "did not respond" message + // (with timeoutMs = -1 that renders as "within 0 seconds", which also matches above). + gitProcess.LastInvokedTimeoutMs.ShouldEqual(1000, "Expected the credential timeout to reach InvokeGitImpl"); + err.ShouldContain("within 1 seconds"); + } + + [TestCase] + public void TryGetCredentialsReportsTimedOutOnlyForTimeouts() + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = this.GetGitProcess(); + + GitAuthentication dut = new GitAuthentication(gitProcess, "mock://repoUrl"); + dut.TryInitializeAndRequireAuth(tracer, out _); + + string authString; + string err; + bool timedOut; + dut.TryGetCredentials(tracer, out authString, out err, out timedOut).ShouldEqual(true, "Initial credential fetch should succeed: " + err); + timedOut.ShouldEqual(false, "A successful fetch is not a timeout"); + + // A generic (non-timeout) credential failure must NOT be reported as a timeout, + // otherwise a real auth failure would incorrectly suppress the caller's retry. + gitProcess.SetExpectedCommandResult( + $"{AzureDevOpsUseHttpPathString} credential fill", + () => new GitProcess.Result(string.Empty, "fatal: could not read Username", GitProcess.Result.GenericFailureCode), + matchPrefix: true); + + dut.RejectCredentials(tracer, authString); + dut.TryGetCredentials(tracer, out authString, out err, out timedOut).ShouldEqual(false, "Expected the credential failure to fail"); + timedOut.ShouldEqual(false, "A generic credential failure must not be reported as a timeout"); + + // Now a real timeout must be reported as one, so the caller can stop retrying. + // Use a fresh instance: the failure above left backoff engaged on this one, and + // initialization must succeed before the fill is switched to timing out. + MockGitProcess timingOutProcess = this.GetGitProcess(); + GitAuthentication timingOutDut = new GitAuthentication(timingOutProcess, "mock://repoUrl"); + timingOutDut.TryInitializeAndRequireAuth(tracer, out _); + + string timingOutAuth; + timingOutDut.TryGetCredentials(tracer, out timingOutAuth, out err).ShouldEqual(true, "Initial fetch should succeed: " + err); + + timingOutProcess.SetExpectedCommandResult( + $"{AzureDevOpsUseHttpPathString} credential fill", + () => new GitProcess.Result(string.Empty, "Operation timed out: git credential fill", GitProcess.Result.GenericFailureCode), + matchPrefix: true); + + timingOutDut.RejectCredentials(tracer, timingOutAuth); + + timingOutDut.TryGetCredentials(tracer, out _, out err, out timedOut, credentialTimeoutMs: 1000).ShouldEqual(false, "Expected timeout to cause failure"); + timedOut.ShouldEqual(true, "A credential manager timeout must be reported as a timeout"); + } + + [TestCase] + public void RejectCredentialsBoundsTheCredentialReload() + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = this.GetGitProcess(); + + GitAuthentication dut = new GitAuthentication(gitProcess, "mock://repoUrl"); + dut.TryInitializeAndRequireAuth(tracer, out _); + + string authString; + string err; + dut.TryGetCredentials(tracer, out authString, out err).ShouldEqual(true, "Initial credential fetch should succeed: " + err); + + // The 401-retry leg reloads the credential and then erases it. Both legs spawn a git + // process, and both must honor the caller's bound rather than waiting forever. + gitProcess.InvokedTimeoutMs.Clear(); + dut.RejectCredentials(tracer, authString, credentialTimeoutMs: 1000); + + gitProcess.InvokedTimeoutMs.Count.ShouldEqual(2, "Expected RejectCredentials to reload and then erase the credential"); + gitProcess.InvokedTimeoutMs.ShouldNotContain(timeout => timeout < 0); + gitProcess.LastInvokedTimeoutMs.ShouldEqual(1000, "Expected the credential erase to be bounded too"); + } + + [TestCase] + public void TryGetCredentialsSucceedsWithExplicitTimeout() + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = this.GetGitProcess(); + + GitAuthentication dut = new GitAuthentication(gitProcess, "mock://repoUrl"); + dut.TryInitializeAndRequireAuth(tracer, out _); + + string cred; + string err; + dut.TryGetCredentials(tracer, out cred, out err, credentialTimeoutMs: 30000).ShouldEqual(true, "Expected success with explicit timeout: " + err); + cred.ShouldNotBeNull(); + } + private MockGitProcess GetGitProcess() { MockGitProcess gitProcess = new MockGitProcess(); diff --git a/GVFS/GVFS.UnitTests/Mock/Git/MockGitProcess.cs b/GVFS/GVFS.UnitTests/Mock/Git/MockGitProcess.cs index c9095cc2c..69cad652f 100644 --- a/GVFS/GVFS.UnitTests/Mock/Git/MockGitProcess.cs +++ b/GVFS/GVFS.UnitTests/Mock/Git/MockGitProcess.cs @@ -18,12 +18,26 @@ public MockGitProcess() : base(new MockGVFSEnlistment()) { this.CommandsRun = new List(); + this.InvokedTimeoutMs = new List(); + this.LastInvokedTimeoutMs = null; this.StoredCredentials = new Dictionary(StringComparer.OrdinalIgnoreCase); this.CredentialApprovals = new Dictionary>(); this.CredentialRejections = new Dictionary>(); } public List CommandsRun { get; } + + /// + /// The timeout passed to every InvokeGitImpl call, in order. Lets tests assert that a + /// caller actually plumbed a finite timeout rather than defaulting to -1 (infinite). + /// + public List InvokedTimeoutMs { get; } + + /// + /// The timeout passed to the most recent InvokeGitImpl call, or null if none has run. + /// + public int? LastInvokedTimeoutMs { get; private set; } + public bool ShouldFail { get; set; } public Dictionary StoredCredentials { get; } public Dictionary> CredentialApprovals { get; } @@ -35,7 +49,7 @@ public void SetExpectedCommandResult(string command, Func result, bool m this.expectedCommandInfos.Add(commandInfo); } - public override bool TryStoreCredential(ITracer tracer, string repoUrl, string username, string password, out string error) + public override bool TryStoreCredential(ITracer tracer, string repoUrl, string username, string password, out string error, int timeoutMs = -1) { Credential credential = new Credential(username, password); @@ -52,10 +66,10 @@ public override bool TryStoreCredential(ITracer tracer, string repoUrl, string u // Store the credential this.StoredCredentials[repoUrl] = credential; - return base.TryStoreCredential(tracer, repoUrl, username, password, out error); + return base.TryStoreCredential(tracer, repoUrl, username, password, out error, timeoutMs); } - public override bool TryDeleteCredential(ITracer tracer, string repoUrl, string username, string password, out string error) + public override bool TryDeleteCredential(ITracer tracer, string repoUrl, string username, string password, out string error, int timeoutMs = -1) { Credential credential = new Credential(username, password); @@ -72,7 +86,7 @@ public override bool TryDeleteCredential(ITracer tracer, string repoUrl, string // Erase the credential this.StoredCredentials.Remove(repoUrl); - return base.TryDeleteCredential(tracer, repoUrl, username, password, out error); + return base.TryDeleteCredential(tracer, repoUrl, username, password, out error, timeoutMs); } protected override Result InvokeGitImpl( @@ -87,6 +101,8 @@ protected override Result InvokeGitImpl( bool usePrecommandHook = true) { this.CommandsRun.Add(command); + this.LastInvokedTimeoutMs = timeoutMs; + this.InvokedTimeoutMs.Add(timeoutMs); if (this.ShouldFail) {