From 46c694fa642faaa7303c037da4b29ce1c46c3c10 Mon Sep 17 00:00:00 2001 From: Tyrie Vella Date: Mon, 20 Jul 2026 10:55:51 -0700 Subject: [PATCH] Split blob-hydration and directory-enumeration failure telemetry by cause The GVFS telemetry "Blob hydration failure" and "Directory enumeration failure" buckets conflate causes outside gvfs.exe's control (network, local disk/IO, ProjFS) with actionable ones (a missing object on the server, a size mismatch, or GVFS's own stale-enumeration eviction). Stamp a cause tag on the failure telemetry so the release-readiness dashboard can bucket them apart. No behavior changes: - BlobHydrationFailureCategory (nested in GVFSGitObjects) is now returned from TryCopyBlobContentStream via an out parameter as well as stamped on the terminal telemetry, so the virtualizer's own terminal event is tagged with the same cause rather than left uncategorized. Categories: NetworkUnavailable / DownloadFailed / LocalIO / ProjFSWriteFailed (not gvfs-fixable) vs ObjectNotOnServer / LocalCopyFailed / SizeMismatch / Unexpected (actionable). The size-mismatch, IOException, and WriteFileData failure sites were previously logged with a message the dashboard did not match; they now carry the tag so they are counted. - EnumerationFailureReason (nested enum) on "Failed to find active enumeration ID": Evicted (GVFS eviction removed a live enumeration; self-inflicted) vs Unknown (ProjFS delivered an id GVFS never held or already ended). The eviction-tracking map is populated before the entry is removed from the active set (closing a mislabel race) and pruned on every sweep so it cannot outlive its window. Unit tests assert each cause value deterministically. Assisted-by: Claude Opus 4.8 Signed-off-by: Tyrie Vella --- GVFS/GVFS.Common/Git/GVFSGitObjects.cs | 69 +++++++- .../WindowsFileSystemVirtualizer.cs | 76 ++++++++- .../GVFS.UnitTests/Git/GVFSGitObjectsTests.cs | 148 +++++++++++++++++- .../Mock/Git/MockGVFSGitObjects.cs | 42 ++++- .../WindowsFileSystemVirtualizerTests.cs | 103 ++++++++++++ 5 files changed, 425 insertions(+), 13 deletions(-) diff --git a/GVFS/GVFS.Common/Git/GVFSGitObjects.cs b/GVFS/GVFS.Common/Git/GVFSGitObjects.cs index b9044b2be4..0c27a5316a 100644 --- a/GVFS/GVFS.Common/Git/GVFSGitObjects.cs +++ b/GVFS/GVFS.Common/Git/GVFSGitObjects.cs @@ -33,14 +33,48 @@ public enum RequestSource SymLinkCreation, } + /// + /// Why a blob-hydration request ultimately failed. Recorded on the terminal failure + /// telemetry so failures outside gvfs.exe's control (network, local disk/IO, ProjFS) + /// can be told apart from failures that point at an actionable bug or a server/data + /// problem. Kept in sync with the telemetry bucketing in the devprod.git.telemetry + /// workbook (gvfs-regression-signatures.kql). + /// + public enum BlobHydrationFailureCategory + { + None = 0, + + // Outside gvfs.exe's control: + NetworkUnavailable, // A network/HTTP-layer exception while fetching the blob. + DownloadFailed, // The blob download reported failure (transient/unclassified). + LocalIO, // IOException reading the local object or streaming to the ProjFS buffer. + ProjFSWriteFailed, // ProjFS WriteFileData returned a non-recoverable error. + + // Actionable (bug, corruption, or server/data problem): + ObjectNotOnServer, // The cache server returned 404 for the blob. + LocalCopyFailed, // Blob downloaded, but the subsequent local copy still failed. + SizeMismatch, // Blob length did not match the length ProjFS requested. + Unexpected, // Unclassified exception. + } + protected GVFSContext Context { get; private set; } public virtual bool TryCopyBlobContentStream( string sha, CancellationToken cancellationToken, RequestSource requestSource, - Action writeAction) + Action writeAction, + out BlobHydrationFailureCategory failureCategory) { + // Track the outcome of the most recent attempt so that the terminal failure + // telemetry can attribute the failure to a cause (network vs. object-missing vs. + // 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; + bool downloadSucceededButCopyFailed = false; + BlobHydrationFailureCategory capturedCategory = BlobHydrationFailureCategory.None; + RetryWrapper retrier = new RetryWrapper(this.GitObjectRequestor.RetryConfig.MaxAttempts, cancellationToken); retrier.OnFailure += errorArgs => @@ -50,10 +84,35 @@ public virtual bool TryCopyBlobContentStream( metadata.Add("AttemptNumber", errorArgs.TryCount); metadata.Add("WillRetry", errorArgs.WillRetry); + BlobHydrationFailureCategory category; if (errorArgs.Error != null) { metadata.Add("Exception", errorArgs.Error.ToString()); + + // An IOException here can also originate in the download/network layer, but + // we cannot tell where it came from, so it is bucketed as local IO. + category = errorArgs.Error is IOException + ? BlobHydrationFailureCategory.LocalIO + : BlobHydrationFailureCategory.NetworkUnavailable; } + else if (downloadSucceededButCopyFailed) + { + category = BlobHydrationFailureCategory.LocalCopyFailed; + } + else if (lastDownloadResult == DownloadAndSaveObjectResult.ObjectNotOnServer) + { + category = BlobHydrationFailureCategory.ObjectNotOnServer; + } + else + { + // The download reported failure without an exception; the cause (network, + // disk-save, etc.) is unclassified, so use the neutral DownloadFailed bucket + // rather than over-asserting NetworkUnavailable. + category = BlobHydrationFailureCategory.DownloadFailed; + } + + capturedCategory = category; + metadata.Add(nameof(BlobHydrationFailureCategory), category.ToString()); string message = "TryCopyBlobContentStream: Failed to provide blob contents"; if (errorArgs.WillRetry) @@ -76,19 +135,25 @@ public virtual bool TryCopyBlobContentStream( } else { + downloadSucceededButCopyFailed = false; + // Pass in false for retryOnFailure because the retrier in this method manages multiple attempts - if (this.TryDownloadAndSaveObject(sha, cancellationToken, requestSource, retryOnFailure: false) == DownloadAndSaveObjectResult.Success) + lastDownloadResult = this.TryDownloadAndSaveObject(sha, cancellationToken, requestSource, retryOnFailure: false); + if (lastDownloadResult == DownloadAndSaveObjectResult.Success) { if (this.Context.Repository.TryCopyBlobContentStream(sha, writeAction)) { return new RetryWrapper.CallbackResult(true); } + + downloadSucceededButCopyFailed = true; } return new RetryWrapper.CallbackResult(error: null, shouldRetry: true); } }); + failureCategory = invokeResult.Result ? BlobHydrationFailureCategory.None : capturedCategory; return invokeResult.Result; } diff --git a/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs b/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs index a4bea90680..7a6bad6f24 100644 --- a/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs +++ b/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs @@ -59,6 +59,24 @@ public class WindowsFileSystemVirtualizer : FileSystemVirtualizer, IRequiredCall // the throttle cannot be disturbed by wall-clock adjustments. private long lastEnumerationEvictionSweepTickCount = Environment.TickCount64; + // Enumeration IDs recently removed by EvictStaleEnumerations, mapped to the monotonic tick at + // which they were evicted. Retained briefly so a later GetDirectoryEnumeration for an evicted + // ID can be attributed to GVFS eviction (self-inflicted) rather than a ProjFS unknown-ID + // delivery. Bounded by pruning during each sweep; empty while eviction is disabled (the default). + private readonly ConcurrentDictionary recentlyEvictedEnumerations = new ConcurrentDictionary(); + + /// + /// Why a GetDirectoryEnumeration failed to find its enumeration ID. Recorded on the failure + /// telemetry so a self-inflicted eviction can be told apart from a ProjFS unknown-ID delivery. + /// Kept in sync with the telemetry bucketing in devprod.git.telemetry + /// (gvfs-regression-signatures.kql). + /// + public enum EnumerationFailureReason + { + Unknown = 0, // ProjFS delivered an ID GVFS never held or already ended (outside gvfs.exe's control). + Evicted, // GVFS's own stale-enumeration eviction removed a live enumeration (self-inflicted). + } + public WindowsFileSystemVirtualizer(GVFSContext context, GVFSGitObjects gitObjects) : this( context, @@ -187,19 +205,51 @@ private void MaybeEvictStaleEnumerations() private void EvictStaleEnumerations() { + long now = Environment.TickCount64; + + // Prune the eviction-tracking map on every sweep, independent of whether an eviction + // happens this pass, so entries never outlive the window in which a stale + // GetDirectoryEnumeration could still arrive for an evicted ID. (If this ran only when + // Count > max below, the last evicted batch would linger once activity subsided.) Guids + // are never reused, so there is no need to prune on re-add. Cheap no-op while empty + // (the default, since eviction is off). + if (!this.recentlyEvictedEnumerations.IsEmpty) + { + long trackingCutoff = now - (long)(2 * this.activeEnumerationStaleTimeout.TotalMilliseconds); + foreach (KeyValuePair tracked in this.recentlyEvictedEnumerations) + { + if (tracked.Value < trackingCutoff) + { + this.recentlyEvictedEnumerations.TryRemove(tracked.Key, out _); + } + } + } + if (this.activeEnumerations.Count <= this.maxActiveEnumerations) { return; } - long cutoff = Environment.TickCount64 - (long)this.activeEnumerationStaleTimeout.TotalMilliseconds; + long cutoff = now - (long)this.activeEnumerationStaleTimeout.TotalMilliseconds; int evictedCount = 0; foreach (KeyValuePair entry in this.activeEnumerations) { - if (entry.Value.LastActivityTickCount < cutoff && - this.activeEnumerations.TryRemove(entry.Key, out _)) + if (entry.Value.LastActivityTickCount < cutoff) { - evictedCount++; + // Record the eviction BEFORE removing from activeEnumerations so a concurrent + // GetDirectoryEnumeration for this ID always finds it in one map or the other, + // and is never mis-attributed to a ProjFS unknown-ID delivery. + this.recentlyEvictedEnumerations[entry.Key] = now; + if (this.activeEnumerations.TryRemove(entry.Key, out _)) + { + evictedCount++; + } + else + { + // Lost the race (e.g. a normal EndDirectoryEnumeration removed it first); + // it was not evicted by us, so undo the tracking entry. + this.recentlyEvictedEnumerations.TryRemove(entry.Key, out _); + } } } @@ -464,6 +514,16 @@ public HResult GetDirectoryEnumerationCallback( EventMetadata metadata = this.CreateEventMetadata(enumerationId); metadata.Add("filterFileName", filterFileName); metadata.Add("restartScan", restartScan); + + // Distinguish a failure caused by GVFS's own stale-enumeration eviction + // (self-inflicted, fixable) from ProjFS delivering an ID GVFS never held or + // already ended (outside gvfs.exe's control). Kept in sync with the telemetry + // bucketing in devprod.git.telemetry (gvfs-regression-signatures.kql). + EnumerationFailureReason enumerationFailureReason = this.recentlyEvictedEnumerations.ContainsKey(enumerationId) + ? EnumerationFailureReason.Evicted + : EnumerationFailureReason.Unknown; + metadata.Add(nameof(EnumerationFailureReason), enumerationFailureReason.ToString()); + this.Context.Tracer.RelatedError(metadata, nameof(this.GetDirectoryEnumerationCallback) + ": Failed to find active enumeration ID"); return HResult.InternalError; @@ -1180,6 +1240,7 @@ private void GetFileStreamHandlerAsyncHandler( if (blobLength != length) { requestMetadata.Add("blobLength", blobLength); + requestMetadata.Add(nameof(GVFSGitObjects.BlobHydrationFailureCategory), GVFSGitObjects.BlobHydrationFailureCategory.SizeMismatch.ToString()); this.Context.Tracer.RelatedError(requestMetadata, $"{nameof(this.GetFileStreamHandlerAsyncHandler)}: Actual file length (blobLength) does not match requested length"); throw new GetFileStreamException(HResult.InternalError); @@ -1204,6 +1265,7 @@ private void GetFileStreamHandlerAsyncHandler( catch (IOException e) { requestMetadata.Add("Exception", e.ToString()); + requestMetadata.Add(nameof(GVFSGitObjects.BlobHydrationFailureCategory), GVFSGitObjects.BlobHydrationFailureCategory.LocalIO.ToString()); this.Context.Tracer.RelatedError(requestMetadata, "IOException while copying to unmanaged buffer."); throw new GetFileStreamException("IOException while copying to unmanaged buffer: " + e.Message, (HResult)HResultExtensions.HResultFromNtStatus.FileNotAvailable); @@ -1225,6 +1287,7 @@ private void GetFileStreamHandlerAsyncHandler( default: { + requestMetadata.Add(nameof(GVFSGitObjects.BlobHydrationFailureCategory), GVFSGitObjects.BlobHydrationFailureCategory.ProjFSWriteFailed.ToString()); this.Context.Tracer.RelatedError(requestMetadata, $"{nameof(this.virtualizationInstance.WriteFileData)} failed, error: " + writeResult.ToString("X") + "(" + writeResult.ToString("G") + ")"); } @@ -1235,8 +1298,10 @@ private void GetFileStreamHandlerAsyncHandler( } } } - })) + }, + out GVFSGitObjects.BlobHydrationFailureCategory failureCategory)) { + requestMetadata.Add(nameof(GVFSGitObjects.BlobHydrationFailureCategory), failureCategory.ToString()); this.Context.Tracer.RelatedError(requestMetadata, $"{nameof(this.GetFileStreamHandlerAsyncHandler)}: TryCopyBlobContentStream failed"); this.TryCompleteCommand(commandId, (HResult)HResultExtensions.HResultFromNtStatus.FileNotAvailable); @@ -1264,6 +1329,7 @@ private void GetFileStreamHandlerAsyncHandler( catch (Exception e) { requestMetadata.Add("Exception", e.ToString()); + requestMetadata.Add(nameof(GVFSGitObjects.BlobHydrationFailureCategory), GVFSGitObjects.BlobHydrationFailureCategory.Unexpected.ToString()); this.Context.Tracer.RelatedError(requestMetadata, $"{nameof(this.GetFileStreamHandlerAsyncHandler)}: TryCopyBlobContentStream failed"); this.TryCompleteCommand(commandId, (HResult)HResultExtensions.HResultFromNtStatus.FileNotAvailable); diff --git a/GVFS/GVFS.UnitTests/Git/GVFSGitObjectsTests.cs b/GVFS/GVFS.UnitTests/Git/GVFSGitObjectsTests.cs index caa23da244..dea5efc62e 100644 --- a/GVFS/GVFS.UnitTests/Git/GVFSGitObjectsTests.cs +++ b/GVFS/GVFS.UnitTests/Git/GVFSGitObjectsTests.cs @@ -11,6 +11,7 @@ using System; using System.Collections.Generic; using System.IO; +using System.Linq; using System.Net; using System.Reflection; using System.Threading; @@ -56,11 +57,124 @@ public void CatchesFileNotFoundAfterFileDeleted() ValidTestObjectFileSha1, new CancellationToken(), GVFSGitObjects.RequestSource.FileStreamCallback, - (stream, length) => Assert.Fail("Should not be able to call copy stream callback")) + (stream, length) => Assert.Fail("Should not be able to call copy stream callback"), + out GVFSGitObjects.BlobHydrationFailureCategory _) .ShouldEqual(false); } } + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void TerminalBlobHydrationFailureIsTaggedWithCategory() + { + MockFileSystemWithCallbacks fileSystem = new MockFileSystemWithCallbacks(); + fileSystem.OnFileExists = (path) => true; + fileSystem.OnOpenFileStream = (path, fileMode, fileAccess) => + { + if (fileAccess == FileAccess.Write) + { + return new MemoryStream(); + } + + throw new FileNotFoundException(); + }; + + MockHttpGitObjects httpObjects = new MockHttpGitObjects(); + using (httpObjects.InputStream = new MemoryStream(this.validTestObjectFileContents)) + { + httpObjects.MediaType = GVFSConstants.MediaTypes.LooseObjectMediaType; + 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); + + // The terminal failure carries a specific BlobHydrationFailureCategory so telemetry + // can tell failures outside gvfs.exe's control apart from actionable ones. Here the + // local copy misses and the download then fails, so the cause is NetworkUnavailable — + // surfaced both on the telemetry event and via the out parameter. + failureCategory.ShouldEqual(GVFSGitObjects.BlobHydrationFailureCategory.NetworkUnavailable); + string terminalError = tracer.RelatedErrorEvents.First(e => e.Contains("Failed to provide blob contents")); + terminalError.ShouldContain("\"BlobHydrationFailureCategory\":\"NetworkUnavailable\""); + } + } + + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void TerminalBlobHydrationFailureTagsObjectNotOnServer() + { + 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(); + httpObjects.StatusCodeToReturn = HttpStatusCode.NotFound; + 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); + + // The server returned 404, so the blob is genuinely missing on the server (actionable). + failureCategory.ShouldEqual(GVFSGitObjects.BlobHydrationFailureCategory.ObjectNotOnServer); + string terminalError = tracer.RelatedErrorEvents.First(e => e.Contains("Failed to provide blob contents")); + terminalError.ShouldContain("\"BlobHydrationFailureCategory\":\"ObjectNotOnServer\""); + } + + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void TerminalBlobHydrationFailureTagsLocalCopyFailed() + { + MockFileSystemWithCallbacks fileSystem = new MockFileSystemWithCallbacks(); + fileSystem.OnFileExists = (path) => true; + fileSystem.OnOpenFileStream = (path, mode, access) => + { + if (access == FileAccess.Write) + { + return new MemoryStream(); + } + + throw new FileNotFoundException(); + }; + fileSystem.OnMoveFile = (source, target) => { }; + + MockHttpGitObjects httpObjects = new MockHttpGitObjects(); + + // Serve fresh content on every attempt so the download succeeds; the failure must then be + // attributed to the local copy that keeps failing afterward, not to the download. + httpObjects.ContentBytesToServe = this.validTestObjectFileContents; + httpObjects.MediaType = GVFSConstants.MediaTypes.LooseObjectMediaType; + 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.LocalCopyFailed); + string terminalError = tracer.RelatedErrorEvents.First(e => e.Contains("Failed to provide blob contents")); + terminalError.ShouldContain("\"BlobHydrationFailureCategory\":\"LocalCopyFailed\""); + } + [TestCase] public void SucceedsForNormalLookingLooseObjectDownloads() { @@ -541,12 +655,18 @@ private void AssertRetryableExceptionOnDownload( private GVFSGitObjects CreateTestableGVFSGitObjects(GitObjectsHttpRequestor httpObjects, MockFileSystemWithCallbacks fileSystem) { - MockTracer tracer = new MockTracer(); + return this.CreateTestableGVFSGitObjects(httpObjects, fileSystem, out _); + } + + private GVFSGitObjects CreateTestableGVFSGitObjects(GitObjectsHttpRequestor httpObjects, MockFileSystemWithCallbacks fileSystem, out MockTracer tracer) + { + MockTracer localTracer = new MockTracer(); + tracer = localTracer; GVFSEnlistment enlistment = new GVFSEnlistment(TestEnlistmentRoot, "https://fakeRepoUrl", "fakeGitBinPath", authentication: null); enlistment.InitializeCachePathsFromKey(TestLocalCacheRoot, TestObjectRoot); - GitRepo repo = new GitRepo(tracer, enlistment, fileSystem, () => new MockLibGit2Repo(tracer)); + GitRepo repo = new GitRepo(localTracer, enlistment, fileSystem, () => new MockLibGit2Repo(localTracer)); - GVFSContext context = new GVFSContext(tracer, fileSystem, repo, enlistment); + GVFSContext context = new GVFSContext(localTracer, fileSystem, repo, enlistment); GVFSGitObjects dut = new UnsafeGVFSGitObjects(context, httpObjects); return dut; } @@ -565,6 +685,8 @@ private MockHttpGitObjects(MockGVFSEnlistment enlistment) public Stream InputStream { get; set; } public string MediaType { get; set; } + public HttpStatusCode? StatusCodeToReturn { get; set; } + public byte[] ContentBytesToServe { get; set; } public static MemoryStream GetRandomStream(int size) { @@ -595,10 +717,26 @@ public override RetryWrapper.InvocationResult TryDownloadOb Action.ErrorEventArgs> onFailure, bool preferBatchedLooseObjects) { + if (this.StatusCodeToReturn.HasValue) + { + // Simulate the server returning a non-OK status (e.g. 404) so callers can exercise + // the ObjectNotOnServer path. + return new RetryWrapper.InvocationResult( + 0, + error: null, + result: new GitObjectTaskResult(this.StatusCodeToReturn.Value)); + } + + // 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 + ? new MemoryStream(this.ContentBytesToServe) + : this.InputStream; + using (GitEndPointResponseData response = new GitEndPointResponseData( HttpStatusCode.OK, this.MediaType, - this.InputStream, + contentStream, message: null, onResponseDisposed: null)) { diff --git a/GVFS/GVFS.UnitTests/Mock/Git/MockGVFSGitObjects.cs b/GVFS/GVFS.UnitTests/Mock/Git/MockGVFSGitObjects.cs index b95984ecce..bb34332875 100644 --- a/GVFS/GVFS.UnitTests/Mock/Git/MockGVFSGitObjects.cs +++ b/GVFS/GVFS.UnitTests/Mock/Git/MockGVFSGitObjects.cs @@ -20,6 +20,8 @@ public MockGVFSGitObjects(GVFSContext context, GitObjectsHttpRequestor httpGitOb } public bool CancelTryCopyBlobContentStream { get; set; } + public bool ThrowOnTryCopyBlobContentStream { get; set; } + public bool ThrowIOExceptionDuringCopy { get; set; } public uint FileLength { get; set; } = DefaultFileLength; public override bool TryDownloadCommit(string objectSha) @@ -43,13 +45,31 @@ public override bool TryCopyBlobContentStream( string sha, CancellationToken cancellationToken, RequestSource requestSource, - Action writeAction) + Action writeAction, + out GVFSGitObjects.BlobHydrationFailureCategory failureCategory) { + failureCategory = GVFSGitObjects.BlobHydrationFailureCategory.None; + if (this.CancelTryCopyBlobContentStream) { throw new OperationCanceledException(); } + if (this.ThrowOnTryCopyBlobContentStream) + { + // A non-cancellation, non-GetFileStreamException exception exercises the generic + // catch in GetFileStreamHandlerAsyncHandler (BlobHydrationFailureCategory.Unexpected). + throw new InvalidOperationException("Simulated unexpected hydration failure"); + } + + if (this.ThrowIOExceptionDuringCopy) + { + // The served length matches the requested length (so no size mismatch), but reading + // the blob content throws IOException, exercising the LocalIO copy-failure path. + writeAction(new ThrowOnReadStream(this.FileLength), this.FileLength); + return true; + } + writeAction( new MemoryStream(new byte[this.FileLength]), this.FileLength); @@ -57,6 +77,26 @@ public override bool TryCopyBlobContentStream( return true; } + private sealed class ThrowOnReadStream : Stream + { + public ThrowOnReadStream(long length) + { + this.Length = length; + } + + public override bool CanRead => true; + public override bool CanSeek => false; + public override bool CanWrite => false; + public override long Length { get; } + public override long Position { get; set; } + + public override int Read(byte[] buffer, int offset, int count) => throw new IOException("Simulated IO failure while reading blob content"); + public override void Flush() { } + public override long Seek(long offset, SeekOrigin origin) => throw new NotSupportedException(); + public override void SetLength(long value) => throw new NotSupportedException(); + public override void Write(byte[] buffer, int offset, int count) => throw new NotSupportedException(); + } + public override string[] ReadPackFileNames(string packFolderPath, string prefixFilter = "") { return Array.Empty(); diff --git a/GVFS/GVFS.UnitTests/Windows/Virtualization/WindowsFileSystemVirtualizerTests.cs b/GVFS/GVFS.UnitTests/Windows/Virtualization/WindowsFileSystemVirtualizerTests.cs index c2d96a446b..bfd4a0e094 100644 --- a/GVFS/GVFS.UnitTests/Windows/Virtualization/WindowsFileSystemVirtualizerTests.cs +++ b/GVFS/GVFS.UnitTests/Windows/Virtualization/WindowsFileSystemVirtualizerTests.cs @@ -13,6 +13,7 @@ using System.IO; using System.Threading; using System.Threading.Tasks; +using System.Linq; using GVFS.Common.Tracing; namespace GVFS.UnitTests.Windows.Virtualization @@ -326,6 +327,42 @@ public void StaleEnumerationsAreEvictedWhenEnabledButLiveOnesAreKept() } } + [TestCase] + public void GetDirectoryEnumerationTagsEvictedVersusUnknownId() + { + using (WindowsFileSystemVirtualizerTester tester = new WindowsFileSystemVirtualizerTester(this.Repo, new[] { "test" })) + { + tester.GitIndexProjection.EnumerationInMemory = true; + + tester.WindowsVirtualizer.MaxActiveEnumerationsForTest = 1; + tester.WindowsVirtualizer.ActiveEnumerationStaleTimeoutForTest = TimeSpan.FromMilliseconds(20); + + Guid staleId = Guid.NewGuid(); + tester.MockVirtualization.RequiredCallbacks.StartDirectoryEnumerationCallback(1, staleId, "test", TriggeringProcessId, TriggeringProcessImageFileName).ShouldEqual(HResult.Ok); + + Thread.Sleep(200); + + Guid freshId = Guid.NewGuid(); + tester.MockVirtualization.RequiredCallbacks.StartDirectoryEnumerationCallback(2, freshId, "test", TriggeringProcessId, TriggeringProcessImageFileName).ShouldEqual(HResult.Ok); + + tester.WindowsVirtualizer.ForceEnumerationEvictionSweepForTest(); + + MockTracer mockTracker = this.Repo.Context.Tracer as MockTracer; + + // A Get for the evicted enumeration is attributed to GVFS eviction (self-inflicted). + // results is unused on the failure path, so null is safe. + tester.MockVirtualization.RequiredCallbacks.GetDirectoryEnumerationCallback(3, staleId, string.Empty, false, null).ShouldEqual(HResult.InternalError); + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("Failed to find active enumeration ID") && e.Contains("\"EnumerationFailureReason\":\"Evicted\"")).ShouldBeTrue(); + + // A Get for an ID GVFS never held is attributed to a ProjFS unknown-ID delivery. + Guid neverSeenId = Guid.NewGuid(); + tester.MockVirtualization.RequiredCallbacks.GetDirectoryEnumerationCallback(4, neverSeenId, string.Empty, false, null).ShouldEqual(HResult.InternalError); + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("Failed to find active enumeration ID") && e.Contains("\"EnumerationFailureReason\":\"Unknown\"")).ShouldBeTrue(); + } + } + [TestCase] public void GetPlaceholderInformationHandlerPathNotProjected() { @@ -600,6 +637,72 @@ public void OnGetFileStreamHandlesWriteFailure() HResult result = tester.MockVirtualization.WaitForCompletionStatus(); result.ShouldEqual(tester.MockVirtualization.WriteFileReturnResult); + + // The failure is tagged as a ProjFS write failure (a cause outside gvfs.exe's + // control) so telemetry can bucket it apart from actionable hydration failures. + MockTracer mockTracker = this.Repo.Context.Tracer as MockTracer; + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("\"BlobHydrationFailureCategory\":\"ProjFSWriteFailed\"")).ShouldBeTrue(); + } + } + + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void OnGetFileStreamTagsSizeMismatch() + { + using (WindowsFileSystemVirtualizerTester tester = new WindowsFileSystemVirtualizerTester(this.Repo)) + { + // The blob length served (FileLength) differs from the length ProjFS requested + // (DefaultFileLength), so hydration fails with a size mismatch (actionable cause). + MockGVFSGitObjects mockGVFSGitObjects = this.Repo.GitObjects as MockGVFSGitObjects; + mockGVFSGitObjects.FileLength = MockGVFSGitObjects.DefaultFileLength - 1; + + tester.InvokeGetFileDataCallback(expectedResult: HResult.Pending); + tester.MockVirtualization.WaitForCompletionStatus(); + + MockTracer mockTracker = this.Repo.Context.Tracer as MockTracer; + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("\"BlobHydrationFailureCategory\":\"SizeMismatch\"")).ShouldBeTrue(); + } + } + + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void OnGetFileStreamTagsUnexpectedException() + { + using (WindowsFileSystemVirtualizerTester tester = new WindowsFileSystemVirtualizerTester(this.Repo)) + { + // A non-cancellation, non-GetFileStreamException failure hits the generic catch and + // is tagged Unexpected so it can be triaged separately from known causes. + MockGVFSGitObjects mockGVFSGitObjects = this.Repo.GitObjects as MockGVFSGitObjects; + mockGVFSGitObjects.ThrowOnTryCopyBlobContentStream = true; + + tester.InvokeGetFileDataCallback(expectedResult: HResult.Pending); + tester.MockVirtualization.WaitForCompletionStatus(); + + MockTracer mockTracker = this.Repo.Context.Tracer as MockTracer; + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("\"BlobHydrationFailureCategory\":\"Unexpected\"")).ShouldBeTrue(); + } + } + + [TestCase] + [Category(CategoryConstants.ExceptionExpected)] + public void OnGetFileStreamTagsLocalIO() + { + using (WindowsFileSystemVirtualizerTester tester = new WindowsFileSystemVirtualizerTester(this.Repo)) + { + // Reading the blob content throws IOException while copying to the ProjFS buffer, + // so hydration fails with the LocalIO cause (outside gvfs.exe's control). + MockGVFSGitObjects mockGVFSGitObjects = this.Repo.GitObjects as MockGVFSGitObjects; + mockGVFSGitObjects.ThrowIOExceptionDuringCopy = true; + + tester.InvokeGetFileDataCallback(expectedResult: HResult.Pending); + tester.MockVirtualization.WaitForCompletionStatus(); + + MockTracer mockTracker = this.Repo.Context.Tracer as MockTracer; + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("\"BlobHydrationFailureCategory\":\"LocalIO\"")).ShouldBeTrue(); } }