From 7895b454b79dae3a1998314b741e7445f45f05d7 Mon Sep 17 00:00:00 2001 From: Tyrie Vella Date: Wed, 8 Jul 2026 10:49:44 -0700 Subject: [PATCH] Bound runtime credential fetch so prefetch can't hang on auth The runtime credential path (HttpRequestor.SendRequest -> GitAuthentication.TryGetCredentials/RejectCredentials -> TryCallGitCredential) called git-credential with timeoutMs = -1, so Process.WaitForExit(-1) waited forever. When a GCM auth popup was missed (e.g. behind another window), the mount's background maintenance PrefetchStep blocked indefinitely while holding the shared prefetch-commits-trees.lock, which in turn blocked a user-initiated `gvfs prefetch`. The mount startup auth path was already bounded via credentialTimeoutMs; this extends the same bound to every runtime credential invocation: - TryGetCredentials takes credentialTimeoutMs (default DefaultCredentialTimeoutMs) and plumbs it to TryCallGitCredential. - RejectCredentials, which reloads the credential on the 401-retry leg, takes and plumbs the same timeout (this leg is the actual stale-token hang path and was otherwise still unbounded). - ApproveCredentials, RejectCredentials and the ICredentialStore store/delete operations are bounded too. `git credential approve` and `git credential reject` previously ran with timeoutMs = -1 while holding gitAuthLock, so a stalled helper could still pin the prefetch lock forever even after the fill leg was bounded. - HttpRequestor exposes a protected virtual CredentialTimeoutMs and passes it to TryGetCredentials, RejectCredentials and ApproveCredentials. The bound is generous (120s) rather than the 30s default: 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 legitimately take longer than 30s to answer a GCM cold-start / MFA / smartcard prompt. 120s still bounds the hang while being long enough not to cut off a prompt the user is actively answering. The value lives on RetryConfig, which is already loaded once from git config and already passed into the HttpRequestor constructor alongside MaxRetries and Timeout. It is overridable via gvfs.credential-timeout-seconds; 0 or less restores the old unbounded wait as a field escape hatch. Reading it here rather than inside the requestor keeps requestor construction free of config I/O: a per-instance read would spawn `git config` on the mount startup path, and GetFromConfig itself runs unbounded, which is exactly the class of unbounded git invocation this change exists to remove. The credential serialization gate now waits at least as long as the fetch it is serializing. It previously waited a fixed 60s, and on expiry fell through and spawned a second credential fetch. With a 120s fetch bound that guaranteed a second, competing GCM prompt in exactly the slow-prompt case the longer bound exists to tolerate. A timed-out fetch no longer asks the caller to retry. SendRequest previously returned shouldRetry: true for every credential failure, so a timeout burned the whole RetryWrapper budget (up to MaxAttempts x 120s), re-prompting the user each time. TryGetCredentials now reports whether the failure was a timeout, and SendRequest sets shouldRetry accordingly; genuine auth failures still retry as before. On timeout the git process tree is killed, not just git.exe. Killing only git.exe left the credential helper child alive, holding the credential store and showing orphaned prompt UI. The kill is now followed by a bounded wait so the async stdout/stderr readers flush before their buffers are read. The timeout is reported as a distinct CredentialFetchTimedOut telemetry event with structured timeoutMs and RepoUrl fields, rather than only as warning message text. This is what makes the 120s choice measurable in the field: how often the bound fires, and whether a timeout is followed by a successful fetch (a prompt that was cut off) or not (a hang that was prevented). On timeout the fetch fails, backoff engages, the download gives up, and the lock is released instead of hanging forever. Tests: MockGitProcess now records the timeout passed to each git invocation, so tests can assert the bound is actually plumbed rather than just that a failure message appears. The timeout test asserts the observed timeout and the rendered "within 1 seconds" message; reverting the plumbing makes it fail (verified by mutation). Adds a test that the 401-reject leg bounds both the credential reload and the erase, a test that only genuine timeouts are reported as timeouts so a real auth failure still retries (also mutation-verified), and RetryConfig coverage for the default, configured, and unbounded-escape-hatch values. Assisted-by: Claude Opus 4.8 Signed-off-by: Tyrie Vella --- GVFS/GVFS.Common/GVFSConstants.cs | 7 + GVFS/GVFS.Common/Git/GitAuthentication.cs | 55 +++++--- GVFS/GVFS.Common/Git/GitProcess.cs | 44 +++++-- GVFS/GVFS.Common/Git/ICredentialStore.cs | 6 +- GVFS/GVFS.Common/Http/HttpRequestor.cs | 24 +++- GVFS/GVFS.Common/RetryConfig.cs | 71 +++++++++- .../GVFS.UnitTests/Common/RetryConfigTests.cs | 33 +++++ .../Git/GitAuthenticationTests.cs | 121 +++++++++++++++++- .../GVFS.UnitTests/Mock/Git/MockGitProcess.cs | 24 +++- 9 files changed, 346 insertions(+), 39 deletions(-) diff --git a/GVFS/GVFS.Common/GVFSConstants.cs b/GVFS/GVFS.Common/GVFSConstants.cs index 3dd946bff5..fd97ed3754 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 37c3563b51..b395b3ad62 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 03cc27b417..e0d7366e74 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 9ab38e13d9..1a578418ea 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 0f9767dde1..a73b386603 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 4462a18bcc..c4e8b5ca27 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 0f8c45b26d..c418ff74e7 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 25aa675b7e..b388f61da6 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 c9095cc2c8..69cad652fc 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) {