diff --git a/GVFS/GVFS.Common/GVFSConstants.cs b/GVFS/GVFS.Common/GVFSConstants.cs index 3dd946bff..e4d670c9e 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; @@ -70,6 +77,12 @@ public static class GitConfig public const string PrefetchOffload = GVFSPrefix + "prefetch-offload"; public const bool PrefetchOffloadDefault = false; + + /* Off-by-default flag (stabilization ship). When enabled, HttpRequestor releases + * its process-wide connection-pool slot before running the credential-reject leg on + * a 401, so a slow credential helper cannot starve healthy parallel requests. */ + public const string ReleaseConnectionBeforeCredentialReject = GVFSPrefix + "release-connection-before-credential-reject"; + public const bool ReleaseConnectionBeforeCredentialRejectDefault = false; } public static class LocalGVFSConfig diff --git a/GVFS/GVFS.Common/Git/GitAuthentication.cs b/GVFS/GVFS.Common/Git/GitAuthentication.cs index 37c3563b5..73464bb2f 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,16 @@ public bool IsBackingOff private GitSsl GitSsl { get; } - public void ApproveCredentials(ITracer tracer, string credentialString) + /// + /// Test-only hook to force the anonymous state. Production code determines this + /// by probing the server in . + /// + internal void SetIsAnonymousForTesting(bool isAnonymous) + { + this.IsAnonymous = isAnonymous; + } + + public void ApproveCredentials(ITracer tracer, string credentialString, int credentialTimeoutMs = DefaultCredentialTimeoutMs, CancellationToken cancellationToken = default) { lock (this.gitAuthLock) { @@ -86,7 +102,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, cancellationToken)) { // Storing credentials is best effort attempt - log failure, but do not fail tracer.RelatedWarning("Failed to store credential string: {0}", error); @@ -107,7 +123,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, CancellationToken cancellationToken = default) { lock (this.gitAuthLock) { @@ -118,7 +134,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, cancellationToken)) { if (this.cachedCredentialString != cachedCredentialAtStartOfReject) { @@ -139,7 +155,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, cancellationToken)) { // Deleting credentials is best effort attempt - log failure, but do not fail tracer.RelatedWarning("Failed to delete credential string: {0}", error); @@ -154,7 +170,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, cancellationToken: cancellationToken); } this.cachedCredentialString = null; @@ -169,8 +185,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, CancellationToken cancellationToken = default) { + return this.TryGetCredentials(tracer, out credentialString, out errorMessage, out _, credentialTimeoutMs, cancellationToken); + } + + /// + /// 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, CancellationToken cancellationToken = default) + { + timedOut = false; + if (!this.isInitialized) { // Initialization may still be running in the background (mount can @@ -199,7 +227,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, cancellationToken)) { return false; } @@ -285,7 +313,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 +355,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 +447,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, CancellationToken cancellationToken = default) { // 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, cancellationToken); + 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, cancellationToken)) { this.UpdateBackoff(); return false; diff --git a/GVFS/GVFS.Common/Git/GitProcess.cs b/GVFS/GVFS.Common/Git/GitProcess.cs index 03cc27b41..bb25d1d0b 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, CancellationToken cancellationToken = default) { StringBuilder sb = new StringBuilder(); sb.AppendFormat("url={0}\n", repoUrl); @@ -214,7 +220,9 @@ public virtual bool TryDeleteCredential(ITracer tracer, string repoUrl, string u GenerateCredentialVerbCommand("reject"), stdin => stdin.Write(stdinConfig), null, - usePreCommandHook: false); + usePreCommandHook: false, + timeoutMs: timeoutMs, + cancellationToken: cancellationToken); if (result.ExitCodeIsFailure) { @@ -228,7 +236,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, CancellationToken cancellationToken = default) { StringBuilder sb = new StringBuilder(); sb.AppendFormat("url={0}\n", repoUrl); @@ -242,7 +250,9 @@ public virtual bool TryStoreCredential(ITracer tracer, string repoUrl, string us GenerateCredentialVerbCommand("approve"), stdin => stdin.Write(stdinConfig), null, - usePreCommandHook: false); + usePreCommandHook: false, + timeoutMs: timeoutMs, + cancellationToken: cancellationToken); if (result.ExitCodeIsFailure) { @@ -320,11 +330,14 @@ public virtual bool TryGetCredential( out string username, out string password, out string errorMessage, - int timeoutMs = -1) + out bool timedOut, + int timeoutMs = -1, + CancellationToken cancellationToken = default) { username = null; password = null; errorMessage = null; + timedOut = false; using (ITracer activity = tracer.StartActivity(nameof(this.TryGetCredential), EventLevel.Informational)) { @@ -335,7 +348,8 @@ public virtual bool TryGetCredential( stdin => stdin.Write($"url={repoUrl}\n\n"), parseStdOutLine: null, usePreCommandHook: false, - timeoutMs: timeoutMs); + timeoutMs: timeoutMs, + cancellationToken: cancellationToken); if (gitCredentialOutput.ExitCodeIsFailure) { @@ -343,10 +357,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 @@ -975,7 +1000,8 @@ protected virtual Result InvokeGitImpl( Action parseStdOutLine, int timeoutMs, string gitObjectsDirectory = null, - bool usePreCommandHook = true) + bool usePreCommandHook = true, + CancellationToken cancellationToken = default) { if (failedToSetEncoding && writeStdIn != null) { @@ -1049,9 +1075,29 @@ protected virtual Result InvokeGitImpl( this.executingProcess.BeginOutputReadLine(); this.executingProcess.BeginErrorReadLine(); - if (!this.executingProcess.WaitForExit(timeoutMs)) + bool cancellationRequested = false; + bool exited = cancellationToken.CanBeCanceled + ? this.WaitForExitWithCancellation(timeoutMs, cancellationToken, out cancellationRequested) + : this.executingProcess.WaitForExit(timeoutMs); + + if (!exited) { - 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); + + if (cancellationRequested) + { + // The caller (e.g. mount shutdown or a cancelled request) asked us + // to stop. Surface cancellation rather than a timeout so callers such + // as RetryWrapper abort promptly instead of retrying the operation. + throw new OperationCanceledException(cancellationToken); + } return new Result(output.ToString(), "Operation timed out: " + errors.ToString(), Result.GenericFailureCode, output.Truncated, errors.Truncated); } @@ -1070,6 +1116,46 @@ protected virtual Result InvokeGitImpl( } } + /// + /// Waits for the currently executing git process to exit, giving up when the + /// timeout elapses or the caller cancels. Polls at a short interval so cancellation + /// (e.g. mount shutdown) is observed promptly even though + /// has no cancellation-aware overload. + /// + /// True if the process exited on its own; false if it must be killed. + private bool WaitForExitWithCancellation(int timeoutMs, CancellationToken cancellationToken, out bool cancellationRequested) + { + const int PollIntervalMs = 100; + cancellationRequested = false; + + Stopwatch stopwatch = Stopwatch.StartNew(); + while (true) + { + int waitMs = PollIntervalMs; + if (timeoutMs >= 0) + { + long remainingMs = timeoutMs - stopwatch.ElapsedMilliseconds; + if (remainingMs <= 0) + { + return false; + } + + waitMs = (int)Math.Min(PollIntervalMs, remainingMs); + } + + if (this.executingProcess.WaitForExit(waitMs)) + { + return true; + } + + if (cancellationToken.IsCancellationRequested) + { + cancellationRequested = true; + return false; + } + } + } + private static string GenerateCredentialVerbCommand(string verb) { return $"-c {GitConfigSetting.CredentialUseHttpPath}=true credential {verb}"; @@ -1155,7 +1241,8 @@ private Result InvokeGitAgainstDotGitFolder( Action parseStdOutLine, bool usePreCommandHook = true, string gitObjectsDirectory = null, - int timeoutMs = -1) + int timeoutMs = -1, + CancellationToken cancellationToken = default) { // This git command should not need/use the working directory of the repo. // Run git.exe in Environment.SystemDirectory to ensure the git.exe process @@ -1169,7 +1256,8 @@ private Result InvokeGitAgainstDotGitFolder( parseStdOutLine: parseStdOutLine, timeoutMs: timeoutMs, gitObjectsDirectory: gitObjectsDirectory, - usePreCommandHook: usePreCommandHook); + usePreCommandHook: usePreCommandHook, + cancellationToken: cancellationToken); } public class Result diff --git a/GVFS/GVFS.Common/Git/ICredentialStore.cs b/GVFS/GVFS.Common/Git/ICredentialStore.cs index 9ab38e13d..4eeed5b97 100644 --- a/GVFS/GVFS.Common/Git/ICredentialStore.cs +++ b/GVFS/GVFS.Common/Git/ICredentialStore.cs @@ -1,13 +1,14 @@ using GVFS.Common.Tracing; +using System.Threading; 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, CancellationToken cancellationToken = default); - 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, CancellationToken cancellationToken = default); - 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, CancellationToken cancellationToken = default); } } diff --git a/GVFS/GVFS.Common/Http/HttpRequestor.cs b/GVFS/GVFS.Common/Http/HttpRequestor.cs index 0f9767dde..1359d836f 100644 --- a/GVFS/GVFS.Common/Http/HttpRequestor.cs +++ b/GVFS/GVFS.Common/Http/HttpRequestor.cs @@ -22,6 +22,7 @@ public abstract class HttpRequestor : IDisposable private static long requestCount = 0; private static SemaphoreSlim availableConnections; private static int connectionLimitConfigured = 0; + private static bool releaseConnectionBeforeCredentialReject = GVFSConstants.GitConfig.ReleaseConnectionBeforeCredentialRejectDefault; private readonly ProductInfoHeaderValue userAgentHeader; @@ -38,6 +39,17 @@ static HttpRequestor() } protected HttpRequestor(ITracer tracer, RetryConfig retryConfig, Enlistment enlistment) + : this(tracer, retryConfig, enlistment, handlerOverride: null) + { + } + + /// + /// Test-only constructor that injects a custom so + /// can be exercised without real network I/O. Production code + /// uses the parameterless-handler overload, which builds a configured + /// . + /// + internal HttpRequestor(ITracer tracer, RetryConfig retryConfig, Enlistment enlistment, HttpMessageHandler handlerOverride) { this.RetryConfig = retryConfig; @@ -50,6 +62,7 @@ protected HttpRequestor(ITracer tracer, RetryConfig retryConfig, Enlistment enli if (Interlocked.CompareExchange(ref connectionLimitConfigured, 1, 0) == 0) { TryApplyConnectionLimitFromConfig(tracer, enlistment); + TryApplyReleaseConnectionBeforeRejectFromConfig(tracer, enlistment); } // WARNING: Do NOT set Credentials or ServerCredentials on this handler. @@ -61,14 +74,23 @@ protected HttpRequestor(ITracer tracer, RetryConfig retryConfig, Enlistment enli // GVFS cache servers and Azure DevOps accept PAT/OAuth tokens via the // "Authorization: Basic " header that SendRequest already attaches. // Transport-level credentials are redundant and purely wasteful. - SocketsHttpHandler handler = new SocketsHttpHandler() + HttpMessageHandler handler; + if (handlerOverride != null) { - MaxConnectionsPerServer = Environment.ProcessorCount, - PooledConnectionLifetime = Timeout.InfiniteTimeSpan, - PooledConnectionIdleTimeout = TimeSpan.FromMinutes(5), - }; + handler = handlerOverride; + } + else + { + SocketsHttpHandler socketsHandler = new SocketsHttpHandler() + { + MaxConnectionsPerServer = Environment.ProcessorCount, + PooledConnectionLifetime = Timeout.InfiniteTimeSpan, + PooledConnectionIdleTimeout = TimeSpan.FromMinutes(5), + }; - this.authentication.ConfigureSocketsHandlerSslIfNeeded(this.Tracer, handler, enlistment.CreateGitProcess()); + this.authentication.ConfigureSocketsHandlerSslIfNeeded(this.Tracer, socketsHandler, enlistment.CreateGitProcess()); + handler = socketsHandler; + } this.client = new HttpClient(handler) { @@ -84,6 +106,31 @@ protected HttpRequestor(ITracer tracer, RetryConfig retryConfig, Enlistment enli protected ITracer Tracer { get; } + /// + /// Number of currently-available connection-pool permits. Test-only observability hook + /// for asserting that releases its slot at the right time. + /// + internal static int AvailableConnectionCount => availableConnections.CurrentCount; + + /// + /// When true, releases the connection-pool slot before running + /// the (potentially slow) credential-reject leg on a 401. Off by default; enabled via + /// . Overridable + /// in tests. + /// + protected virtual bool ShouldReleaseConnectionBeforeCredentialReject => releaseConnectionBeforeCredentialReject; + + // 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 +156,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, cancellationToken)) { 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); } @@ -176,6 +228,11 @@ protected GitEndPointResponseData SendRequest( GitEndPointResponseData gitEndPointResponseData = null; HttpResponseMessage response = null; + // Tracks whether we already released the connection-pool slot inside the try body + // (F06 early-release before the credential-reject leg). The finally block must not + // release a second time, which would corrupt the semaphore's permit count. + bool connectionReleasedEarly = false; + try { requestStopwatch.Restart(); @@ -207,7 +264,7 @@ protected GitEndPointResponseData SendRequest( if (!this.authentication.IsAnonymous) { - this.authentication.ApproveCredentials(this.Tracer, authString); + this.authentication.ApproveCredentials(this.Tracer, authString, this.CredentialTimeoutMs, cancellationToken); } Stream responseStream = response.Content.ReadAsStreamAsync().GetAwaiter().GetResult(); @@ -222,39 +279,54 @@ protected GitEndPointResponseData SendRequest( else { errorMessage = response.Content.ReadAsStringAsync().GetAwaiter().GetResult(); - int statusInt = (int)response.StatusCode; + HttpStatusCode statusCode = response.StatusCode; + int statusInt = (int)statusCode; - bool shouldRetry = ShouldRetry(response.StatusCode); + bool shouldRetry = ShouldRetry(statusCode); - if (response.StatusCode == HttpStatusCode.Unauthorized && + if (statusCode == HttpStatusCode.Unauthorized && this.authentication.IsAnonymous) { shouldRetry = false; errorMessage = "Anonymous request was rejected with a 401"; } - else if (response.StatusCode == HttpStatusCode.Unauthorized || response.StatusCode == HttpStatusCode.BadRequest || response.StatusCode == HttpStatusCode.Redirect) + else if (statusCode == HttpStatusCode.Unauthorized || statusCode == HttpStatusCode.BadRequest || statusCode == HttpStatusCode.Redirect) { - this.authentication.RejectCredentials(this.Tracer, authString); + if (this.ShouldReleaseConnectionBeforeCredentialReject) + { + // F06: the error body is already buffered into errorMessage, and the + // reject leg can block for a long time on a slow or hung credential + // helper. Free the process-wide connection slot before that wait so + // healthy parallel requests are not starved by credential contention. + // The finally block honors connectionReleasedEarly so a reject that + // throws (e.g. on cancellation) does not double-release the permit. + response.Dispose(); + response = null; + availableConnections.Release(); + connectionReleasedEarly = true; + } + + this.authentication.RejectCredentials(this.Tracer, authString, this.CredentialTimeoutMs, cancellationToken); 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); + 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, statusCode, errorMessage); } else { - errorMessage = string.Format("Server returned error code {0} ({1}) after successfully renewing your PAT. You may not have access to this repo. Original error message from server: {2}", statusInt, response.StatusCode, errorMessage); + errorMessage = string.Format("Server returned error code {0} ({1}) after successfully renewing your PAT. You may not have access to this repo. Original error message from server: {2}", statusInt, statusCode, errorMessage); } } else { - errorMessage = string.Format("Server returned error code {0} ({1}). Original error message from server: {2}", statusInt, response.StatusCode, errorMessage); + errorMessage = string.Format("Server returned error code {0} ({1}). Original error message from server: {2}", statusInt, statusCode, errorMessage); } gitEndPointResponseData = new GitEndPointResponseData( - response.StatusCode, - new GitObjectsHttpException(response.StatusCode, errorMessage), + statusCode, + new GitObjectsHttpException(statusCode, errorMessage), shouldRetry, - message: response, - onResponseDisposed: () => availableConnections.Release()); + message: connectionReleasedEarly ? null : response, + onResponseDisposed: connectionReleasedEarly ? (Action)null : () => availableConnections.Release()); } } catch (TaskCanceledException) @@ -304,7 +376,12 @@ protected GitEndPointResponseData SendRequest( response.Dispose(); } - availableConnections.Release(); + // Don't release a second time if the connection slot was already freed + // early (F06) before a reject leg that then threw (e.g. on cancellation). + if (!connectionReleasedEarly) + { + availableConnections.Release(); + } } } @@ -430,5 +507,44 @@ private static void TryApplyConnectionLimitFromConfig(ITracer tracer, Enlistment tracer.RelatedWarning(metadata, "HttpRequestor: Failed to read gvfs.max-http-connections config, using default"); } } + + private static void TryApplyReleaseConnectionBeforeRejectFromConfig(ITracer tracer, Enlistment enlistment) + { + try + { + GitProcess.ConfigResult result = enlistment.CreateGitProcess().GetFromConfig(GVFSConstants.GitConfig.ReleaseConnectionBeforeCredentialReject); + if (!result.TryParseAsString(out string value, out string error)) + { + EventMetadata metadata = new EventMetadata(); + metadata.Add("error", error); + tracer.RelatedWarning(metadata, "HttpRequestor: Failed to read gvfs.release-connection-before-credential-reject config, using default"); + return; + } + + if (!string.IsNullOrWhiteSpace(value) && IsGitConfigTrue(value)) + { + releaseConnectionBeforeCredentialReject = true; + + EventMetadata metadata = new EventMetadata(); + metadata.Add("value", value); + tracer.RelatedEvent(EventLevel.Informational, "HttpRequestor_ReleaseConnectionBeforeCredentialRejectEnabled", metadata); + } + } + catch (Exception e) + { + EventMetadata metadata = new EventMetadata(); + metadata.Add("Exception", e.ToString()); + tracer.RelatedWarning(metadata, "HttpRequestor: Failed to read gvfs.release-connection-before-credential-reject config, using default"); + } + } + + private static bool IsGitConfigTrue(string value) + { + // Mirror git's boolean truthiness for config values. + return value.Equals("true", StringComparison.OrdinalIgnoreCase) + || value.Equals("1", StringComparison.Ordinal) + || value.Equals("yes", StringComparison.OrdinalIgnoreCase) + || value.Equals("on", StringComparison.OrdinalIgnoreCase); + } } } 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..894296cf8 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,243 @@ 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(); + } + + [TestCase] + public void RejectCredentialsPlumbsCancellationTokenToGitProcess() + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = this.GetGitProcess(); + + GitAuthentication dut = new GitAuthentication(gitProcess, "mock://repoUrl"); + dut.TryInitializeAndRequireAuth(tracer, out _); + + string authString; + dut.TryGetCredentials(tracer, out authString, out _).ShouldBeTrue(); + + using (CancellationTokenSource cts = new CancellationTokenSource()) + { + // The reject leg reloads and then erases the credential; both spawn a git process. + // Assert the caller's token reached the git invocation. Without the plumbing the + // recorded token would be the default (non-cancelable) CancellationToken. + dut.RejectCredentials(tracer, authString, GitAuthentication.DefaultCredentialTimeoutMs, cts.Token); + + gitProcess.LastInvokedCancellationToken.CanBeCanceled.ShouldEqual(true, "Expected the caller's cancellation token to reach the git invocation"); + gitProcess.LastInvokedCancellationToken.ShouldEqual(cts.Token, "Expected the exact caller token to reach the git invocation"); + } + } + + [TestCase] + public void TryGetCredentialsCancellationInterruptsBlockedFetch() + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = this.GetGitProcess(); + + GitAuthentication dut = new GitAuthentication(gitProcess, "mock://repoUrl"); + dut.TryInitializeAndRequireAuth(tracer, out _); + + string authString; + dut.TryGetCredentials(tracer, out authString, out _).ShouldBeTrue(); + + // Clear the cache so the next TryGetCredentials must re-fetch through git. + dut.RejectCredentials(tracer, authString); + + using (ManualResetEventSlim reached = new ManualResetEventSlim(false)) + using (ManualResetEventSlim block = new ManualResetEventSlim(false)) + using (CancellationTokenSource cts = new CancellationTokenSource()) + { + gitProcess.InvokeReachedBlock = reached; + gitProcess.BlockInvokeUntilSignaled = block; + + Exception caught = null; + Thread worker = new Thread(() => + { + try + { + dut.TryGetCredentials(tracer, out _, out _, GitAuthentication.BackgroundCredentialTimeoutMs, cts.Token); + } + catch (Exception e) + { + caught = e; + } + }); + worker.IsBackground = true; + worker.Start(); + + reached.Wait(TimeSpan.FromSeconds(5)).ShouldEqual(true, "The git credential invocation should have started"); + + // Cancellation must interrupt the in-flight fetch instead of waiting the full + // 120s bound. Without the token reaching InvokeGitImpl the worker blocks forever + // and this Join times out. + cts.Cancel(); + worker.Join(TimeSpan.FromSeconds(5)).ShouldEqual(true, "Cancellation should have unblocked the credential fetch promptly"); + + caught.ShouldNotBeNull("Expected the canceled fetch to throw"); + (caught is OperationCanceledException).ShouldEqual(true, "Expected an OperationCanceledException, got: " + caught); + } + } + + [TestCase] + public void RejectCredentialsCancellationInterruptsBlockedReload() + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = this.GetGitProcess(); + + GitAuthentication dut = new GitAuthentication(gitProcess, "mock://repoUrl"); + dut.TryInitializeAndRequireAuth(tracer, out _); + + string authString; + dut.TryGetCredentials(tracer, out authString, out _).ShouldBeTrue(); + + using (ManualResetEventSlim reached = new ManualResetEventSlim(false)) + using (ManualResetEventSlim block = new ManualResetEventSlim(false)) + using (CancellationTokenSource cts = new CancellationTokenSource()) + { + gitProcess.InvokeReachedBlock = reached; + gitProcess.BlockInvokeUntilSignaled = block; + + Exception caught = null; + Thread worker = new Thread(() => + { + try + { + dut.RejectCredentials(tracer, authString, GitAuthentication.BackgroundCredentialTimeoutMs, cts.Token); + } + catch (Exception e) + { + caught = e; + } + }); + worker.IsBackground = true; + worker.Start(); + + reached.Wait(TimeSpan.FromSeconds(5)).ShouldEqual(true, "The reject leg should have started a git invocation"); + + cts.Cancel(); + worker.Join(TimeSpan.FromSeconds(5)).ShouldEqual(true, "Cancellation should have unblocked the reject leg promptly"); + + caught.ShouldNotBeNull("Expected the canceled reject to throw"); + (caught is OperationCanceledException).ShouldEqual(true, "Expected an OperationCanceledException, got: " + caught); + } + } + private MockGitProcess GetGitProcess() { MockGitProcess gitProcess = new MockGitProcess(); diff --git a/GVFS/GVFS.UnitTests/Http/HttpRequestorTests.cs b/GVFS/GVFS.UnitTests/Http/HttpRequestorTests.cs new file mode 100644 index 000000000..f638ccfae --- /dev/null +++ b/GVFS/GVFS.UnitTests/Http/HttpRequestorTests.cs @@ -0,0 +1,223 @@ +using System; +using System.Net; +using System.Net.Http; +using System.Threading; +using System.Threading.Tasks; +using GVFS.Common; +using GVFS.Common.Git; +using GVFS.Common.Http; +using GVFS.Common.Tracing; +using GVFS.Tests.Should; +using GVFS.UnitTests.Mock.Common; +using GVFS.UnitTests.Mock.Git; +using NUnit.Framework; + +namespace GVFS.UnitTests.Http +{ + [TestFixture] + public class HttpRequestorTests + { + private const string RepoUrl = "mock://repoUrl"; + private const string AzureDevOpsUseHttpPathString = "-c credential.\"https://dev.azure.com\".useHttpPath=true"; + + [TestCase] + public void SendRequestReleasesConnectionBeforeCredentialRejectWhenEnabled() + { + this.RunConnectionReleaseTest(releaseEarly: true, expectReleasedDuringReject: true); + } + + [TestCase] + public void SendRequestHoldsConnectionDuringCredentialRejectWhenDisabled() + { + this.RunConnectionReleaseTest(releaseEarly: false, expectReleasedDuringReject: false); + } + + [TestCase] + public void SendRequestDoesNotDoubleReleaseConnectionWhenRejectCanceled() + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = CreateGitProcess(); + GitAuthentication authentication = CreateInitializedAuthentication(tracer, gitProcess); + MockGVFSEnlistment enlistment = new MockGVFSEnlistment(gitProcess, authentication); + + using (ManualResetEventSlim reached = new ManualResetEventSlim(false)) + using (ManualResetEventSlim block = new ManualResetEventSlim(false)) + using (CancellationTokenSource cts = new CancellationTokenSource()) + using (StubHttpMessageHandler handler = new StubHttpMessageHandler(HttpStatusCode.Unauthorized, "unauthorized")) + using (TestingHttpRequestor requestor = new TestingHttpRequestor(tracer, new RetryConfig(), enlistment, handler, releaseEarly: true)) + { + int before = HttpRequestor.AvailableConnectionCount; + gitProcess.InvokeReachedBlock = reached; + gitProcess.BlockInvokeUntilSignaled = block; + + Exception caught = null; + Thread worker = new Thread(() => + { + try + { + using (requestor.Send(cts.Token)) + { + } + } + catch (Exception e) + { + caught = e; + } + }); + worker.IsBackground = true; + worker.Start(); + + reached.Wait(TimeSpan.FromSeconds(5)).ShouldEqual(true, "The reject leg should have started a git invocation"); + HttpRequestor.AvailableConnectionCount.ShouldEqual(before, "The connection slot should have been released before the reject leg ran"); + + cts.Cancel(); + worker.Join(TimeSpan.FromSeconds(5)).ShouldEqual(true, "Cancellation should have unblocked the reject leg promptly"); + + caught.ShouldNotBeNull("Expected the canceled request to throw"); + (caught is OperationCanceledException).ShouldEqual(true, "Expected an OperationCanceledException, got: " + caught); + + // The key invariant: the early release plus the canceled reject must not + // double-release the process-wide connection permit. + HttpRequestor.AvailableConnectionCount.ShouldEqual(before, "The connection slot must be released exactly once, not double-released"); + } + } + + private static MockGitProcess CreateGitProcess() + { + MockGitProcess gitProcess = new MockGitProcess(); + gitProcess.SetExpectedCommandResult("config gvfs.FunctionalTests.UserName", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.GenericFailureCode)); + gitProcess.SetExpectedCommandResult("config gvfs.FunctionalTests.Password", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.GenericFailureCode)); + gitProcess.SetExpectedCommandResult("config --get-urlmatch http mock://repoUrl", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + + // HttpRequestor reads these once (on the first instance constructed in the process) + // during its connection-limit / flag initialization. Register them so the read does + // not fault the mock, regardless of test ordering. + gitProcess.SetExpectedCommandResult("config gvfs.max-http-connections", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + gitProcess.SetExpectedCommandResult("config gvfs.release-connection-before-credential-reject", () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + + int rejections = 0; + gitProcess.SetExpectedCommandResult( + $"{AzureDevOpsUseHttpPathString} credential fill", + () => new GitProcess.Result("username=username\r\npassword=password" + rejections + "\r\n", string.Empty, GitProcess.Result.SuccessCode)); + + gitProcess.SetExpectedCommandResult( + $"{AzureDevOpsUseHttpPathString} credential approve", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + + gitProcess.SetExpectedCommandResult( + $"{AzureDevOpsUseHttpPathString} credential reject", + () => + { + rejections++; + return new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode); + }); + + return gitProcess; + } + + private static GitAuthentication CreateInitializedAuthentication(MockTracer tracer, MockGitProcess gitProcess) + { + GitAuthentication authentication = new GitAuthentication(gitProcess, RepoUrl); + authentication.TryInitializeAndRequireAuth(tracer, out _); + + // Populate the credential cache so SendRequest attaches auth and reaches the reject leg. + authentication.TryGetCredentials(tracer, out _, out _).ShouldBeTrue(); + + // Force the non-anonymous path; production determines this by probing the server. + authentication.SetIsAnonymousForTesting(false); + + return authentication; + } + + private void RunConnectionReleaseTest(bool releaseEarly, bool expectReleasedDuringReject) + { + MockTracer tracer = new MockTracer(); + MockGitProcess gitProcess = CreateGitProcess(); + GitAuthentication authentication = CreateInitializedAuthentication(tracer, gitProcess); + MockGVFSEnlistment enlistment = new MockGVFSEnlistment(gitProcess, authentication); + + using (ManualResetEventSlim reached = new ManualResetEventSlim(false)) + using (ManualResetEventSlim block = new ManualResetEventSlim(false)) + using (StubHttpMessageHandler handler = new StubHttpMessageHandler(HttpStatusCode.Unauthorized, "unauthorized")) + using (TestingHttpRequestor requestor = new TestingHttpRequestor(tracer, new RetryConfig(), enlistment, handler, releaseEarly)) + { + int before = HttpRequestor.AvailableConnectionCount; + gitProcess.InvokeReachedBlock = reached; + gitProcess.BlockInvokeUntilSignaled = block; + + GitEndPointResponseData response = null; + Thread worker = new Thread(() => response = requestor.Send(CancellationToken.None)); + worker.IsBackground = true; + worker.Start(); + + reached.Wait(TimeSpan.FromSeconds(5)).ShouldEqual(true, "The reject leg should have started a git invocation"); + + int duringReject = HttpRequestor.AvailableConnectionCount; + if (expectReleasedDuringReject) + { + duringReject.ShouldEqual(before, "The connection slot should be released before the reject leg runs"); + } + else + { + duringReject.ShouldEqual(before - 1, "The connection slot should still be held during the reject leg"); + } + + block.Set(); + worker.Join(TimeSpan.FromSeconds(5)).ShouldEqual(true, "The request should complete after the reject leg unblocks"); + + response.ShouldNotBeNull("Expected a response"); + response.HasErrors.ShouldEqual(true, "Expected a 401 error response"); + response.Dispose(); + + HttpRequestor.AvailableConnectionCount.ShouldEqual(before, "The connection slot should be fully released after completion"); + } + } + + private sealed class TestingHttpRequestor : HttpRequestor + { + private readonly bool releaseEarly; + + public TestingHttpRequestor(ITracer tracer, RetryConfig retryConfig, Enlistment enlistment, HttpMessageHandler handler, bool releaseEarly) + : base(tracer, retryConfig, enlistment, handler) + { + this.releaseEarly = releaseEarly; + } + + protected override int CredentialTimeoutMs => GitAuthentication.BackgroundCredentialTimeoutMs; + + protected override bool ShouldReleaseConnectionBeforeCredentialReject => this.releaseEarly; + + public GitEndPointResponseData Send(CancellationToken cancellationToken) + { + return this.SendRequest( + GetNewRequestId(), + new Uri("https://mock.gvfs/gvfs/objects"), + HttpMethod.Get, + requestContent: null, + cancellationToken: cancellationToken); + } + } + + private sealed class StubHttpMessageHandler : HttpMessageHandler + { + private readonly HttpStatusCode statusCode; + private readonly string body; + + public StubHttpMessageHandler(HttpStatusCode statusCode, string body) + { + this.statusCode = statusCode; + this.body = body; + } + + protected override Task SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) + { + HttpResponseMessage response = new HttpResponseMessage(this.statusCode) + { + Content = new StringContent(this.body), + }; + + return Task.FromResult(response); + } + } + } +} diff --git a/GVFS/GVFS.UnitTests/Mock/Common/MockGVFSEnlistment.cs b/GVFS/GVFS.UnitTests/Mock/Common/MockGVFSEnlistment.cs index 2292149b6..77b59deb3 100644 --- a/GVFS/GVFS.UnitTests/Mock/Common/MockGVFSEnlistment.cs +++ b/GVFS/GVFS.UnitTests/Mock/Common/MockGVFSEnlistment.cs @@ -29,6 +29,15 @@ public MockGVFSEnlistment(MockGitProcess gitProcess) this.gitProcess = gitProcess; } + public MockGVFSEnlistment(MockGitProcess gitProcess, GitAuthentication authentication) + : base(Path.Combine("mock:", "path"), "mock://repoUrl", Path.Combine("mock:", "git"), authentication) + { + this.gitProcess = gitProcess; + this.GitObjectsRoot = Path.Combine("mock:", "path", ".git", "objects"); + this.LocalObjectsRoot = this.GitObjectsRoot; + this.GitPackRoot = Path.Combine("mock:", "path", ".git", "objects", "pack"); + } + public override string GitObjectsRoot { get; protected set; } public override string LocalObjectsRoot { get; protected set; } diff --git a/GVFS/GVFS.UnitTests/Mock/Git/MockGitProcess.cs b/GVFS/GVFS.UnitTests/Mock/Git/MockGitProcess.cs index c9095cc2c..c0d2cb055 100644 --- a/GVFS/GVFS.UnitTests/Mock/Git/MockGitProcess.cs +++ b/GVFS/GVFS.UnitTests/Mock/Git/MockGitProcess.cs @@ -7,6 +7,7 @@ using System.IO; using System.Linq; using System.Text; +using System.Threading; namespace GVFS.UnitTests.Mock.Git { @@ -18,12 +19,47 @@ public MockGitProcess() : base(new MockGVFSEnlistment()) { this.CommandsRun = new List(); + this.InvokedTimeoutMs = new List(); + this.LastInvokedTimeoutMs = null; + this.LastInvokedCancellationToken = CancellationToken.None; 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; } + + /// + /// The cancellation token passed to the most recent InvokeGitImpl call. Lets tests assert + /// that a caller plumbed a real (cancelable) token down to the git invocation. + /// + public CancellationToken LastInvokedCancellationToken { get; private set; } + + /// + /// When set, InvokeGitImpl blocks until this event is signaled or the caller's token is + /// canceled. Lets tests simulate a slow/hung git credential process and prove that + /// cancellation interrupts it and that shared resources are not held meanwhile. + /// + public ManualResetEventSlim BlockInvokeUntilSignaled { get; set; } + + /// + /// Signaled by InvokeGitImpl right before it starts blocking on + /// . Lets a test wait until the git invocation is + /// actually in-flight before it inspects shared state or cancels. + /// + public ManualResetEventSlim InvokeReachedBlock { get; set; } + public bool ShouldFail { get; set; } public Dictionary StoredCredentials { get; } public Dictionary> CredentialApprovals { get; } @@ -35,7 +71,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, CancellationToken cancellationToken = default) { Credential credential = new Credential(username, password); @@ -52,10 +88,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, cancellationToken); } - 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, CancellationToken cancellationToken = default) { Credential credential = new Credential(username, password); @@ -72,7 +108,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, cancellationToken); } protected override Result InvokeGitImpl( @@ -84,9 +120,32 @@ protected override Result InvokeGitImpl( Action parseStdOutLine, int timeoutMs, string gitObjectsDirectory = null, - bool usePrecommandHook = true) + bool usePrecommandHook = true, + CancellationToken cancellationToken = default) { this.CommandsRun.Add(command); + this.LastInvokedTimeoutMs = timeoutMs; + this.InvokedTimeoutMs.Add(timeoutMs); + this.LastInvokedCancellationToken = cancellationToken; + + // Simulate a slow/hung git process that only completes when the test signals it or the + // caller cancels. This lets tests assert that cancellation actually interrupts an + // in-flight credential invocation instead of blocking for the full timeout. + ManualResetEventSlim blockUntilSignaled = this.BlockInvokeUntilSignaled; + if (blockUntilSignaled != null) + { + this.InvokeReachedBlock?.Set(); + try + { + blockUntilSignaled.Wait(cancellationToken); + } + catch (OperationCanceledException) + { + // Mirror the real GitProcess.InvokeGitImpl contract: a canceled invocation + // surfaces cancellation rather than returning a timeout Result. + throw new OperationCanceledException(cancellationToken); + } + } if (this.ShouldFail) {