diff --git a/GVFS/GVFS.Common/Git/GVFSGitObjects.cs b/GVFS/GVFS.Common/Git/GVFSGitObjects.cs index b232e7b74..f8a314b2e 100644 --- a/GVFS/GVFS.Common/Git/GVFSGitObjects.cs +++ b/GVFS/GVFS.Common/Git/GVFSGitObjects.cs @@ -1,4 +1,4 @@ -using GVFS.Common.Http; +using GVFS.Common.Http; using GVFS.Common.Tracing; using System; using System.Collections.Concurrent; @@ -15,14 +15,14 @@ public class GVFSGitObjects : GitObjects private static readonly TimeSpan NegativeCacheTTL = TimeSpan.FromSeconds(30); private ConcurrentDictionary objectNegativeCache; - internal ConcurrentDictionary> inflightDownloads; + internal ConcurrentDictionary> inflightDownloads; public GVFSGitObjects(GVFSContext context, GitObjectsHttpRequestor objectRequestor) : base(context.Tracer, context.Enlistment, objectRequestor, context.FileSystem) { this.Context = context; this.objectNegativeCache = new ConcurrentDictionary(StringComparer.OrdinalIgnoreCase); - this.inflightDownloads = new ConcurrentDictionary>(StringComparer.OrdinalIgnoreCase); + this.inflightDownloads = new ConcurrentDictionary>(StringComparer.OrdinalIgnoreCase); } public enum RequestSource @@ -58,6 +58,28 @@ public enum BlobHydrationFailureCategory Unexpected, // Unclassified exception. } + /// + /// Carries the outcome of an object download together with the HTTP status of the last + /// download attempt. The public enum only records + /// success/not-found/error, which collapses genuine auth failures (401/400/302) and + /// transient failures (408/5xx/pool-exhaustion 503) into a single "error" outcome. The + /// status is retained here so the terminal blob-hydration telemetry can tell them apart. + /// + internal class DownloadAttemptResult + { + public DownloadAttemptResult(DownloadAndSaveObjectResult result, HttpStatusCode? httpStatusCode) + { + this.Result = result; + this.HttpStatusCode = httpStatusCode; + } + + public DownloadAndSaveObjectResult Result { get; } + + // The HTTP status of the last download attempt, or null when no HTTP response was + // received (for example an exhausted retry that ended in an exception). + public HttpStatusCode? HttpStatusCode { get; } + } + protected GVFSContext Context { get; private set; } public virtual bool TryCopyBlobContentStream( @@ -72,7 +94,7 @@ public virtual bool TryCopyBlobContentStream( // local copy) that is otherwise collapsed into the bool return value below. The // final category is also surfaced via the out parameter so the caller can tag its // own terminal telemetry with the same cause. - DownloadAndSaveObjectResult lastDownloadResult = DownloadAndSaveObjectResult.Error; + DownloadAttemptResult lastDownloadResult = null; bool downloadSucceededButCopyFailed = false; BlobHydrationFailureCategory capturedCategory = BlobHydrationFailureCategory.None; @@ -109,7 +131,7 @@ public virtual bool TryCopyBlobContentStream( { category = BlobHydrationFailureCategory.LocalCopyFailed; } - else if (lastDownloadResult == DownloadAndSaveObjectResult.ObjectNotOnServer) + else if (lastDownloadResult?.Result == DownloadAndSaveObjectResult.ObjectNotOnServer) { category = BlobHydrationFailureCategory.ObjectNotOnServer; } @@ -124,6 +146,22 @@ public virtual bool TryCopyBlobContentStream( capturedCategory = category; metadata.Add(nameof(BlobHydrationFailureCategory), category.ToString()); + // Surface the HTTP status of the last download attempt so telemetry can tell a + // genuine auth failure (401/400/302) apart from a transient one (408/5xx/503), + // both of which otherwise land in the DownloadFailed bucket. Only attach it when + // the failure is attributable to the download itself (DownloadFailed or + // ObjectNotOnServer). On the exception (LocalIO/NetworkUnavailable) and + // LocalCopyFailed paths lastDownloadResult can hold a status captured on an + // earlier attempt, so the status would be stale and misattribute the failure. + bool statusIsAttributable = + category == BlobHydrationFailureCategory.DownloadFailed || + category == BlobHydrationFailureCategory.ObjectNotOnServer; + if (statusIsAttributable && lastDownloadResult?.HttpStatusCode != null) + { + metadata.Add("HttpStatusCode", (int)lastDownloadResult.HttpStatusCode.Value); + metadata.Add("HttpStatusName", lastDownloadResult.HttpStatusCode.Value.ToString()); + } + string message = "TryCopyBlobContentStream: Failed to provide blob contents"; if (errorArgs.WillRetry) { @@ -149,7 +187,7 @@ public virtual bool TryCopyBlobContentStream( // Pass in false for retryOnFailure because the retrier in this method manages multiple attempts lastDownloadResult = this.TryDownloadAndSaveObject(sha, cancellationToken, requestSource, retryOnFailure: false); - if (lastDownloadResult == DownloadAndSaveObjectResult.Success) + if (lastDownloadResult.Result == DownloadAndSaveObjectResult.Success) { if (this.Context.Repository.TryCopyBlobContentStream(sha, writeAction)) { @@ -169,7 +207,7 @@ public virtual bool TryCopyBlobContentStream( public DownloadAndSaveObjectResult TryDownloadAndSaveObject(string objectId, RequestSource requestSource) { - return this.TryDownloadAndSaveObject(objectId, CancellationToken.None, requestSource, retryOnFailure: true); + return this.TryDownloadAndSaveObject(objectId, CancellationToken.None, requestSource, retryOnFailure: true).Result; } public bool TryGetBlobSizeLocally(string sha, out long length) @@ -182,7 +220,7 @@ public bool TryGetBlobSizeLocally(string sha, out long length) return this.GitObjectRequestor.QueryForFileSizes(objectIds, cancellationToken); } - private DownloadAndSaveObjectResult TryDownloadAndSaveObject( + private DownloadAttemptResult TryDownloadAndSaveObject( string objectId, CancellationToken cancellationToken, RequestSource requestSource, @@ -190,7 +228,7 @@ private DownloadAndSaveObjectResult TryDownloadAndSaveObject( { if (objectId == GVFSConstants.AllZeroSha) { - return DownloadAndSaveObjectResult.Error; + return new DownloadAttemptResult(DownloadAndSaveObjectResult.Error, httpStatusCode: null); } DateTime negativeCacheRequestTime; @@ -198,7 +236,7 @@ private DownloadAndSaveObjectResult TryDownloadAndSaveObject( { if (negativeCacheRequestTime > DateTime.Now.Subtract(NegativeCacheTTL)) { - return DownloadAndSaveObjectResult.ObjectNotOnServer; + return new DownloadAttemptResult(DownloadAndSaveObjectResult.ObjectNotOnServer, httpStatusCode: null); } this.objectNegativeCache.TryRemove(objectId, out negativeCacheRequestTime); @@ -210,9 +248,9 @@ private DownloadAndSaveObjectResult TryDownloadAndSaveObject( // captured by the Lazy factory. Subsequent coalesced callers inherit those // settings. In practice this is fine because the primary concurrent path // (NamedPipeMessage from git.exe) always uses CancellationToken.None. - Lazy newLazy = new Lazy( + Lazy newLazy = new Lazy( () => this.DoDownloadAndSaveObject(objectId, cancellationToken, requestSource, retryOnFailure)); - Lazy lazy = this.inflightDownloads.GetOrAdd(objectId, newLazy); + Lazy lazy = this.inflightDownloads.GetOrAdd(objectId, newLazy); if (!ReferenceEquals(lazy, newLazy)) { @@ -240,13 +278,13 @@ private DownloadAndSaveObjectResult TryDownloadAndSaveObject( /// .NET Framework 4.7.1. When we upgrade to .NET 10 (backlog), this can be /// replaced with ConcurrentDictionary.TryRemove(KeyValuePair). /// - private bool TryRemoveInflightDownload(string objectId, Lazy lazy) + private bool TryRemoveInflightDownload(string objectId, Lazy lazy) { - return ((ICollection>>)this.inflightDownloads) - .Remove(new KeyValuePair>(objectId, lazy)); + return ((ICollection>>)this.inflightDownloads) + .Remove(new KeyValuePair>(objectId, lazy)); } - private DownloadAndSaveObjectResult DoDownloadAndSaveObject( + private DownloadAttemptResult DoDownloadAndSaveObject( string objectId, CancellationToken cancellationToken, RequestSource requestSource, @@ -273,21 +311,32 @@ private DownloadAndSaveObjectResult DoDownloadAndSaveObject( return new RetryWrapper.CallbackResult(new GitObjectsHttpRequestor.GitObjectTaskResult(true)); }); + // Capture the HTTP status of the last download attempt when a response was received. + // On failure the requestor propagates the real status (e.g. 401/404/503); on an + // exhausted retry that ended in an exception output.Result is null and no status is + // known. A default (zero) status means the result carried no HTTP response, so it is + // treated as "no status". + HttpStatusCode? httpStatusCode = null; + if (output.Result != null && output.Result.HttpStatusCodeResult != 0) + { + httpStatusCode = output.Result.HttpStatusCodeResult; + } + if (output.Result != null) { if (output.Succeeded && output.Result.Success) { - return DownloadAndSaveObjectResult.Success; + return new DownloadAttemptResult(DownloadAndSaveObjectResult.Success, httpStatusCode); } if (output.Result.HttpStatusCodeResult == HttpStatusCode.NotFound) { this.objectNegativeCache.AddOrUpdate(objectId, DateTime.Now, (unused1, unused2) => DateTime.Now); - return DownloadAndSaveObjectResult.ObjectNotOnServer; + return new DownloadAttemptResult(DownloadAndSaveObjectResult.ObjectNotOnServer, httpStatusCode); } } - return DownloadAndSaveObjectResult.Error; + return new DownloadAttemptResult(DownloadAndSaveObjectResult.Error, httpStatusCode); } } } \ No newline at end of file diff --git a/GVFS/GVFS.UnitTests/Git/GVFSGitObjectsTests.cs b/GVFS/GVFS.UnitTests/Git/GVFSGitObjectsTests.cs index 205d2b4de..561536112 100644 --- a/GVFS/GVFS.UnitTests/Git/GVFSGitObjectsTests.cs +++ b/GVFS/GVFS.UnitTests/Git/GVFSGitObjectsTests.cs @@ -1,4 +1,4 @@ -using GVFS.Common; +using GVFS.Common; using GVFS.Common.Git; using GVFS.Common.Http; using GVFS.Common.Tracing; @@ -157,6 +157,124 @@ public void TerminalBlobHydrationFailureTagsObjectNotOnServer() terminalError.ShouldContain("\"BlobHydrationFailureCategory\":\"ObjectNotOnServer\""); } + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void TerminalBlobHydrationFailureRecordsHttpStatusCode() + { + MockFileSystemWithCallbacks fileSystem = new MockFileSystemWithCallbacks(); + fileSystem.OnFileExists = (path) => true; + fileSystem.OnOpenFileStream = (path, mode, access) => + { + if (access == FileAccess.Write) + { + return new MemoryStream(); + } + + throw new FileNotFoundException(); + }; + + MockHttpGitObjects httpObjects = new MockHttpGitObjects(); + + // Force the download to fail with 401. The DownloadFailed bucket collapses auth and + // transient failures, so the terminal event must also carry the HTTP status to tell + // a real 401 apart from a transient failure. + httpObjects.StatusCodeToReturn = HttpStatusCode.Unauthorized; + GVFSGitObjects dut = this.CreateTestableGVFSGitObjects(httpObjects, fileSystem, out MockTracer tracer); + + bool copied = dut.TryCopyBlobContentStream( + ValidTestObjectFileSha1, + new CancellationToken(), + GVFSGitObjects.RequestSource.FileStreamCallback, + (stream, length) => Assert.Fail("Should not be able to call copy stream callback"), + out GVFSGitObjects.BlobHydrationFailureCategory failureCategory); + copied.ShouldEqual(false); + + // A 401 is not classified as ObjectNotOnServer, so it lands in the neutral + // DownloadFailed bucket; the HTTP status is what distinguishes it. + failureCategory.ShouldEqual(GVFSGitObjects.BlobHydrationFailureCategory.DownloadFailed); + string terminalError = tracer.RelatedErrorEvents.First(e => e.Contains("Failed to provide blob contents")); + terminalError.ShouldContain("\"BlobHydrationFailureCategory\":\"DownloadFailed\""); + terminalError.ShouldContain("\"HttpStatusCode\":401"); + terminalError.ShouldContain("\"HttpStatusName\":\"Unauthorized\""); + } + + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void TerminalBlobHydrationFailureRecordsTransientHttpStatusCode() + { + MockFileSystemWithCallbacks fileSystem = new MockFileSystemWithCallbacks(); + fileSystem.OnFileExists = (path) => true; + fileSystem.OnOpenFileStream = (path, mode, access) => + { + if (access == FileAccess.Write) + { + return new MemoryStream(); + } + + throw new FileNotFoundException(); + }; + + MockHttpGitObjects httpObjects = new MockHttpGitObjects(); + + // A transient 503 must also carry the HTTP status so it can be told apart from a real + // auth failure - both share the DownloadFailed category. + httpObjects.StatusCodeToReturn = HttpStatusCode.ServiceUnavailable; + GVFSGitObjects dut = this.CreateTestableGVFSGitObjects(httpObjects, fileSystem, out MockTracer tracer); + + bool copied = dut.TryCopyBlobContentStream( + ValidTestObjectFileSha1, + new CancellationToken(), + GVFSGitObjects.RequestSource.FileStreamCallback, + (stream, length) => Assert.Fail("Should not be able to call copy stream callback"), + out GVFSGitObjects.BlobHydrationFailureCategory failureCategory); + copied.ShouldEqual(false); + + failureCategory.ShouldEqual(GVFSGitObjects.BlobHydrationFailureCategory.DownloadFailed); + string terminalError = tracer.RelatedErrorEvents.First(e => e.Contains("Failed to provide blob contents")); + terminalError.ShouldContain("\"BlobHydrationFailureCategory\":\"DownloadFailed\""); + terminalError.ShouldContain("\"HttpStatusCode\":503"); + terminalError.ShouldContain("\"HttpStatusName\":\"ServiceUnavailable\""); + } + + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void TerminalBlobHydrationFailureOmitsHttpStatusWhenDownloadHasNoStatus() + { + MockFileSystemWithCallbacks fileSystem = new MockFileSystemWithCallbacks(); + fileSystem.OnFileExists = (path) => true; + fileSystem.OnOpenFileStream = (path, mode, access) => + { + if (access == FileAccess.Write) + { + return new MemoryStream(); + } + + throw new FileNotFoundException(); + }; + + MockHttpGitObjects httpObjects = new MockHttpGitObjects(); + + // The download fails without an HTTP response (no status). The terminal event must NOT + // carry a status - in particular it must never emit "HttpStatusCode":0 for a status that + // was never received. + httpObjects.FailWithoutStatus = true; + GVFSGitObjects dut = this.CreateTestableGVFSGitObjects(httpObjects, fileSystem, out MockTracer tracer); + + bool copied = dut.TryCopyBlobContentStream( + ValidTestObjectFileSha1, + new CancellationToken(), + GVFSGitObjects.RequestSource.FileStreamCallback, + (stream, length) => Assert.Fail("Should not be able to call copy stream callback"), + out GVFSGitObjects.BlobHydrationFailureCategory failureCategory); + copied.ShouldEqual(false); + + failureCategory.ShouldEqual(GVFSGitObjects.BlobHydrationFailureCategory.DownloadFailed); + string terminalError = tracer.RelatedErrorEvents.First(e => e.Contains("Failed to provide blob contents")); + terminalError.ShouldContain("\"BlobHydrationFailureCategory\":\"DownloadFailed\""); + terminalError.ShouldNotContain(false, "HttpStatusCode"); + terminalError.ShouldNotContain(false, "HttpStatusName"); + } + [TestCase] [Category(CategoryConstants.ExceptionExpected)] public void TerminalBlobHydrationFailureTagsLocalCopyFailed() @@ -707,15 +825,15 @@ public void StragglingFinallyDoesNotRemoveNewInflightDownload() wave2Started.Wait(TimeSpan.FromSeconds(5)).ShouldBeTrue("Wave 2 download should have started"); // Capture wave 2's Lazy from the dictionary - Lazy wave2Lazy; + Lazy wave2Lazy; dut.inflightDownloads.TryGetValue(ValidTestObjectFileSha1, out wave2Lazy).ShouldBeTrue("Wave 2 Lazy should be in dictionary"); // Simulate a straggling wave-1 thread: create a different Lazy and try to remove it. // With value-aware removal, this must NOT remove wave 2's Lazy. - Lazy staleLazy = - new Lazy(() => GitObjects.DownloadAndSaveObjectResult.Success); - bool staleRemoved = ((ICollection>>)dut.inflightDownloads) - .Remove(new KeyValuePair>(ValidTestObjectFileSha1, staleLazy)); + Lazy staleLazy = + new Lazy(() => new GVFSGitObjects.DownloadAttemptResult(GitObjects.DownloadAndSaveObjectResult.Success, httpStatusCode: null)); + bool staleRemoved = ((ICollection>>)dut.inflightDownloads) + .Remove(new KeyValuePair>(ValidTestObjectFileSha1, staleLazy)); staleRemoved.ShouldBeFalse("Straggling finally must not remove wave 2's Lazy"); dut.inflightDownloads.ContainsKey(ValidTestObjectFileSha1).ShouldBeTrue("Wave 2 Lazy must survive"); @@ -796,6 +914,12 @@ private MockHttpGitObjects(MockGVFSEnlistment enlistment) public Stream InputStream { get; set; } public string MediaType { get; set; } public HttpStatusCode? StatusCodeToReturn { get; set; } + + // When true, TryDownloadObjects returns a failing result built from GitObjectTaskResult(bool), + // i.e. Result is non-null but carries no HTTP status (HttpStatusCodeResult == 0). This + // exercises the "download failed without a status" branch of the telemetry status capture. + public bool FailWithoutStatus { get; set; } + public byte[] ContentBytesToServe { get; set; } public static MemoryStream GetRandomStream(int size) @@ -837,6 +961,16 @@ public override RetryWrapper.InvocationResult TryDownloadOb result: new GitObjectTaskResult(this.StatusCodeToReturn.Value)); } + if (this.FailWithoutStatus) + { + // A download that failed without an HTTP response: Result is non-null but its + // HttpStatusCodeResult stays 0, so no status should reach telemetry. + return new RetryWrapper.InvocationResult( + 0, + error: null, + result: new GitObjectTaskResult(false)); + } + // Serve a fresh stream per call when ContentBytesToServe is set so the download // succeeds even across retries (InputStream would be consumed after the first read). Stream contentStream = this.ContentBytesToServe != null