diff --git a/.github/dependabot.yml b/.github/dependabot.yml index 22d5376407..7b2eaaf9f0 100644 --- a/.github/dependabot.yml +++ b/.github/dependabot.yml @@ -11,3 +11,5 @@ updates: directory: "/" # Location of package manifests schedule: interval: "weekly" + cooldown: + default-days: 7 diff --git a/.github/workflows/build.yaml b/.github/workflows/build.yaml index d0b4a4509a..a2778fb5a1 100644 --- a/.github/workflows/build.yaml +++ b/.github/workflows/build.yaml @@ -37,7 +37,7 @@ jobs: - name: Look for prior successful runs id: check if: github.event.inputs.git_version == '' - uses: actions/github-script@v9 + uses: actions/github-script@3a2844b7e9c422d3c10d287c895573f7108da1b3 # v9.0.0 with: github-token: ${{secrets.GITHUB_TOKEN}} result-encoding: string @@ -199,7 +199,7 @@ jobs: - name: Checkout source if: steps.check.outputs.result == '' - uses: actions/checkout@v7 + uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1 - name: Validate Microsoft Git version if: steps.check.outputs.result == '' @@ -249,7 +249,7 @@ jobs: - name: Upload microsoft/git installers if: steps.check.outputs.result == '' - uses: actions/upload-artifact@v7 + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 with: name: MicrosoftGit path: MicrosoftGit @@ -269,7 +269,7 @@ jobs: - name: Skip this job if there is a previous successful run if: needs.validate.outputs.skip != '' id: skip - uses: actions/github-script@v9 + uses: actions/github-script@3a2844b7e9c422d3c10d287c895573f7108da1b3 # v9.0.0 with: script: | core.info(`Skipping: There already is a successful run: ${{ needs.validate.outputs.skip }}`) @@ -277,19 +277,19 @@ jobs: - name: Checkout source if: steps.skip.outputs.result != 'true' - uses: actions/checkout@v7 + uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1 with: path: src - name: Install .NET SDK if: steps.skip.outputs.result != 'true' - uses: actions/setup-dotnet@v6 + uses: actions/setup-dotnet@a98b56852c35b8e3190ac28c8c2271da59106c68 # v6.0.0 with: global-json-file: src/global.json - name: Add MSBuild to PATH if: steps.skip.outputs.result != 'true' - uses: microsoft/setup-msbuild@v3.0.0 + uses: microsoft/setup-msbuild@30375c66a4eea26614e0d39710365f22f8b0af57 # v3.0.0 - name: Build VFS for Git if: steps.skip.outputs.result != 'true' @@ -308,21 +308,21 @@ jobs: - name: Upload functional tests drop if: steps.skip.outputs.result != 'true' - uses: actions/upload-artifact@v7 + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 with: name: FunctionalTests_${{ matrix.configuration }}_${{ matrix.architecture }} path: artifacts\GVFS.FunctionalTests - name: Upload FastFetch drop if: steps.skip.outputs.result != 'true' - uses: actions/upload-artifact@v7 + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 with: name: FastFetch_${{ matrix.configuration }}_${{ matrix.architecture }} path: artifacts\FastFetch - name: Upload GVFS installer if: steps.skip.outputs.result != 'true' - uses: actions/upload-artifact@v7 + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 with: name: GVFS_${{ matrix.configuration }}_${{ matrix.architecture }} path: artifacts\GVFS.Installers diff --git a/.github/workflows/functional-tests.yaml b/.github/workflows/functional-tests.yaml index 9b14047aab..7274f97656 100644 --- a/.github/workflows/functional-tests.yaml +++ b/.github/workflows/functional-tests.yaml @@ -70,7 +70,7 @@ jobs: - name: Skip this job if there is a previous successful run if: inputs.skip != '' id: skip - uses: actions/github-script@v9 + uses: actions/github-script@3a2844b7e9c422d3c10d287c895573f7108da1b3 # v9.0.0 with: script: | core.info(`Skipping: There already is a successful run: ${{ inputs.skip }}`) @@ -80,7 +80,7 @@ jobs: id: download-git if: steps.skip.outputs.result != 'true' continue-on-error: true - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: ${{ inputs.git_artifact_name }} path: git @@ -90,7 +90,7 @@ jobs: - name: Download Git installer (retry) if: steps.skip.outputs.result != 'true' && steps.download-git.outcome == 'failure' - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: ${{ inputs.git_artifact_name }} path: git @@ -102,7 +102,7 @@ jobs: id: download-gvfs if: steps.skip.outputs.result != 'true' continue-on-error: true - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: GVFS_${{ matrix.configuration }}_${{ matrix.architecture }} path: gvfs @@ -112,7 +112,7 @@ jobs: - name: Download GVFS installer (retry) if: steps.skip.outputs.result != 'true' && steps.download-gvfs.outcome == 'failure' - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: GVFS_${{ matrix.configuration }}_${{ matrix.architecture }} path: gvfs @@ -124,7 +124,7 @@ jobs: id: download-ft if: steps.skip.outputs.result != 'true' continue-on-error: true - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: FunctionalTests_${{ matrix.configuration }}_${{ matrix.architecture }} path: ft @@ -134,7 +134,7 @@ jobs: - name: Download functional tests drop (retry) if: steps.skip.outputs.result != 'true' && steps.download-ft.outcome == 'failure' - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: FunctionalTests_${{ matrix.configuration }}_${{ matrix.architecture }} path: ft @@ -145,7 +145,7 @@ jobs: - name: Download FastFetch drop if: steps.skip.outputs.result != 'true' continue-on-error: true - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: FastFetch_${{ matrix.configuration }}_${{ matrix.architecture }} path: ft @@ -189,7 +189,7 @@ jobs: - name: Upload installation logs if: always() && steps.skip.outputs.result != 'true' - uses: actions/upload-artifact@v7 + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 continue-on-error: true with: name: ${{ env.ARTIFACT_PREFIX }}InstallationLogs_${{ env.FT_MATRIX_NAME }} @@ -204,18 +204,28 @@ jobs: run: | SET PATH=C:\Program Files\VFS for Git;%PATH% SET GIT_TRACE2_PERF=C:\temp\git-trace2.log + SET GVFS_TEST_DIAGNOSTICS_DIR=C:\temp\gvfs-ft-diagnostics ft\GVFS.FunctionalTests.exe /result:TestResult.xml --ci --slice=${{ matrix.nr }},12 - - name: Upload functional test results + - name: Upload failure diagnostics (mount dumps + logs) if: always() && steps.skip.outputs.result != 'true' uses: actions/upload-artifact@v7 + continue-on-error: true + with: + name: ${{ env.ARTIFACT_PREFIX }}FailureDiagnostics_${{ env.FT_MATRIX_NAME }} + path: C:\temp\gvfs-ft-diagnostics + if-no-files-found: ignore + + - name: Upload functional test results + if: always() && steps.skip.outputs.result != 'true' + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 with: name: ${{ env.ARTIFACT_PREFIX }}FunctionalTests_Results_${{ env.FT_MATRIX_NAME }} path: TestResult.xml - name: Upload Git trace2 output if: always() && steps.skip.outputs.result != 'true' - uses: actions/upload-artifact@v7 + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 with: name: ${{ env.ARTIFACT_PREFIX }}GitTrace2_${{ env.FT_MATRIX_NAME }} path: C:\temp\git-trace2.log diff --git a/.github/workflows/upgrade-tests.yaml b/.github/workflows/upgrade-tests.yaml index fe33976f0f..04cb26f6b1 100644 --- a/.github/workflows/upgrade-tests.yaml +++ b/.github/workflows/upgrade-tests.yaml @@ -40,7 +40,7 @@ jobs: - name: Skip this job if there is a previous successful run if: inputs.skip != '' id: skip - uses: actions/github-script@v9 + uses: actions/github-script@3a2844b7e9c422d3c10d287c895573f7108da1b3 # v9.0.0 with: script: | core.info(`Skipping: There already is a successful run: ${{ inputs.skip }}`) @@ -66,14 +66,14 @@ jobs: id: download-git if: steps.skip.outputs.result != 'true' continue-on-error: true - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: MicrosoftGit path: git - name: Download Git installer (retry) if: steps.skip.outputs.result != 'true' && steps.download-git.outcome == 'failure' - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: MicrosoftGit path: git @@ -82,14 +82,14 @@ jobs: id: download-gvfs if: steps.skip.outputs.result != 'true' continue-on-error: true - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: GVFS_${{ matrix.configuration }}_x64 path: gvfs-new - name: Download current GVFS installer (retry) if: steps.skip.outputs.result != 'true' && steps.download-gvfs.outcome == 'failure' - uses: actions/download-artifact@v8 + uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1 with: name: GVFS_${{ matrix.configuration }}_x64 path: gvfs-new @@ -118,8 +118,25 @@ jobs: run: | $ErrorActionPreference = 'Stop' - $lkgInstaller = (Get-ChildItem gvfs-lkg\SetupGVFS*.exe).FullName - $newInstaller = (Get-ChildItem gvfs-new\SetupGVFS*.exe).FullName + # Releases publish both x64 and arm64 installers. The x64 installer + # keeps the historical suffix-less name "SetupGVFS..exe"; other + # architectures add a suffix (e.g. "SetupGVFS.-arm64.exe"). + # These tests run on an x64 runner, so select the x64 installer by its + # suffix-less name and require exactly one match, rather than picking an + # arbitrary file when the directory holds more than one installer. + # NOTE: arm64 upgrade is not exercised here because the runner is x64; + # arm64 upgrade coverage is a known gap for when arm64 runners exist. + function Select-X64Installer($directory) { + $installers = @(Get-ChildItem "$directory\SetupGVFS*.exe" | + Where-Object { $_.Name -match '^SetupGVFS\.[\d.]+\.exe$' }) + if ($installers.Count -ne 1) { + throw "Expected exactly one x64 installer in '$directory', found $($installers.Count): $($installers.Name -join ', ')" + } + return $installers[0].FullName + } + + $lkgInstaller = Select-X64Installer "gvfs-lkg" + $newInstaller = Select-X64Installer "gvfs-new" $installDir = "C:\Program Files\VFS for Git" $testRepo = "https://dev.azure.com/gvfs/ci/_git/ForTests" $enlistment = "C:\gvfs-upgrade-test" @@ -370,7 +387,7 @@ jobs: - name: Upload service logs if: always() && steps.skip.outputs.result != 'true' - uses: actions/upload-artifact@v7 + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 continue-on-error: true with: name: UpgradeTest_Logs_${{ matrix.scenario }} diff --git a/GVFS/FastFetch/FastFetchVerb.cs b/GVFS/FastFetch/FastFetchVerb.cs index 737b31ffe3..cf6add3aad 100644 --- a/GVFS/FastFetch/FastFetchVerb.cs +++ b/GVFS/FastFetch/FastFetchVerb.cs @@ -237,7 +237,9 @@ private int ExecuteWithExitCode() string fastfetchLogFile = Enlistment.GetNewLogFileName(enlistment.FastFetchLogRoot, "fastfetch"); tracer.AddLogFileEventListener(fastfetchLogFile, EventLevel.Informational, Keywords.Any); - CacheServerInfo cacheServer = new CacheServerInfo(this.GetRemoteUrl(enlistment), null); + CacheServerInfo cacheServer = string.IsNullOrWhiteSpace(this.CacheServerUrl) + ? CacheServerResolver.GetCacheServerFromConfig(enlistment) + : new CacheServerInfo(this.GetRemoteUrl(enlistment), null); tracer.WriteStartEvent( enlistment.PrimaryEnlistmentRoot, diff --git a/GVFS/GVFS.CommandLine.Tests/GvfsMainCliTests.cs b/GVFS/GVFS.CommandLine.Tests/GvfsMainCliTests.cs index 4eb360808e..5cb6be2407 100644 --- a/GVFS/GVFS.CommandLine.Tests/GvfsMainCliTests.cs +++ b/GVFS/GVFS.CommandLine.Tests/GvfsMainCliTests.cs @@ -215,12 +215,36 @@ public void Clone_FullCommandLine_ParsesCorrectly() { "clone", "https://example.com/repo", @"C:\Users\test\repo", "--cache-server-url", "https://cache.test", + "--prefetch-cache-server-url", "https://prefetch-cache.test", + "--get-cache-server-url", "https://get-cache.test", + "--post-cache-server-url", "https://post-cache.test", + "--sizes-cache-server-url", "https://sizes-cache.test", "-b", "develop", "--single-branch", "--no-mount", "--no-prefetch" }); Assert.That(parseResult.Errors, Is.Empty, "Full clone command should parse without errors"); + Assert.Multiple(() => + { + Assert.That(parseResult.GetValue((Option)FindOptionOnCommand("clone", "--cache-server-url")), Is.EqualTo("https://cache.test")); + Assert.That(parseResult.GetValue((Option)FindOptionOnCommand("clone", "--prefetch-cache-server-url")), Is.EqualTo("https://prefetch-cache.test")); + Assert.That(parseResult.GetValue((Option)FindOptionOnCommand("clone", "--get-cache-server-url")), Is.EqualTo("https://get-cache.test")); + Assert.That(parseResult.GetValue((Option)FindOptionOnCommand("clone", "--post-cache-server-url")), Is.EqualTo("https://post-cache.test")); + Assert.That(parseResult.GetValue((Option)FindOptionOnCommand("clone", "--sizes-cache-server-url")), Is.EqualTo("https://sizes-cache.test")); + }); + } + + [TestCase("--prefetch-cache-server-url")] + [TestCase("--get-cache-server-url")] + [TestCase("--post-cache-server-url")] + [TestCase("--sizes-cache-server-url")] + public void Clone_EndpointCacheServerUrl_RejectsInvalidUrl(string optionName) + { + var parseResult = rootCommand.Parse(new[] { "clone", "https://example.com/repo", optionName, "not-a-url" }); + + Assert.That(parseResult.Errors, Has.Count.EqualTo(1)); + Assert.That(parseResult.Errors[0].Message, Does.Contain("requires an absolute URL")); } [Test] @@ -342,7 +366,19 @@ public void Repair_FullCommandLine_ParsesCorrectly() [Test] public void Clone_HasAllExpectedOptions() { - var expected = new[] { "--cache-server-url", "--branch", "--single-branch", "--no-mount", "--no-prefetch", "--local-cache-path" }; + var expected = new[] + { + "--cache-server-url", + "--prefetch-cache-server-url", + "--get-cache-server-url", + "--post-cache-server-url", + "--sizes-cache-server-url", + "--branch", + "--single-branch", + "--no-mount", + "--no-prefetch", + "--local-cache-path", + }; foreach (var optName in expected) { Assert.That(FindOptionOnCommand("clone", optName), Is.Not.Null, diff --git a/GVFS/GVFS.Common/GVFSConstants.cs b/GVFS/GVFS.Common/GVFSConstants.cs index 3dd946bff5..088d771957 100644 --- a/GVFS/GVFS.Common/GVFSConstants.cs +++ b/GVFS/GVFS.Common/GVFSConstants.cs @@ -33,6 +33,10 @@ public static class GitConfig public const string MountId = GVFSPrefix + "mount-id"; public const string EnlistmentId = GVFSPrefix + "enlistment-id"; public const string CacheServer = GVFSPrefix + "cache-server"; + public const string PrefetchCacheServer = GVFSPrefix + "prefetch.cache-server"; + public const string GetCacheServer = GVFSPrefix + "get.cache-server"; + public const string PostCacheServer = GVFSPrefix + "post.cache-server"; + public const string SizesCacheServer = GVFSPrefix + "sizes.cache-server"; public const string DeprecatedCacheEndpointSuffix = ".cache-server-url"; public const string HooksPrefix = GitConfig.GVFSPrefix + "clone.default-"; public const string GVFSTelemetryId = GitConfig.GVFSPrefix + "telemetry-id"; @@ -45,6 +49,13 @@ public static class GitConfig public const string TrustPackIndexes = GVFSPrefix + "trust-pack-indexes"; public const bool TrustPackIndexesDefault = true; + /* Kill switch for the destructive part of packfile-maintenance corruption recovery: when + * false, GVFS still detects and reports corrupt packs but does not delete them (or later + * prefetch packs) and does not request a restoring prefetch. Detection/telemetry is + * unaffected; the non-destructive multi-pack-index rewrite still runs. */ + public const string EnablePackfileRecovery = GVFSPrefix + "enable-packfile-recovery"; + public const bool EnablePackfileRecoveryDefault = true; + public const string ShowHydrationStatus = GVFSPrefix + "show-hydration-status"; public const bool ShowHydrationStatusDefault = false; diff --git a/GVFS/GVFS.Common/Git/GitObjects.cs b/GVFS/GVFS.Common/Git/GitObjects.cs index a9b0f2851a..19c1a0e608 100644 --- a/GVFS/GVFS.Common/Git/GitObjects.cs +++ b/GVFS/GVFS.Common/Git/GitObjects.cs @@ -180,6 +180,11 @@ public virtual bool TryDownloadPrefetchPacks(GitProcess gitProcess, long latestT "{0}?lastPackTimestamp={1}", this.GitObjectRequestor.CacheServer.PrefetchEndpointUrl, latestTimestamp)), + fallbackEndPointGenerator: () => new Uri( + string.Format( + "{0}?lastPackTimestamp={1}", + this.GitObjectRequestor.CacheServer.GlobalPrefetchEndpointUrl, + latestTimestamp)), requestBodyGenerator: () => null, cancellationToken: CancellationToken.None, acceptType: new MediaTypeWithQualityHeaderValue(GVFSConstants.MediaTypes.PrefetchPackFilesAndIndexesMediaType)); @@ -188,18 +193,21 @@ public virtual bool TryDownloadPrefetchPacks(GitProcess gitProcess, long latestT if (!result.Succeeded) { + Uri requestUri = result.Result?.RequestUri + ?? new Uri(this.GitObjectRequestor.CacheServer.PrefetchEndpointUrl); + string requestAuthority = HttpRequestor.GetAuthorityForTelemetry(requestUri); if (result.Result != null && result.Result.HttpStatusCodeResult == HttpStatusCode.NotFound) { EventMetadata warning = CreateEventMetadata(); warning.Add(TracingConstants.MessageKey.WarningMessage, "The server does not support " + GVFSConstants.Endpoints.GVFSPrefetch); - warning.Add(nameof(this.GitObjectRequestor.CacheServer.PrefetchEndpointUrl), this.GitObjectRequestor.CacheServer.PrefetchEndpointUrl); + warning.Add("PrefetchEndpointUrl", requestAuthority); activity.RelatedEvent(EventLevel.Warning, "CommandNotSupported", warning); } else { EventMetadata error = CreateEventMetadata(result.Error); error.Add("latestTimestamp", latestTimestamp); - error.Add(nameof(this.GitObjectRequestor.CacheServer.PrefetchEndpointUrl), this.GitObjectRequestor.CacheServer.PrefetchEndpointUrl); + error.Add("PrefetchEndpointUrl", requestAuthority); activity.RelatedWarning(error, "DownloadPrefetchPacks failed.", Keywords.Telemetry); } } diff --git a/GVFS/GVFS.Common/Git/GitProcess.cs b/GVFS/GVFS.Common/Git/GitProcess.cs index 03cc27b417..43a40ced02 100644 --- a/GVFS/GVFS.Common/Git/GitProcess.cs +++ b/GVFS/GVFS.Common/Git/GitProcess.cs @@ -806,6 +806,17 @@ public Result VerifyMultiPackIndex(string objectDir) return this.InvokeGitAgainstDotGitFolder("-c core.multiPackIndex=true multi-pack-index verify --object-dir=\"" + objectDir + "\" --no-progress"); } + /// + /// Verifies the integrity of a single packfile via its .idx. Returns a failure exit code if the + /// pack is truncated or otherwise unreadable. Used by pack maintenance recovery to determine + /// which pack is corrupt - the "could not load pack N" ordinal reported by the multi-pack-index + /// is an internal position, not a filename, so it cannot be mapped to a file directly. + /// + public Result VerifyPack(string packIndexPath) + { + return this.InvokeGitAgainstDotGitFolder("verify-pack \"" + packIndexPath + "\""); + } + public Result RemoteAdd(string remoteName, string url) { return this.InvokeGitAgainstDotGitFolder("remote add " + remoteName + " " + url); diff --git a/GVFS/GVFS.Common/Git/LibGit2Repo.cs b/GVFS/GVFS.Common/Git/LibGit2Repo.cs index 00bc55e73e..b21eb83b9e 100644 --- a/GVFS/GVFS.Common/Git/LibGit2Repo.cs +++ b/GVFS/GVFS.Common/Git/LibGit2Repo.cs @@ -39,8 +39,13 @@ public LibGit2Repo(ITracer tracer, string repoPath) } protected LibGit2Repo() + : this(NullTracer.Instance) { - this.Tracer = NullTracer.Instance; + } + + protected LibGit2Repo(ITracer tracer) + { + this.Tracer = tracer; } ~LibGit2Repo() @@ -327,6 +332,55 @@ public virtual string GetConfigString(string name) } } + /// + /// Reads a boolean config value from this already-open repo, falling back to + /// if the key is unset or the read fails for any reason + /// (e.g. a corrupt/unreadable config). + /// + public bool GetConfigBoolOrDefault(string key, bool defaultValue) + { + try + { + return this.GetConfigBool(key) ?? defaultValue; + } + catch (Exception e) + { + this.Tracer.RelatedWarning($"Failed to read {key} config, using default: {e.Message}"); + return defaultValue; + } + } + + /// + /// Reads a single boolean config value from the repo at , + /// opening and disposing a transient for the lookup. Prefer + /// this over for one-off config reads: + /// LibGit2RepoInvoker.InitializeSharedRepo forces the object store to load, which is + /// wasted work when all that's needed is a single config value. Falls back to + /// if the repo can't be opened or the read fails for any + /// reason. + /// + public static bool GetConfigBoolOrDefault(ITracer tracer, string repoPath, string key, bool defaultValue) + { + try + { + using (LibGit2Repo repo = new LibGit2Repo(tracer, repoPath)) + { + return repo.GetConfigBoolOrDefault(key, defaultValue); + } + } + catch (InvalidDataException) + { + // The LibGit2Repo constructor already logged a RelatedWarning with the native + // failure reason before throwing; avoid logging the same failure twice. + return defaultValue; + } + catch (Exception e) + { + tracer.RelatedWarning($"Failed to read {key} config, using default: {e.Message}"); + return defaultValue; + } + } + public void ForEachMultiVarConfig(string key, MultiVarConfigCallback callback) { if (Native.Config.GetConfig(out IntPtr configHandle, this.RepoHandle) != Native.ResultCode.Success) diff --git a/GVFS/GVFS.Common/Git/RequiredGitConfig.cs b/GVFS/GVFS.Common/Git/RequiredGitConfig.cs index a9159e6638..8f40e2dd37 100644 --- a/GVFS/GVFS.Common/Git/RequiredGitConfig.cs +++ b/GVFS/GVFS.Common/Git/RequiredGitConfig.cs @@ -183,6 +183,9 @@ public static Dictionary GetRequiredSettings(GVFSEnlistment enli // Disable the builtin FS Monitor in case it was enabled globally. { "core.useBuiltinFSMonitor", "false" }, + + // Disable the FS Monitor in case it was enabled globally. + { "core.fsmonitor", "false" }, }; } } diff --git a/GVFS/GVFS.Common/Http/CacheServerInfo.cs b/GVFS/GVFS.Common/Http/CacheServerInfo.cs index 0ec929b0dc..9df0399e42 100644 --- a/GVFS/GVFS.Common/Http/CacheServerInfo.cs +++ b/GVFS/GVFS.Common/Http/CacheServerInfo.cs @@ -11,30 +11,105 @@ public class CacheServerInfo [JsonConstructor] public CacheServerInfo(string url, string name, bool globalDefault = false) + : this(url, name, globalDefault, null, null, null, null) + { + } + + public CacheServerInfo( + string url, + string name, + bool globalDefault, + string prefetchCacheServerUrl, + string getCacheServerUrl, + string postCacheServerUrl, + string sizesCacheServerUrl) { this.Url = url; this.Name = name; this.GlobalDefault = globalDefault; + this.PrefetchCacheServerUrl = prefetchCacheServerUrl; + this.GetCacheServerUrl = getCacheServerUrl; + this.PostCacheServerUrl = postCacheServerUrl; + this.SizesCacheServerUrl = sizesCacheServerUrl; if (this.Url != null) { this.ObjectsEndpointUrl = this.Url + ObjectsEndpointSuffix; - this.PrefetchEndpointUrl = this.Url + PrefetchEndpointSuffix; - this.SizesEndpointUrl = this.Url + SizesEndpointSuffix; } + + this.GlobalPrefetchEndpointUrl = GetEndpointUrl(this.Url, PrefetchEndpointSuffix); + this.GlobalSizesEndpointUrl = GetEndpointUrl(this.Url, SizesEndpointSuffix); + this.PrefetchEndpointUrl = GetEndpointUrl(prefetchCacheServerUrl ?? this.Url, PrefetchEndpointSuffix); + this.ObjectsGetEndpointUrl = GetEndpointUrl(getCacheServerUrl ?? this.Url, ObjectsEndpointSuffix); + this.ObjectsPostEndpointUrl = GetEndpointUrl(postCacheServerUrl ?? this.Url, ObjectsEndpointSuffix); + this.SizesEndpointUrl = GetEndpointUrl(sizesCacheServerUrl ?? this.Url, SizesEndpointSuffix); } public string Url { get; } public string Name { get; } public bool GlobalDefault { get; } + [JsonIgnore] + public string PrefetchCacheServerUrl { get; } + + [JsonIgnore] + public string GetCacheServerUrl { get; } + + [JsonIgnore] + public string PostCacheServerUrl { get; } + + [JsonIgnore] + public string SizesCacheServerUrl { get; } + public string ObjectsEndpointUrl { get; } public string PrefetchEndpointUrl { get; } public string SizesEndpointUrl { get; } + [JsonIgnore] + public string ObjectsGetEndpointUrl { get; } + + [JsonIgnore] + public string ObjectsPostEndpointUrl { get; } + + [JsonIgnore] + public string GlobalPrefetchEndpointUrl { get; } + + [JsonIgnore] + public string GlobalSizesEndpointUrl { get; } + + public CacheServerInfo WithEndpointOverrides( + string prefetchCacheServerUrl, + string getCacheServerUrl, + string postCacheServerUrl, + string sizesCacheServerUrl) + { + return new CacheServerInfo( + this.Url, + this.Name, + this.GlobalDefault, + prefetchCacheServerUrl, + getCacheServerUrl, + postCacheServerUrl, + sizesCacheServerUrl); + } + + public CacheServerInfo WithEndpointOverridesFrom(CacheServerInfo cacheServer) + { + return this.WithEndpointOverrides( + cacheServer.PrefetchCacheServerUrl, + cacheServer.GetCacheServerUrl, + cacheServer.PostCacheServerUrl, + cacheServer.SizesCacheServerUrl); + } + public bool HasValidUrl() { - return Uri.IsWellFormedUriString(this.Url, UriKind.Absolute); + return IsValidUrl(this.Url); + } + + public static bool IsValidUrl(string url) + { + return Uri.IsWellFormedUriString(url, UriKind.Absolute); } public bool IsNone(string repoUrl) @@ -64,5 +139,10 @@ public static class ReservedNames public const string Default = "Default"; public const string UserDefined = "User Defined"; } + + private static string GetEndpointUrl(string cacheServerUrl, string endpointSuffix) + { + return cacheServerUrl == null ? null : cacheServerUrl + endpointSuffix; + } } } diff --git a/GVFS/GVFS.Common/Http/CacheServerResolver.cs b/GVFS/GVFS.Common/Http/CacheServerResolver.cs index bc1df9727b..7a0c6e1a73 100644 --- a/GVFS/GVFS.Common/Http/CacheServerResolver.cs +++ b/GVFS/GVFS.Common/Http/CacheServerResolver.cs @@ -20,10 +20,20 @@ public CacheServerResolver( public static CacheServerInfo GetCacheServerFromConfig(Enlistment enlistment) { + GitProcess git = enlistment.CreateGitProcess(); string url = GetUrlFromConfig(enlistment); + string prefetchCacheServerUrl = GetEndpointUrlFromConfig(git, GVFSConstants.GitConfig.PrefetchCacheServer); + string getCacheServerUrl = GetEndpointUrlFromConfig(git, GVFSConstants.GitConfig.GetCacheServer); + string postCacheServerUrl = GetEndpointUrlFromConfig(git, GVFSConstants.GitConfig.PostCacheServer); + string sizesCacheServerUrl = GetEndpointUrlFromConfig(git, GVFSConstants.GitConfig.SizesCacheServer); return new CacheServerInfo( url, - url == enlistment.RepoUrl ? CacheServerInfo.ReservedNames.None : null); + url == enlistment.RepoUrl ? CacheServerInfo.ReservedNames.None : null, + globalDefault: false, + prefetchCacheServerUrl, + getCacheServerUrl, + postCacheServerUrl, + sizesCacheServerUrl); } public static string GetUrlFromConfig(Enlistment enlistment) @@ -129,6 +139,22 @@ public bool TrySaveUrlToLocalConfig(CacheServerInfo cache, out string error) return result.ExitCodeIsSuccess; } + public bool TrySaveEndpointUrlsToLocalConfig(CacheServerInfo cache, out string error) + { + GitProcess git = this.enlistment.CreateGitProcess(); + + if (!TrySaveEndpointUrl(git, GVFSConstants.GitConfig.PrefetchCacheServer, cache.PrefetchCacheServerUrl, out error) || + !TrySaveEndpointUrl(git, GVFSConstants.GitConfig.GetCacheServer, cache.GetCacheServerUrl, out error) || + !TrySaveEndpointUrl(git, GVFSConstants.GitConfig.PostCacheServer, cache.PostCacheServerUrl, out error) || + !TrySaveEndpointUrl(git, GVFSConstants.GitConfig.SizesCacheServer, cache.SizesCacheServerUrl, out error)) + { + return false; + } + + error = null; + return true; + } + private static string GetValueFromConfig(GitProcess git, string configName, bool localOnly) { GitProcess.ConfigResult result = @@ -144,6 +170,30 @@ private static string GetValueFromConfig(GitProcess git, string configName, bool return value; } + private static string GetEndpointUrlFromConfig(GitProcess git, string configName) + { + string url = GetValueFromConfig(git, configName, localOnly: true); + if (url != null && !CacheServerInfo.IsValidUrl(url)) + { + throw new InvalidRepoException($"Invalid value for {configName}: '{url}' is not an absolute URL."); + } + + return url; + } + + private static bool TrySaveEndpointUrl(GitProcess git, string configName, string url, out string error) + { + error = null; + if (url == null) + { + return true; + } + + GitProcess.Result result = git.SetInLocalConfig(configName, url, replaceAll: true); + error = result.Errors; + return result.ExitCodeIsSuccess; + } + private static string GetDeprecatedCacheConfigSettingName(Enlistment enlistment) { string sectionUrl = diff --git a/GVFS/GVFS.Common/Http/GitEndPointResponseData.cs b/GVFS/GVFS.Common/Http/GitEndPointResponseData.cs index 0d450bf9d1..9eb6164219 100644 --- a/GVFS/GVFS.Common/Http/GitEndPointResponseData.cs +++ b/GVFS/GVFS.Common/Http/GitEndPointResponseData.cs @@ -4,6 +4,8 @@ using System.IO; using System.Net; using System.Net.Http; +using System.Threading; +using System.Threading.Tasks; namespace GVFS.Common.Http { @@ -30,7 +32,7 @@ public GitEndPointResponseData(HttpStatusCode statusCode, Exception error, bool public GitEndPointResponseData(HttpStatusCode statusCode, string contentType, Stream responseStream, HttpResponseMessage message, Action onResponseDisposed) : this(statusCode, null, false, message, onResponseDisposed) { - this.Stream = responseStream; + this.Stream = responseStream == null ? null : new ReadErrorTrackingStream(responseStream); this.ContentType = MapContentType(contentType); } @@ -42,6 +44,11 @@ public GitEndPointResponseData(HttpStatusCode statusCode, string contentType, St public Stream Stream { get; private set; } + public bool StreamReadFailed + { + get { return this.Stream is ReadErrorTrackingStream trackingStream && trackingStream.ReadFailed; } + } + public bool HasErrors { get { return this.StatusCode != HttpStatusCode.OK; } @@ -70,7 +77,7 @@ public string RetryableReadToEnd() { return contentStreamReader.ReadToEnd(); } - catch (Exception ex) + catch (Exception ex) when (!(ex is OperationCanceledException)) { // All exceptions potentially from network should be retried throw new RetryableException("Exception while reading stream. See inner exception for details.", ex); @@ -99,7 +106,7 @@ public List RetryableReadAllLines() line = contentStreamReader.ReadLine(); } - catch (Exception ex) + catch (Exception ex) when (!(ex is OperationCanceledException)) { // All exceptions potentially from network should be retried throw new RetryableException("Exception while reading stream. See inner exception for details.", ex); @@ -159,5 +166,83 @@ private static GitObjectContentType MapContentType(string contentType) return GitObjectContentType.None; } } + + private sealed class ReadErrorTrackingStream : Stream + { + private readonly Stream innerStream; + + public ReadErrorTrackingStream(Stream innerStream) + { + this.innerStream = innerStream; + } + + public bool ReadFailed { get; private set; } + + public override bool CanRead => this.innerStream.CanRead; + + public override bool CanSeek => this.innerStream.CanSeek; + + public override bool CanWrite => this.innerStream.CanWrite; + + public override long Length => this.innerStream.Length; + + public override long Position + { + get { return this.innerStream.Position; } + set { this.innerStream.Position = value; } + } + + public override void Flush() => this.innerStream.Flush(); + + public override int Read(byte[] buffer, int offset, int count) => + this.TrackRead(() => this.innerStream.Read(buffer, offset, count)); + + public override int ReadByte() => this.TrackRead(this.innerStream.ReadByte); + + public override Task ReadAsync(byte[] buffer, int offset, int count, CancellationToken cancellationToken) => + this.TrackReadAsync(() => this.innerStream.ReadAsync(buffer, offset, count, cancellationToken)); + + public override long Seek(long offset, SeekOrigin origin) => this.innerStream.Seek(offset, origin); + + public override void SetLength(long value) => this.innerStream.SetLength(value); + + public override void Write(byte[] buffer, int offset, int count) => this.innerStream.Write(buffer, offset, count); + + protected override void Dispose(bool disposing) + { + if (disposing) + { + this.innerStream.Dispose(); + } + + base.Dispose(disposing); + } + + private T TrackRead(Func read) + { + try + { + return read(); + } + catch (Exception ex) when (!(ex is OperationCanceledException)) + { + this.ReadFailed = true; + throw; + } + } + + private async Task TrackReadAsync(Func> read) + { + try + { + return await read().ConfigureAwait(false); + } + catch (Exception ex) when (!(ex is OperationCanceledException)) + { + this.ReadFailed = true; + throw; + } + } + } } } diff --git a/GVFS/GVFS.Common/Http/GitObjectsHttpRequestor.cs b/GVFS/GVFS.Common/Http/GitObjectsHttpRequestor.cs index 2cdffcb8da..278351b8ee 100644 --- a/GVFS/GVFS.Common/Http/GitObjectsHttpRequestor.cs +++ b/GVFS/GVFS.Common/Http/GitObjectsHttpRequestor.cs @@ -2,6 +2,7 @@ using GVFS.Common.Tracing; using System; using System.Collections.Generic; +using System.IO; using System.Text.Json.Serialization; using System.Linq; using System.Net; @@ -34,8 +35,12 @@ public virtual List QueryForFileSizes(IEnumerable objectI long requestId = HttpRequestor.GetNewRequestId(); string objectIdsJson = ToJsonList(objectIds); - Uri cacheServerEndpoint = new Uri(this.CacheServer.SizesEndpointUrl); + Uri preferredCacheServerEndpoint = new Uri(this.CacheServer.SizesEndpointUrl); + Uri globalCacheServerEndpoint = new Uri(this.CacheServer.GlobalSizesEndpointUrl); Uri originEndpoint = new Uri(this.enlistment.RepoUrl + GVFSConstants.Endpoints.GVFSSizes); + bool hasEndpointOverride = preferredCacheServerEndpoint != globalCacheServerEndpoint; + bool useGlobalCacheServer = !hasEndpointOverride; + bool useOrigin = this.nextCacheServerAttemptTime >= DateTime.Now; EventMetadata metadata = new EventMetadata(); metadata.Add("RequestId", requestId); @@ -51,38 +56,91 @@ public virtual List QueryForFileSizes(IEnumerable objectI this.Tracer.RelatedEvent(EventLevel.Informational, "QueryFileSizes", metadata, Keywords.Network); - RetryWrapper> retrier = new RetryWrapper>(this.RetryConfig.MaxAttempts, cancellationToken); + RetryWrapper> retrier = new RetryWrapper>( + this.RetryConfig.MaxAttempts + (hasEndpointOverride && !useOrigin ? 2 : 0), + cancellationToken); retrier.OnFailure += RetryWrapper>.StandardErrorHandler(this.Tracer, requestId, "QueryFileSizes"); RetryWrapper>.InvocationResult requestTask = retrier.Invoke( tryCount => { Uri gvfsEndpoint; - if (this.nextCacheServerAttemptTime < DateTime.Now) + if (useOrigin) + { + gvfsEndpoint = originEndpoint; + } + else if (useGlobalCacheServer) { - gvfsEndpoint = cacheServerEndpoint; + gvfsEndpoint = globalCacheServerEndpoint; } else { - gvfsEndpoint = originEndpoint; + gvfsEndpoint = preferredCacheServerEndpoint; } - using (GitEndPointResponseData response = this.SendRequest(requestId, gvfsEndpoint, HttpMethod.Post, objectIdsJson, cancellationToken)) + try { - if (response.StatusCode == HttpStatusCode.NotFound) + using (GitEndPointResponseData response = this.SendProtocolRequest(requestId, gvfsEndpoint, HttpMethod.Post, objectIdsJson, cancellationToken)) { - this.nextCacheServerAttemptTime = DateTime.Now.AddDays(1); - return new RetryWrapper>.CallbackResult(response.Error, true); + if (response.HasErrors && !useGlobalCacheServer && !useOrigin) + { + this.TraceCacheServerFallback( + requestId, + preferredCacheServerEndpoint, + globalCacheServerEndpoint, + "EndpointSpecific", + "Global"); + useGlobalCacheServer = true; + return new RetryWrapper>.CallbackResult( + response.Error, + shouldRetry: true, + result: null, + shouldRecordFailure: false); + } + + if (response.StatusCode == HttpStatusCode.NotFound) + { + if (!useOrigin) + { + this.TraceCacheServerFallback( + requestId, + globalCacheServerEndpoint, + originEndpoint, + "Global", + "Origin"); + } + + this.nextCacheServerAttemptTime = DateTime.Now.AddDays(1); + useOrigin = true; + return new RetryWrapper>.CallbackResult( + response.Error, + shouldRetry: true, + result: null, + shouldRecordFailure: false); + } + + if (response.HasErrors) + { + return new RetryWrapper>.CallbackResult(response.Error, response.ShouldRetry); + } + + string objectSizesString = response.RetryableReadToEnd(); + List objectSizes = GVFSJsonOptions.Deserialize>(objectSizesString); + return new RetryWrapper>.CallbackResult(objectSizes); } - - if (response.HasErrors) - { - return new RetryWrapper>.CallbackResult(response.Error, response.ShouldRetry); - } - - string objectSizesString = response.RetryableReadToEnd(); - List objectSizes = GVFSJsonOptions.Deserialize>(objectSizesString); - return new RetryWrapper>.CallbackResult(objectSizes); + } + catch (Exception e) when ( + (e is HttpRequestException || e is IOException || e is RetryableException) && + !useGlobalCacheServer && + !useOrigin) + { + this.TraceCacheServerFallback(requestId, preferredCacheServerEndpoint, globalCacheServerEndpoint, "EndpointSpecific", "Global"); + useGlobalCacheServer = true; + return new RetryWrapper>.CallbackResult( + e, + shouldRetry: true, + result: null, + shouldRecordFailure: false); } }); @@ -109,7 +167,7 @@ public virtual GitRefs QueryInfoRefs(string branch) RetryWrapper.InvocationResult output = retrier.Invoke( tryCount => { - using (GitEndPointResponseData response = this.SendRequest( + using (GitEndPointResponseData response = this.SendProtocolRequest( requestId, infoRefsEndpoint, HttpMethod.Get, @@ -149,6 +207,7 @@ public virtual RetryWrapper.InvocationResult TryDownloadLoo onSuccess, eArgs => this.HandleDownloadAndSaveObjectError(retryOnFailure, requestId, eArgs), HttpMethod.Get, + new Uri(this.CacheServer.ObjectsGetEndpointUrl + "/" + objectId), new Uri(this.CacheServer.ObjectsEndpointUrl + "/" + objectId), cancellationToken, requestBody: null, @@ -170,10 +229,11 @@ public virtual RetryWrapper.InvocationResult TryDownloadObj onSuccess, onFailure, HttpMethod.Post, - new Uri(this.CacheServer.ObjectsEndpointUrl), - CancellationToken.None, - () => this.ObjectIdsJsonGenerator(requestId, objectIdGenerator), - preferBatchedLooseObjects ? CustomLooseObjectsHeader : null); + () => new Uri(this.CacheServer.ObjectsPostEndpointUrl), + requestBodyGenerator: () => this.ObjectIdsJsonGenerator(requestId, objectIdGenerator), + cancellationToken: CancellationToken.None, + acceptType: preferBatchedLooseObjects ? CustomLooseObjectsHeader : null, + fallbackEndPointGenerator: () => new Uri(this.CacheServer.ObjectsEndpointUrl)); } public virtual RetryWrapper.InvocationResult TryDownloadObjects( @@ -204,12 +264,38 @@ public virtual RetryWrapper.InvocationResult TryDownloadObj onSuccess, onFailure, HttpMethod.Post, + new Uri(this.CacheServer.ObjectsPostEndpointUrl), new Uri(this.CacheServer.ObjectsEndpointUrl), CancellationToken.None, objectIdsJson, preferBatchedLooseObjects ? CustomLooseObjectsHeader : null); } + public virtual RetryWrapper.InvocationResult TrySendProtocolRequest( + long requestId, + Func.CallbackResult> onSuccess, + Action.ErrorEventArgs> onFailure, + HttpMethod method, + Uri endPoint, + Uri fallbackEndPoint, + CancellationToken cancellationToken, + string requestBody = null, + MediaTypeWithQualityHeaderValue acceptType = null, + bool retryOnFailure = true) + { + return this.TrySendProtocolRequest( + requestId, + onSuccess, + onFailure, + method, + () => endPoint, + requestBodyGenerator: () => requestBody, + cancellationToken: cancellationToken, + acceptType: acceptType, + retryOnFailure: retryOnFailure, + fallbackEndPointGenerator: () => fallbackEndPoint); + } + public virtual RetryWrapper.InvocationResult TrySendProtocolRequest( long requestId, Func.CallbackResult> onSuccess, @@ -227,10 +313,11 @@ public virtual RetryWrapper.InvocationResult TrySendProtoco onFailure, method, endPoint, - cancellationToken, - () => requestBody, - acceptType, - retryOnFailure); + fallbackEndPoint: null, + cancellationToken: cancellationToken, + requestBody: requestBody, + acceptType: acceptType, + retryOnFailure: retryOnFailure); } public virtual RetryWrapper.InvocationResult TrySendProtocolRequest( @@ -250,10 +337,10 @@ public virtual RetryWrapper.InvocationResult TrySendProtoco onFailure, method, () => endPoint, - requestBodyGenerator, - cancellationToken, - acceptType, - retryOnFailure); + requestBodyGenerator: requestBodyGenerator, + cancellationToken: cancellationToken, + acceptType: acceptType, + retryOnFailure: retryOnFailure); } public virtual RetryWrapper.InvocationResult TrySendProtocolRequest( @@ -265,10 +352,16 @@ public virtual RetryWrapper.InvocationResult TrySendProtoco Func requestBodyGenerator, CancellationToken cancellationToken, MediaTypeWithQualityHeaderValue acceptType = null, - bool retryOnFailure = true) + bool retryOnFailure = true, + Func fallbackEndPointGenerator = null) { + Uri endPoint = endPointGenerator(); + Uri fallbackEndPoint = fallbackEndPointGenerator?.Invoke(); + bool hasFallbackEndPoint = fallbackEndPoint != null && endPoint != fallbackEndPoint; + bool useFallbackEndPoint = false; + RetryWrapper retrier = new RetryWrapper( - retryOnFailure ? this.RetryConfig.MaxAttempts : 1, + (retryOnFailure ? this.RetryConfig.MaxAttempts : 1) + (hasFallbackEndPoint ? 1 : 0), cancellationToken); if (onFailure != null) { @@ -278,24 +371,182 @@ public virtual RetryWrapper.InvocationResult TrySendProtoco return retrier.Invoke( tryCount => { - using (GitEndPointResponseData response = this.SendRequest( - requestId, - endPointGenerator(), - method, - requestBodyGenerator(), - cancellationToken, - acceptType)) + Uri requestEndPoint = useFallbackEndPoint ? fallbackEndPointGenerator() : endPointGenerator(); + GitEndPointResponseData response; + + try + { + response = this.SendProtocolRequest( + requestId, + requestEndPoint, + method, + requestBodyGenerator(), + cancellationToken, + acceptType); + } + catch (HttpRequestException e) + { + return this.HandleProtocolException( + requestId, + e, + requestEndPoint, + fallbackEndPoint, + hasFallbackEndPoint, + ref useFallbackEndPoint, + retryOnFailure); + } + catch (IOException e) + { + return this.HandleProtocolException( + requestId, + e, + requestEndPoint, + fallbackEndPoint, + hasFallbackEndPoint, + ref useFallbackEndPoint, + retryOnFailure); + } + catch (RetryableException e) + { + return this.HandleProtocolException( + requestId, + e, + requestEndPoint, + fallbackEndPoint, + hasFallbackEndPoint, + ref useFallbackEndPoint, + retryOnFailure); + } + + using (response) { if (response.HasErrors) { - return new RetryWrapper.CallbackResult(response.Error, response.ShouldRetry, new GitObjectTaskResult(response.StatusCode)); + bool shouldFallBack = hasFallbackEndPoint && !useFallbackEndPoint; + if (shouldFallBack) + { + this.TraceCacheServerFallback( + requestId, + requestEndPoint, + fallbackEndPoint, + "EndpointSpecific", + "Global"); + } + + useFallbackEndPoint |= shouldFallBack; + return new RetryWrapper.CallbackResult( + response.Error, + shouldFallBack || response.ShouldRetry, + new GitObjectTaskResult(response.StatusCode, requestEndPoint), + shouldRecordFailure: response.ShouldRetry && !shouldFallBack); } - return onSuccess(tryCount, response); + RetryWrapper.CallbackResult result; + try + { + result = onSuccess(tryCount, response); + } + catch (Exception e) + { + if (response.StreamReadFailed) + { + return this.HandleProtocolException( + requestId, + e, + requestEndPoint, + fallbackEndPoint, + hasFallbackEndPoint, + ref useFallbackEndPoint, + retryOnFailure); + } + + throw; + } + + if (result.HasErrors) + { + bool shouldFallBack = response.StreamReadFailed && hasFallbackEndPoint && !useFallbackEndPoint; + if (shouldFallBack) + { + this.TraceCacheServerFallback( + requestId, + requestEndPoint, + fallbackEndPoint, + "EndpointSpecific", + "Global"); + useFallbackEndPoint = true; + } + + GitObjectTaskResult requestResult = result.Result == null + ? new GitObjectTaskResult(success: false, requestEndPoint) + : result.Result.WithRequestUri(requestEndPoint); + return new RetryWrapper.CallbackResult( + result.Error, + shouldFallBack || result.ShouldRetry, + requestResult, + shouldRecordFailure: result.ShouldRecordFailure && !shouldFallBack); + } + + return result; } }); } + private RetryWrapper.CallbackResult HandleProtocolException( + long requestId, + Exception error, + Uri requestEndPoint, + Uri fallbackEndPoint, + bool hasFallbackEndPoint, + ref bool useFallbackEndPoint, + bool retryOnFailure) + { + bool shouldFallBack = hasFallbackEndPoint && !useFallbackEndPoint; + if (shouldFallBack) + { + this.TraceCacheServerFallback( + requestId, + requestEndPoint, + fallbackEndPoint, + "EndpointSpecific", + "Global"); + useFallbackEndPoint = true; + } + + return new RetryWrapper.CallbackResult( + error, + shouldFallBack || retryOnFailure, + new GitObjectTaskResult(success: false, requestEndPoint), + shouldRecordFailure: retryOnFailure && !shouldFallBack); + } + + private void TraceCacheServerFallback( + long requestId, + Uri source, + Uri target, + string sourceRoute, + string targetRoute) + { + EventMetadata metadata = new EventMetadata(); + metadata.Add("RequestId", requestId); + metadata.Add("SourceRoute", sourceRoute); + metadata.Add("SourceAuthority", GetAuthorityForTelemetry(source)); + metadata.Add("TargetRoute", targetRoute); + metadata.Add("TargetAuthority", GetAuthorityForTelemetry(target)); + this.Tracer.RelatedEvent(EventLevel.Informational, "CacheServerFallback", metadata, Keywords.Network | Keywords.Telemetry); + } + + protected virtual GitEndPointResponseData SendProtocolRequest( + long requestId, + Uri requestUri, + HttpMethod httpMethod, + string requestContent, + CancellationToken cancellationToken, + MediaTypeWithQualityHeaderValue acceptType = null) + { + return this.SendRequest(requestId, requestUri, httpMethod, requestContent, cancellationToken, acceptType); + } + private static string ToJsonList(IEnumerable strings) { return "[\"" + string.Join("\",\"", strings) + "\"]"; @@ -356,19 +607,29 @@ public GitObjectSize(string id, long size) public class GitObjectTaskResult { - public GitObjectTaskResult(bool success) + public GitObjectTaskResult(bool success, Uri requestUri = null) { this.Success = success; + this.RequestUri = requestUri; } - public GitObjectTaskResult(HttpStatusCode statusCode) - : this(statusCode == HttpStatusCode.OK) + public GitObjectTaskResult(HttpStatusCode statusCode, Uri requestUri = null) + : this(statusCode == HttpStatusCode.OK, requestUri) { this.HttpStatusCodeResult = statusCode; } public bool Success { get; } - public HttpStatusCode HttpStatusCodeResult { get; } + public HttpStatusCode HttpStatusCodeResult { get; private set; } + public Uri RequestUri { get; } + + public GitObjectTaskResult WithRequestUri(Uri requestUri) + { + return new GitObjectTaskResult(this.Success, requestUri) + { + HttpStatusCodeResult = this.HttpStatusCodeResult, + }; + } } } } \ No newline at end of file diff --git a/GVFS/GVFS.Common/Http/HttpRequestor.cs b/GVFS/GVFS.Common/Http/HttpRequestor.cs index 0f9767dde1..ee1558abf2 100644 --- a/GVFS/GVFS.Common/Http/HttpRequestor.cs +++ b/GVFS/GVFS.Common/Http/HttpRequestor.cs @@ -232,7 +232,7 @@ protected GitEndPointResponseData SendRequest( 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 (ShouldRejectCredentials(response.StatusCode, errorMessage)) { this.authentication.RejectCredentials(this.Tracer, authString); if (!this.authentication.IsBackingOff) @@ -312,11 +312,11 @@ protected GitEndPointResponseData SendRequest( } private static bool ShouldRetry(HttpStatusCode statusCode) - { + { // Retry timeout, Unauthorized, 429 (Too Many Requests), and 5xx errors int statusInt = (int)statusCode; if (statusCode == HttpStatusCode.RequestTimeout || - statusCode == HttpStatusCode.Unauthorized || + statusCode == HttpStatusCode.Unauthorized || statusInt == 429 || (statusInt >= 500 && statusInt < 600)) { @@ -326,6 +326,63 @@ private static bool ShouldRetry(HttpStatusCode statusCode) return false; } + /// + /// The message the Azure DevOps GVFS cache server returns in a 400 (Bad Request) + /// body when the request carried no parseable Basic Authorization header - i.e. + /// the one 400 that genuinely means "authentication required". + /// + /// + /// Mirrors the cache server's own message, emitted by + /// GvfsHttpHandler.PrepareContextAsync as + /// $"A valid {scheme} {header} header is required." with scheme="Basic" and + /// header="Authorization". Kept as a literal (not a format) so a substring match + /// stays robust if the server text is wrapped or prefixed. + /// + internal const string CacheServerAuthRequiredBadRequestMessage = "A valid Basic Authorization header is required."; + + /// + /// Determines whether an HTTP response indicates an authentication failure + /// that warrants rejecting (erasing) the stored credential. + /// + /// + /// 401 (Unauthorized) and 302 (Redirect to the Azure DevOps sign-in page) are + /// always genuine authentication failures. A 400 (Bad Request) is usually NOT an + /// auth failure - a present-but-expired/invalid credential returns 401, and a + /// malformed request (e.g. a corrupt object SHA in the loose-object URL) returns a + /// 400 that has nothing to do with credentials. Rejecting credentials on every 400 + /// erased valid credentials and caused a storm of credential-manager popups. + /// + /// The one exception: the GVFS cache server returns a 400 (instead of a 401) when + /// the request carried no parseable Basic Authorization header. That single 400 is + /// genuinely "authentication required", and microsoft/git's git-gvfs-helper maps it + /// to a 401 for the same reason (its normalize step notes the cache server "sends a + /// somewhat bogus 400 instead of the normal 401 when AUTH is required", and its TODO + /// asks to confirm the response body - which is exactly what we do here). We only + /// treat a 400 as an auth failure when the body matches that specific message. + /// + internal static bool ShouldRejectCredentials(HttpStatusCode statusCode, string responseBody) + { + if (statusCode == HttpStatusCode.Unauthorized || + statusCode == HttpStatusCode.Redirect) + { + return true; + } + + if (statusCode == HttpStatusCode.BadRequest && + responseBody != null && + responseBody.IndexOf(CacheServerAuthRequiredBadRequestMessage, StringComparison.OrdinalIgnoreCase) >= 0) + { + return true; + } + + return false; + } + + internal static string GetAuthorityForTelemetry(Uri uri) + { + return uri.Authority; + } + private static string GetSingleHeaderOrEmpty(HttpHeaders headers, string headerName) { IEnumerable values; diff --git a/GVFS/GVFS.Common/Maintenance/GitMaintenanceScheduler.cs b/GVFS/GVFS.Common/Maintenance/GitMaintenanceScheduler.cs index 760f803291..2759306ff5 100644 --- a/GVFS/GVFS.Common/Maintenance/GitMaintenanceScheduler.cs +++ b/GVFS/GVFS.Common/Maintenance/GitMaintenanceScheduler.cs @@ -54,7 +54,9 @@ private void ScheduleRecurringSteps() return; } - if (this.gitObjects.IsUsingCacheServer()) + bool usingCacheServer = this.gitObjects.IsUsingCacheServer(); + + if (usingCacheServer) { TimeSpan prefetchPeriod = TimeSpan.FromMinutes(15); this.stepTimers.Add(new Timer( @@ -70,8 +72,16 @@ private void ScheduleRecurringSteps() dueTime: this.looseObjectsDueTime, period: this.looseObjectsPeriod)); + // When packfile-maintenance recovery removes a corrupt prefetch pack (and the later prefetch + // packs that depend on it), it needs a prefetch to re-download them and rebuild the + // commit-graph. This is only meaningful when a cache server is in use; otherwise the objects + // are restored on demand. + Action requestPrefetch = usingCacheServer + ? () => this.queue.TryEnqueue(new PrefetchStep(this.context, this.gitObjects)) + : (Action)null; + this.stepTimers.Add(new Timer( - (state) => this.queue.TryEnqueue(new PackfileMaintenanceStep(this.context)), + (state) => this.queue.TryEnqueue(new PackfileMaintenanceStep(this.context, requestPrefetch: requestPrefetch)), state: null, dueTime: this.packfileDueTime, period: this.packfilePeriod)); diff --git a/GVFS/GVFS.Common/Maintenance/PackfileMaintenanceStep.cs b/GVFS/GVFS.Common/Maintenance/PackfileMaintenanceStep.cs index a5fc5b54a6..e51f11a2a8 100644 --- a/GVFS/GVFS.Common/Maintenance/PackfileMaintenanceStep.cs +++ b/GVFS/GVFS.Common/Maintenance/PackfileMaintenanceStep.cs @@ -5,6 +5,7 @@ using System.Collections.Generic; using System.IO; using System.Linq; +using System.Text.RegularExpressions; namespace GVFS.Common.Maintenance { @@ -27,21 +28,30 @@ namespace GVFS.Common.Maintenance public class PackfileMaintenanceStep : GitMaintenanceStep { public const string PackfileLastRunFileName = "pack-maintenance.time"; - public const string DefaultBatchSize = "2g"; + public const string DefaultBatchSize = "2g"; private const string MultiPackIndexLock = "multi-pack-index.lock"; private readonly bool forceRun; private readonly string batchSize; + private readonly Action requestPrefetch; + + // Set once corrupt packs have been detected and reported with recovery disabled. Recovery leaves + // the corrupt packs in place, so 'git multi-pack-index write/verify' keeps failing on them for + // the rest of this maintenance run - once reported, skip re-verifying every pack on each + // subsequent failure in the same run rather than repeating an identical, already-known result. + private bool reportedCorruptPacksWithRecoveryDisabled; public PackfileMaintenanceStep( GVFSContext context, bool requireObjectCacheLock = true, bool forceRun = false, string batchSize = DefaultBatchSize, - GitProcessChecker gitProcessChecker = null) + GitProcessChecker gitProcessChecker = null, + Action requestPrefetch = null) : base(context, requireObjectCacheLock, gitProcessChecker) { this.forceRun = forceRun; this.batchSize = batchSize; + this.requestPrefetch = requestPrefetch; } public override string Area => nameof(PackfileMaintenanceStep); @@ -116,41 +126,54 @@ protected override void PerformMaintenance() return; } - string multiPackIndexLockPath = Path.Combine(this.Context.Enlistment.GitPackRoot, MultiPackIndexLock); - this.Context.FileSystem.TryDeleteFile(multiPackIndexLockPath); - - this.RunGitCommand((process) => process.WriteMultiPackIndex(this.Context.Enlistment.GitObjectsRoot), nameof(GitProcess.WriteMultiPackIndex)); - - // If a LibGit2Repo is active, then it may hold handles to the .idx and .pack files we want - // to delete during the 'git multi-pack-index expire' step. If one starts during the step, - // then it can still block those deletions, but we will clean them up in the next run. By - // running CloseActiveRepos() here, we ensure that we do not run twice with the same - // LibGit2Repo active across two calls. A "new" repo should not hold handles to .idx files - // that do not have corresponding .pack files, so we will clean them up in CleanStaleIdxFiles(). - this.Context.Repository.CloseActiveRepo(); - - GitProcess.Result expireResult = this.RunGitCommand((process) => process.MultiPackIndexExpire(this.Context.Enlistment.GitObjectsRoot), nameof(GitProcess.MultiPackIndexExpire)); - - this.Context.Repository.OpenRepo(); - + string multiPackIndexLockPath = Path.Combine(this.Context.Enlistment.GitPackRoot, MultiPackIndexLock); + this.Context.FileSystem.TryDeleteFile(multiPackIndexLockPath); + + // Read the recovery kill switch while the repo is open. When disabled, we still detect and + // report corrupt packs but do not delete anything. + bool recoveryEnabled = this.IsPackfileRecoveryEnabled(); + + // A corrupt or truncated packfile in the shared object cache (e.g. introduced by a + // disk-full event) makes 'git multi-pack-index write' fail with "could not load pack N". + // The existing self-heal only ran after a later verify failed - but the write is first, + // so recover on the write path too rather than pressing on with a broken cache. + GitProcess.Result writeResult = this.RunGitCommand((process) => process.WriteMultiPackIndex(this.Context.Enlistment.GitObjectsRoot), nameof(GitProcess.WriteMultiPackIndex)); + + if (!this.Stopping && writeResult.ExitCodeIsFailure) + { + this.RepairMultiPackIndex(activity, writeResult, recoveryEnabled); + } + + // If a LibGit2Repo is active, then it may hold handles to the .idx and .pack files we want + // to delete during the 'git multi-pack-index expire' step. If one starts during the step, + // then it can still block those deletions, but we will clean them up in the next run. By + // running CloseActiveRepos() here, we ensure that we do not run twice with the same + // LibGit2Repo active across two calls. A "new" repo should not hold handles to .idx files + // that do not have corresponding .pack files, so we will clean them up in CleanStaleIdxFiles(). + this.Context.Repository.CloseActiveRepo(); + + GitProcess.Result expireResult = this.RunGitCommand((process) => process.MultiPackIndexExpire(this.Context.Enlistment.GitObjectsRoot), nameof(GitProcess.MultiPackIndexExpire)); + + this.Context.Repository.OpenRepo(); + List staleIdxFiles = this.CleanStaleIdxFiles(out int numDeletionBlocked); - this.GetPackFilesInfo(out int expireCount, out long expireSize, out hasKeep); - + this.GetPackFilesInfo(out int expireCount, out long expireSize, out hasKeep); + GitProcess.Result verifyAfterExpire = this.RunGitCommand((process) => process.VerifyMultiPackIndex(this.Context.Enlistment.GitObjectsRoot), nameof(GitProcess.VerifyMultiPackIndex)); - if (!this.Stopping && verifyAfterExpire.ExitCodeIsFailure) - { - this.LogErrorAndRewriteMultiPackIndex(activity); + if (!this.Stopping && verifyAfterExpire.ExitCodeIsFailure) + { + this.RepairMultiPackIndex(activity, verifyAfterExpire, recoveryEnabled); } GitProcess.Result repackResult = this.RunGitCommand((process) => process.MultiPackIndexRepack(this.Context.Enlistment.GitObjectsRoot, this.batchSize), nameof(GitProcess.MultiPackIndexRepack)); - this.GetPackFilesInfo(out int afterCount, out long afterSize, out hasKeep); - - GitProcess.Result verifyAfterRepack = this.RunGitCommand((process) => process.VerifyMultiPackIndex(this.Context.Enlistment.GitObjectsRoot), nameof(GitProcess.VerifyMultiPackIndex)); + this.GetPackFilesInfo(out int afterCount, out long afterSize, out hasKeep); - if (!this.Stopping && verifyAfterRepack.ExitCodeIsFailure) - { - this.LogErrorAndRewriteMultiPackIndex(activity); + GitProcess.Result verifyAfterRepack = this.RunGitCommand((process) => process.VerifyMultiPackIndex(this.Context.Enlistment.GitObjectsRoot), nameof(GitProcess.VerifyMultiPackIndex)); + + if (!this.Stopping && verifyAfterRepack.ExitCodeIsFailure) + { + this.RepairMultiPackIndex(activity, verifyAfterRepack, recoveryEnabled); } EventMetadata metadata = new EventMetadata(); @@ -171,5 +194,392 @@ protected override void PerformMaintenance() this.SaveLastRunTimeToFile(); } } + + /// + /// Reads the gvfs.enable-packfile-recovery kill switch. Virtual so unit tests can + /// override it; the LibGit2 invoker is null in tests, in which case recovery defaults to enabled. + /// + protected virtual bool IsPackfileRecoveryEnabled() + { + LibGit2RepoInvoker repoInvoker = this.Context.Repository.LibGit2RepoInvoker; + if (repoInvoker == null) + { + return GVFSConstants.GitConfig.EnablePackfileRecoveryDefault; + } + + return repoInvoker.GetConfigBoolOrDefault( + GVFSConstants.GitConfig.EnablePackfileRecovery, + GVFSConstants.GitConfig.EnablePackfileRecoveryDefault); + } + + private static bool ResultIndicatesCorruptPack(GitProcess.Result result) { + string errors = result?.Errors; + if (string.IsNullOrEmpty(errors)) + { + return false; + } + + // 'git multi-pack-index write/verify' reports an unreadable underlying packfile with + // messages like "could not load pack N" or "failed to load pack in position N". Both mean + // a packfile - not just the multi-pack-index - is corrupt. + return errors.IndexOf("could not load pack", StringComparison.OrdinalIgnoreCase) >= 0 + || errors.IndexOf("failed to load pack", StringComparison.OrdinalIgnoreCase) >= 0; + } + + /// + /// Returns the prefetch timestamp encoded in a prefetch pack file name + /// (prefetch-<timestamp>-<uniqueId>.pack), or null if the file is not a prefetch pack. + /// + private static long? GetPrefetchTimestamp(string packFileName) + { + if (!packFileName.StartsWith(GVFSConstants.PrefetchPackPrefix, StringComparison.OrdinalIgnoreCase)) + { + return null; + } + + string[] parts = packFileName.Split('-'); + if (parts.Length > 1 && long.TryParse(parts[1], out long timestamp)) + { + return timestamp; + } + + return null; + } + + /// + /// Recovers from a failed multi-pack-index write or verify. When git reports it could not load a + /// pack, a packfile itself is corrupt (e.g. truncated by a past disk-full event) and regenerating + /// the multi-pack-index (MIDX) alone keeps failing because the rewrite re-scans the same bad pack. + /// Detect the corrupt pack(s) - and, when recovery is enabled, remove them - then delete and + /// regenerate the MIDX from the packs that remain (fast path, no full repack). + /// + private void RepairMultiPackIndex(ITracer activity, GitProcess.Result failure, bool recoveryEnabled) + { + bool prefetchRestoreNeeded = false; + + if (!this.Stopping && ResultIndicatesCorruptPack(failure)) + { + this.DetectAndRemoveCorruptPacks(activity, recoveryEnabled, out prefetchRestoreNeeded, failure.Errors); + } + + // Delete the (now stale) multi-pack-index and rebuild it from the packs that remain. This is + // non-destructive and runs regardless of the recovery kill switch. + this.LogErrorAndRewriteMultiPackIndex(activity); + + if (prefetchRestoreNeeded && !this.Stopping) + { + this.RequestPrefetchRestore(activity); + } + } + + /// + /// Verifies each packfile in the object cache with 'git verify-pack' and reports every unreadable + /// pack via telemetry (this detection runs even when recovery is disabled). When + /// is true, also removes each corrupt pack's files + /// (.pack/.idx/.keep/.rev). A corrupt prefetch pack additionally forces removal of every + /// later (higher-timestamp) prefetch pack and sets , + /// because prefetch packs are incremental - leaving a hole would let the newest surviving + /// timestamp advance past it so a later prefetch never backfills the gap. + /// + // public only for unit tests + public void DetectAndRemoveCorruptPacks(ITracer activity, bool recoveryEnabled, out bool prefetchRestoreNeeded, string failureErrors = null) + { + prefetchRestoreNeeded = false; + + if (!recoveryEnabled && this.reportedCorruptPacksWithRecoveryDisabled) + { + // Already verified every pack and reported the corrupt ones earlier in this maintenance + // run. Recovery is disabled, so nothing has changed on disk - skip the redundant rescan. + return; + } + + List packDirContents = this.Context + .FileSystem + .ItemsInDirectory(this.Context.Enlistment.GitPackRoot) + .ToList(); + + // Phase 1 - detection (read-only, always runs). git's own 'multi-pack-index verify' failure + // text usually already names the specific unreadable pack (e.g. "packfile pack-1234.pack does + // not match index"), so try verifying just those named packs first - much faster than + // verify-pack'ing every pack in the object cache. Fall back to the full scan whenever no + // candidate can be parsed, or when every candidate turns out to verify successfully (the + // write/verify failure that got us here must then be explained by some other pack). + HashSet candidateIdxPaths = this.ExtractCandidateCorruptIdxPaths(failureErrors); + List idxItemsToVerify = candidateIdxPaths.Count > 0 + ? packDirContents.Where(info => candidateIdxPaths.Contains(info.FullName)).ToList() + : packDirContents; + + long? minCorruptPrefetchTimestamp; + List corruptNonPrefetchIdxPaths; + HashSet corruptIdxPaths = this.VerifyPacksAndReportCorruption( + activity, + recoveryEnabled, + idxItemsToVerify, + out corruptNonPrefetchIdxPaths, + out minCorruptPrefetchTimestamp); + + if (this.Stopping) + { + return; + } + + if (corruptIdxPaths.Count == 0 && idxItemsToVerify != packDirContents) + { + // The candidate(s) parsed from the failure text turned out to be healthy - fall back to + // verifying every pack so a real corruption elsewhere is not missed. + corruptIdxPaths = this.VerifyPacksAndReportCorruption( + activity, + recoveryEnabled, + packDirContents, + out corruptNonPrefetchIdxPaths, + out minCorruptPrefetchTimestamp); + + if (this.Stopping) + { + return; + } + } + + if (corruptIdxPaths.Count == 0) + { + return; + } + + if (!recoveryEnabled) + { + EventMetadata skippedMetadata = this.CreateEventMetadata(); + skippedMetadata["Operation"] = "CorruptPackRecoverySkipped"; + skippedMetadata["CorruptPackCount"] = corruptIdxPaths.Count; + activity.RelatedWarning( + skippedMetadata, + $"Found {corruptIdxPaths.Count} corrupt packfile(s) but {GVFSConstants.GitConfig.EnablePackfileRecovery} is disabled; leaving packs in place.", + Keywords.Telemetry); + this.reportedCorruptPacksWithRecoveryDisabled = true; + return; + } + + // Phase 2 - deletion (gated). Build the set of prefetch packs to remove: the corrupt one and + // every later (>= timestamp) prefetch pack, whether or not those later packs are themselves + // corrupt, because prefetch packs are incremental. + List laterPrefetchIdxPaths = new List(); + if (minCorruptPrefetchTimestamp.HasValue) + { + foreach (DirectoryItemInfo info in packDirContents) + { + if (!string.Equals(Path.GetExtension(info.Name), ".pack", GVFSPlatform.Instance.Constants.PathComparison)) + { + continue; + } + + long? prefetchTimestamp = GetPrefetchTimestamp(info.Name); + if (prefetchTimestamp.HasValue && prefetchTimestamp.Value >= minCorruptPrefetchTimestamp.Value) + { + laterPrefetchIdxPaths.Add(Path.ChangeExtension(info.FullName, ".idx")); + } + } + } + + // Only request a prefetch restore once a corrupt prefetch pack is actually removed. If + // deletion is blocked (e.g. a handle is still open), the corrupt pack is still present, so + // running the restore now would just re-download around a cache that is still broken. + bool corruptPrefetchPackRemoved = false; + + // Close the LibGit2 repo so the .idx files can be deleted, then remove each pack set. + this.Context.Repository.CloseActiveRepo(); + try + { + foreach (string idxPath in corruptNonPrefetchIdxPaths) + { + if (this.Stopping) + { + return; + } + + this.RemovePackFileSet(activity, idxPath, "DeletedCorruptPack", $"Deleted corrupt packfile {Path.GetFileName(Path.ChangeExtension(idxPath, ".pack"))} during pack maintenance recovery."); + } + + foreach (string idxPath in laterPrefetchIdxPaths) + { + if (this.Stopping) + { + return; + } + + if (corruptIdxPaths.Contains(idxPath)) + { + bool removed = this.RemovePackFileSet(activity, idxPath, "DeletedCorruptPack", $"Deleted corrupt prefetch packfile {Path.GetFileName(Path.ChangeExtension(idxPath, ".pack"))} during pack maintenance recovery."); + corruptPrefetchPackRemoved = corruptPrefetchPackRemoved || removed; + } + else + { + this.RemovePackFileSet(activity, idxPath, "DeletedHealthyPrefetchPack", $"Deleted healthy prefetch packfile {Path.GetFileName(Path.ChangeExtension(idxPath, ".pack"))} because an earlier prefetch pack was corrupt; incremental prefetch packs after the corruption must be removed and re-fetched."); + } + } + } + finally + { + this.Context.Repository.OpenRepo(); + } + + prefetchRestoreNeeded = corruptPrefetchPackRemoved; + } + + /// + /// Matches pack/idx file names (e.g. "pack-<hash>.pack", "prefetch-123-abc.idx") as they + /// appear embedded in git's own error text - see packfile.c's "packfile %s does not match + /// index" / "packfile %s index unavailable" and "wrong index v2 file size in %s" messages. Pack + /// file names only ever contain word characters, hyphens, and dots, so this is precise and won't + /// pick up unrelated substrings. + /// + private static readonly Regex CorruptPackFileNamePattern = new Regex(@"[\w\-]+\.(?:pack|idx)", RegexOptions.Compiled); + + /// + /// Parses candidate corrupt pack file names directly out of a 'multi-pack-index write/verify' + /// failure's stderr, returning their .idx paths under . + /// Git's own error text usually already names the specific unreadable packfile, so this lets the + /// caller skip a full verify-pack scan of every pack in the object cache. Only paths that + /// actually exist on disk are returned, since the parsed text could (rarely) reference a pack + /// from a different object-dir or a message format this pattern doesn't recognize (e.g. the + /// ordinal-only "could not load pack N" from the write path, which names no file at all). + /// + private HashSet ExtractCandidateCorruptIdxPaths(string failureErrors) + { + HashSet idxPaths = new HashSet(GVFSPlatform.Instance.Constants.PathComparer); + if (string.IsNullOrEmpty(failureErrors)) + { + return idxPaths; + } + + string packRoot = this.Context.Enlistment.GitPackRoot; + foreach (Match match in CorruptPackFileNamePattern.Matches(failureErrors)) + { + string idxFileName = Path.GetFileNameWithoutExtension(match.Value) + ".idx"; + string idxPath = Path.Combine(packRoot, idxFileName); + if (this.Context.FileSystem.FileExists(idxPath)) + { + idxPaths.Add(idxPath); + } + } + + return idxPaths; + } + + /// + /// Runs 'git verify-pack' against each .idx in that has a + /// matching .pack on disk, and reports (via telemetry) every one that fails to verify. verify-pack + /// is an external git process, so it is safe to run with the LibGit2 repo open. + /// + private HashSet VerifyPacksAndReportCorruption( + ITracer activity, + bool recoveryEnabled, + List idxItemsToVerify, + out List corruptNonPrefetchIdxPaths, + out long? minCorruptPrefetchTimestamp) + { + minCorruptPrefetchTimestamp = null; + corruptNonPrefetchIdxPaths = new List(); + HashSet corruptIdxPaths = new HashSet(GVFSPlatform.Instance.Constants.PathComparer); + + foreach (DirectoryItemInfo info in idxItemsToVerify) + { + if (this.Stopping) + { + return corruptIdxPaths; + } + + if (!string.Equals(Path.GetExtension(info.Name), ".idx", GVFSPlatform.Instance.Constants.PathComparison)) + { + continue; + } + + string idxPath = info.FullName; + string packPath = Path.ChangeExtension(idxPath, ".pack"); + + // A dangling .idx with no matching .pack is handled by CleanStaleIdxFiles; here we only + // care about packs that exist on disk but cannot be read. + if (!this.Context.FileSystem.FileExists(packPath)) + { + continue; + } + + GitProcess.Result verifyPackResult = this.RunGitCommand((process) => process.VerifyPack(idxPath), nameof(GitProcess.VerifyPack)); + + if (this.Stopping) + { + return corruptIdxPaths; + } + + if (verifyPackResult.ExitCodeIsSuccess) + { + continue; + } + + long? prefetchTimestamp = GetPrefetchTimestamp(info.Name); + bool isPrefetchPack = prefetchTimestamp.HasValue; + corruptIdxPaths.Add(idxPath); + + EventMetadata foundMetadata = this.CreateEventMetadata(); + foundMetadata["Operation"] = "FoundCorruptPack"; + foundMetadata["Pack"] = info.Name; + foundMetadata["IsPrefetchPack"] = isPrefetchPack; + foundMetadata["RecoveryEnabled"] = recoveryEnabled; + activity.RelatedWarning(foundMetadata, $"Found corrupt packfile {info.Name} during pack maintenance.", Keywords.Telemetry); + + if (isPrefetchPack) + { + if (!minCorruptPrefetchTimestamp.HasValue || prefetchTimestamp.Value < minCorruptPrefetchTimestamp.Value) + { + minCorruptPrefetchTimestamp = prefetchTimestamp.Value; + } + } + else + { + corruptNonPrefetchIdxPaths.Add(idxPath); + } + } + + return corruptIdxPaths; + } + + /// + /// True if the packfile itself was deleted. The .pack file is what actually contains the corrupt + /// (or, for a later prefetch pack, stale) data, so its deletion result - not the sidecar + /// .idx/.keep/.rev files - is what determines whether recovery for this pack set succeeded. + /// + private bool RemovePackFileSet(ITracer activity, string idxPath, string operation, string message) + { + string packPath = Path.ChangeExtension(idxPath, ".pack"); + bool packDeleted = this.Context.FileSystem.TryDeleteFile(packPath); + + EventMetadata metadata = this.CreateEventMetadata(); + metadata["Operation"] = operation; + metadata["Pack"] = Path.GetFileName(packPath); + metadata["DeletePackResult"] = packDeleted; + metadata["DeleteIdxResult"] = this.Context.FileSystem.TryDeleteFile(idxPath); + metadata["DeleteKeepResult"] = this.Context.FileSystem.TryDeleteFile(Path.ChangeExtension(idxPath, ".keep")); + metadata["DeleteRevResult"] = this.Context.FileSystem.TryDeleteFile(Path.ChangeExtension(idxPath, ".rev")); + activity.RelatedWarning(metadata, message, Keywords.Telemetry); + + return packDeleted; + } + + private void RequestPrefetchRestore(ITracer activity) + { + if (this.requestPrefetch == null) + { + // No prefetch is available (e.g. not using a cache server). The removed prefetch packs' + // objects will be re-fetched on demand through normal virtualization. + EventMetadata metadata = this.CreateEventMetadata(); + metadata["Operation"] = "PrefetchRestoreUnavailable"; + activity.RelatedWarning( + metadata, + "Removed prefetch pack(s) but no prefetch restore is available. Missing objects will be re-fetched on demand.", + Keywords.Telemetry); + return; + } + + activity.RelatedInfo("Requesting a prefetch to restore removed prefetch packs and rebuild the commit-graph."); + this.requestPrefetch(); + } } } diff --git a/GVFS/GVFS.Common/RetryWrapper.cs b/GVFS/GVFS.Common/RetryWrapper.cs index 4d6a0ccd84..4d56ccc1fa 100644 --- a/GVFS/GVFS.Common/RetryWrapper.cs +++ b/GVFS/GVFS.Common/RetryWrapper.cs @@ -88,7 +88,7 @@ public InvocationResult Invoke(Func toInvoke) CallbackResult result = toInvoke(tryCount); if (result.HasErrors) { - if (result.ShouldRetry) + if (result.ShouldRecordFailure) { RetryCircuitBreaker.RecordFailure(); } @@ -224,6 +224,7 @@ public CallbackResult(Exception error, bool shouldRetry) this.HasErrors = true; this.Error = error; this.ShouldRetry = shouldRetry; + this.ShouldRecordFailure = shouldRetry; } public CallbackResult(Exception error, bool shouldRetry, T result) @@ -232,9 +233,16 @@ public CallbackResult(Exception error, bool shouldRetry, T result) this.Result = result; } + public CallbackResult(Exception error, bool shouldRetry, T result, bool shouldRecordFailure) + : this(error, shouldRetry, result) + { + this.ShouldRecordFailure = shouldRecordFailure; + } + public bool HasErrors { get; } public Exception Error { get; } public bool ShouldRetry { get; } + public bool ShouldRecordFailure { get; } public T Result { get; } } } diff --git a/GVFS/GVFS.FunctionalTests/Tests/TestResultsHelper.cs b/GVFS/GVFS.FunctionalTests/Tests/TestResultsHelper.cs index e70adca78d..3c197a1ecd 100644 --- a/GVFS/GVFS.FunctionalTests/Tests/TestResultsHelper.cs +++ b/GVFS/GVFS.FunctionalTests/Tests/TestResultsHelper.cs @@ -69,5 +69,88 @@ public static IEnumerable GetAllFilesInDirectory(string folderName) return directory.GetFiles().Select(file => file.FullName); } + + /// + /// Root directory under which per-failure diagnostics (preserved logs and + /// mount process dumps) are written so CI can upload them as an artifact. + /// Honors the GVFS_TEST_DIAGNOSTICS_DIR environment variable; otherwise + /// falls back to a folder under the temp path. + /// + public static string DiagnosticsRoot + { + get + { + string configured = Environment.GetEnvironmentVariable("GVFS_TEST_DIAGNOSTICS_DIR"); + return string.IsNullOrWhiteSpace(configured) + ? Path.Combine(Path.GetTempPath(), "gvfs_ft_diagnostics") + : configured; + } + } + + /// + /// Copies every file in into + /// . A mount that hung or exited + /// abnormally may still hold its log file open, so a plain copy can fail + /// with a sharing violation. In that case we fall back to opening the file + /// with a read-only shared handle (FileShare.ReadWrite | Delete) and copy + /// out whatever has been flushed so far — partial content is still useful. + /// Best-effort: never throws. + /// + public static void CopyFilesWithFallback(string sourceFolder, string destinationFolder) + { + try + { + Directory.CreateDirectory(destinationFolder); + } + catch (Exception ex) + { + Console.Error.WriteLine($"[DIAGNOSTICS] Unable to create '{destinationFolder}': {ex.Message}"); + return; + } + + foreach (string sourceFile in GetAllFilesInDirectory(sourceFolder)) + { + string destinationFile = Path.Combine(destinationFolder, Path.GetFileName(sourceFile)); + + try + { + File.Copy(sourceFile, destinationFile, overwrite: true); + } + catch (Exception copyException) when (copyException is IOException || copyException is UnauthorizedAccessException) + { + // The file is likely locked by a still-running (possibly hung) + // mount process. Fall back to a shared read-only handle and copy + // what we can. + if (!TryCopyWithSharedReadHandle(sourceFile, destinationFile)) + { + Console.Error.WriteLine($"[DIAGNOSTICS] Failed to copy '{sourceFile}' (locked): {copyException.Message}"); + } + } + catch (Exception ex) + { + Console.Error.WriteLine($"[DIAGNOSTICS] Failed to copy '{sourceFile}': {ex.Message}"); + } + } + } + + private static bool TryCopyWithSharedReadHandle(string sourceFile, string destinationFile) + { + try + { + using (FileStream source = new FileStream(sourceFile, FileMode.Open, FileAccess.Read, FileShare.ReadWrite | FileShare.Delete)) + using (FileStream destination = new FileStream(destinationFile, FileMode.Create, FileAccess.Write, FileShare.None)) + { + source.CopyTo(destination); + } + + Console.Error.WriteLine($"[DIAGNOSTICS] Copied '{sourceFile}' via shared read handle (may be partial)"); + return true; + } + catch (Exception ex) + { + Console.Error.WriteLine($"[DIAGNOSTICS] Shared-handle copy of '{sourceFile}' failed: {ex.Message}"); + return false; + } + } } } diff --git a/GVFS/GVFS.FunctionalTests/Tools/ControlGitRepo.cs b/GVFS/GVFS.FunctionalTests/Tools/ControlGitRepo.cs index 807c09efdc..11e1d972d6 100644 --- a/GVFS/GVFS.FunctionalTests/Tools/ControlGitRepo.cs +++ b/GVFS/GVFS.FunctionalTests/Tools/ControlGitRepo.cs @@ -1,20 +1,18 @@ -using System; +using System; using System.IO; +using System.Threading; namespace GVFS.FunctionalTests.Tools { public class ControlGitRepo { + // Serializes creation and refresh of the machine-global shared cache across every + // functional-test process running on this machine. + private const string CacheMutexName = @"Global\GVFS.FunctionalTests.ControlGitRepoCache"; + static ControlGitRepo() { - if (!Directory.Exists(CachePath)) - { - GitProcess.Invoke(Environment.SystemDirectory, "clone " + GVFSTestConfig.RepoToClone + " " + CachePath + " --bare"); - } - else - { - GitProcess.Invoke(CachePath, "fetch origin +refs/*:refs/*"); - } + EnsureSharedCache(); } private ControlGitRepo(string repoUrl, string rootPath, string commitish) @@ -46,6 +44,28 @@ public static ControlGitRepo Create(string commitish = null) // IMPORTANT! These must parallel the settings in GVFSVerb:TrySetRequiredGitConfigSettings // public void Initialize() + { + const int MaxAttempts = 3; + for (int attempt = 1; attempt <= MaxAttempts; attempt++) + { + try + { + this.InitializeCore(); + return; + } + catch (Exception ex) when (attempt < MaxAttempts) + { + // Building the control repo hit a transient failure (for example the shared + // cache was being rebuilt by another process). Discard the partial repo and + // retry from a clean directory. + Console.WriteLine($"ControlGitRepo.Initialize attempt {attempt} of {MaxAttempts} failed: {ex.Message}"); + RepositoryHelpers.DeleteTestDirectory(this.RootPath); + Thread.Sleep(TimeSpan.FromSeconds(attempt)); + } + } + } + + private void InitializeCore() { Directory.CreateDirectory(this.RootPath); GitProcess.Invoke(this.RootPath, "init"); @@ -57,6 +77,7 @@ public void Initialize() GitProcess.Invoke(this.RootPath, "config core.abbrev 40"); GitProcess.Invoke(this.RootPath, "config checkout.workers 0"); GitProcess.Invoke(this.RootPath, "config core.useBuiltinFSMonitor false"); + GitProcess.Invoke(this.RootPath, "config core.fsmonitor false"); GitProcess.Invoke(this.RootPath, "config pack.useSparse true"); GitProcess.Invoke(this.RootPath, "config reset.quiet true"); GitProcess.Invoke(this.RootPath, "config status.aheadbehind false"); @@ -65,7 +86,15 @@ public void Initialize() GitProcess.Invoke(this.RootPath, "remote add origin " + CachePath); this.Fetch(this.Commitish); GitProcess.Invoke(this.RootPath, "branch --set-upstream " + this.Commitish + " origin/" + this.Commitish); - GitProcess.Invoke(this.RootPath, "checkout " + this.Commitish); + + ProcessResult checkoutResult = GitProcess.InvokeProcess(this.RootPath, "checkout " + this.Commitish); + if (checkoutResult.ExitCode != 0) + { + throw new InvalidOperationException( + $"Control repo failed to checkout '{this.Commitish}'. The shared control-repo cache at '{CachePath}' is likely missing the branch. " + + $"git exit code {checkoutResult.ExitCode}: {checkoutResult.Errors}"); + } + GitProcess.Invoke(this.RootPath, "branch --unset-upstream"); // Enable the ORT merge strategy @@ -74,7 +103,175 @@ public void Initialize() public void Fetch(string commitish) { - GitProcess.Invoke(this.RootPath, "fetch origin " + commitish); + ProcessResult result = InvokeGitWithRetry(this.RootPath, "fetch origin " + commitish); + if (result.ExitCode != 0) + { + // Do not throw here. Some tests fetch a specific commit by SHA; whether the shared + // cache can serve that SHA is a property of the cache, not of the test. The test's + // own ValidateGitCommand (which compares the control repo against the GVFS repo) + // is the correctness gate. Log for diagnosis and continue. + Console.WriteLine( + $"ControlGitRepo.Fetch: 'fetch origin {commitish}' returned {result.ExitCode} from cache '{CachePath}': {result.Errors}"); + } + } + + /// + /// Creates or refreshes the shared bare cache that every control repo fetches from. + /// + /// + /// The cache path is machine-global and is shared by every functional-test fixture (fixtures + /// run in parallel) and by concurrent test processes on the same machine. The previous + /// implementation checked and then either cloned or + /// fetched, and swallowed every git failure. That produced a flaky cascade: a transient + /// clone or fetch failure, or a concurrent process that observed a half-built clone + /// directory, left the cache missing branches. Every GitCommands test then failed its setup + /// checkout with "pathspec ... did not match any file(s) known to git". + /// + /// This method serializes setup across processes with a system-wide mutex. It builds a + /// missing cache atomically (clone into a temporary directory, verify the base branch, then + /// move it into place). It never rebuilds or deletes an existing cache: on CI runners the + /// cache is persistent and can hold commits from branches that no longer exist upstream + /// (some tests fetch those commits by SHA), so replacing it with a fresh clone would drop + /// those objects. An existing cache is only refreshed, best-effort. Finally it enables + /// uploadpack.allowAnySHA1InWant so control repos can fetch any commit in the cache by SHA. + /// + private static void EnsureSharedCache() + { + using (Mutex mutex = new Mutex(initiallyOwned: false, name: CacheMutexName)) + { + bool mutexHeld = false; + try + { + try + { + mutexHeld = mutex.WaitOne(TimeSpan.FromMinutes(10)); + } + catch (AbandonedMutexException) + { + // A previous process exited while holding the mutex. The cache is handled + // below regardless, so it is safe to proceed. + mutexHeld = true; + } + + if (!mutexHeld) + { + throw new TimeoutException($"Timed out waiting to initialize the control-repo cache at '{CachePath}'."); + } + + string baseBranch = Properties.Settings.Default.Commitish; + + if (Directory.Exists(CachePath)) + { + // Refresh the existing cache so newly-added test branches are available. + // Do this best-effort and never delete/rebuild: the persistent cache can + // hold commits that upstream no longer advertises (fetched by SHA by some + // tests), which a fresh clone would not restore. + InvokeGitWithRetry(CachePath, "fetch origin +refs/*:refs/*"); + } + else + { + BuildFreshCache(baseBranch); + } + + // Allow control repos to fetch any commit present in the cache by its SHA + // (some tests fetch specific commits directly). Without this, upload-pack + // rejects a SHA that is not an advertised ref tip with "not our ref". + ConfigureCacheForShaFetch(CachePath); + } + finally + { + if (mutexHeld) + { + mutex.ReleaseMutex(); + } + } + } + } + + private static void BuildFreshCache(string baseBranch) + { + string root = Properties.Settings.Default.ControlGitRepoRoot; + Directory.CreateDirectory(root); + + string tempCache = Path.Combine(root, "cache.tmp." + Guid.NewGuid().ToString("N")); + + ProcessResult clone = null; + for (int attempt = 1; attempt <= 3; attempt++) + { + if (Directory.Exists(tempCache)) + { + RepositoryHelpers.DeleteTestDirectory(tempCache); + } + + // Use --mirror (not --bare) so the cache carries the complete ref set. A --bare + // clone copies only refs/heads/* and tags; some tests fetch commits (by SHA) that + // live outside refs/heads, so a --bare cache would be missing those objects and the + // fetch would fail with "not our ref". --mirror maps refs/*:refs/*, matching the + // refresh path's "fetch origin +refs/*:refs/*". + clone = GitProcess.InvokeProcess( + Environment.SystemDirectory, + "clone " + GVFSTestConfig.RepoToClone + " " + tempCache + " --mirror"); + + if (clone.ExitCode == 0 && CacheHasBranch(tempCache, baseBranch)) + { + break; + } + + if (attempt == 3) + { + throw new InvalidOperationException( + $"Failed to build the control-repo cache from '{GVFSTestConfig.RepoToClone}' after {attempt} attempts. " + + $"git exit code {clone.ExitCode}: {clone.Errors}"); + } + + Thread.Sleep(TimeSpan.FromSeconds(attempt * 2)); + } + + // Move the fully-built cache into place so no other process observes a partial directory. + if (Directory.Exists(CachePath)) + { + RepositoryHelpers.DeleteTestDirectory(CachePath); + } + + Directory.Move(tempCache, CachePath); + } + + private static void ConfigureCacheForShaFetch(string cachePath) + { + GitProcess.InvokeProcess(cachePath, "config uploadpack.allowAnySHA1InWant true"); + GitProcess.InvokeProcess(cachePath, "config uploadpack.allowReachableSHA1InWant true"); + GitProcess.InvokeProcess(cachePath, "config uploadpack.allowTipSHA1InWant true"); + } + + private static bool CacheHasBranch(string cachePath, string branch) + { + if (!Directory.Exists(cachePath)) + { + return false; + } + + ProcessResult result = GitProcess.InvokeProcess(cachePath, "rev-parse --verify --quiet refs/heads/" + branch); + return result.ExitCode == 0 && !string.IsNullOrWhiteSpace(result.Output); + } + + private static ProcessResult InvokeGitWithRetry(string workingDirectory, string command, int attempts = 3) + { + ProcessResult result = null; + for (int attempt = 1; attempt <= attempts; attempt++) + { + result = GitProcess.InvokeProcess(workingDirectory, command); + if (result.ExitCode == 0) + { + return result; + } + + if (attempt < attempts) + { + Thread.Sleep(TimeSpan.FromSeconds(attempt)); + } + } + + return result; } } } diff --git a/GVFS/GVFS.FunctionalTests/Tools/GVFSFunctionalTestEnlistment.cs b/GVFS/GVFS.FunctionalTests/Tools/GVFSFunctionalTestEnlistment.cs index 4d653f7e23..d352a53191 100644 --- a/GVFS/GVFS.FunctionalTests/Tools/GVFSFunctionalTestEnlistment.cs +++ b/GVFS/GVFS.FunctionalTests/Tools/GVFSFunctionalTestEnlistment.cs @@ -2,6 +2,8 @@ using GVFS.FunctionalTests.Should; using GVFS.FunctionalTests.Tests; using GVFS.Tests.Should; +using NUnit.Framework; +using NUnit.Framework.Interfaces; using System; using System.Collections.Generic; using System.IO; @@ -179,10 +181,102 @@ public string GetPackRoot(FileSystemRunner fileSystem) public void DeleteEnlistment() { + this.CaptureFailureLogs(); TestResultsHelper.OutputGVFSLogs(this); RepositoryHelpers.DeleteTestDirectory(this.EnlistmentRoot); } + /// + /// When the current test has failed, writes a full-memory minidump of each still-running + /// GVFS.Mount process for this enlistment, so a mount *hang* can be diagnosed after the fact. + /// Must be called before the mount is unmounted or killed - once the process is gone (whether + /// cleanly unmounted or force-killed) there is nothing left to dump. Written under + /// so CI can upload it. Best-effort: never + /// throws, so it cannot break teardown. + /// + public void CaptureFailureDiagnostics() + { + try + { + if (!this.TryGetFailureDiagnosticsFolder(out string destinationFolder)) + { + return; + } + + List mountProcessIds = this.GetMountProcessIds(); + if (mountProcessIds.Count == 0) + { + Console.Error.WriteLine("[DIAGNOSTICS] No live GVFS.Mount process for this enlistment (already exited/crashed)"); + return; + } + + Console.Error.WriteLine($"[DIAGNOSTICS] Test failed; capturing mount dump(s) to '{destinationFolder}'"); + Directory.CreateDirectory(destinationFolder); + foreach (int pid in mountProcessIds) + { + MiniDump.TryWrite(pid, Path.Combine(destinationFolder, $"GVFS.Mount_{pid}.dmp")); + } + } + catch (Exception ex) + { + Console.Error.WriteLine($"[DIAGNOSTICS] CaptureFailureDiagnostics failed: {ex.Message}"); + } + } + + /// + /// When the current test has failed, preserves the enlistment's .gvfs/logs folder (robust to + /// locked / partially-flushed files) under + /// before the enlistment directory is deleted. Best-effort: never throws. + /// + private void CaptureFailureLogs() + { + try + { + if (!this.TryGetFailureDiagnosticsFolder(out string destinationFolder)) + { + return; + } + + Console.Error.WriteLine($"[DIAGNOSTICS] Test failed; capturing logs to '{destinationFolder}'"); + TestResultsHelper.CopyFilesWithFallback(this.GVFSLogsRoot, Path.Combine(destinationFolder, "logs")); + } + catch (Exception ex) + { + Console.Error.WriteLine($"[DIAGNOSTICS] CaptureFailureLogs failed: {ex.Message}"); + } + } + + private bool TryGetFailureDiagnosticsFolder(out string destinationFolder) + { + destinationFolder = null; + if (TestContext.CurrentContext.Result.Outcome.Status != TestStatus.Failed) + { + return false; + } + + destinationFolder = Path.Combine( + TestResultsHelper.DiagnosticsRoot, + SanitizeForPath(TestContext.CurrentContext.Test.Name) + "_" + Path.GetFileName(this.EnlistmentRoot)); + return true; + } + + private static string SanitizeForPath(string name) + { + if (string.IsNullOrEmpty(name)) + { + return "test"; + } + + foreach (char invalid in Path.GetInvalidFileNameChars()) + { + name = name.Replace(invalid, '_'); + } + + // Flatten characters that are legal in file names but noisy in NUnit + // test names (parameterized cases, spaces). + return name.Replace('(', '_').Replace(')', '_').Replace(' ', '_').Replace(',', '_').Replace('"', '_'); + } + public void CloneAndMount(bool skipPrefetch) { Console.Error.WriteLine("[CI-DEBUG] CloneAndMount: starting clone of " + this.RepoUrl); @@ -303,6 +397,10 @@ public string SetCacheServer(string arg) public void UnmountAndDeleteAll() { + // Capture the mount dump before unmounting or killing anything - once the mount process is + // gone (whether it unmounts cleanly or is force-killed below) there is nothing left to dump. + this.CaptureFailureDiagnostics(); + try { this.UnmountGVFS(); @@ -320,12 +418,39 @@ public void UnmountAndDeleteAll() public void KillMountProcess() { + foreach (int pid in this.GetMountProcessIds()) + { + Console.Error.WriteLine($"[TEARDOWN] Killing GVFS.Mount (PID {pid}) for {this.EnlistmentRoot}"); + try + { + System.Diagnostics.Process.GetProcessById(pid)?.Kill(); + } + catch (Exception ex) + { + Console.Error.WriteLine($"[TEARDOWN] Failed to kill PID {pid}: {ex.Message}"); + } + } + } + + /// + /// Returns the process ids of the GVFS.Mount processes whose command line + /// references this enlistment root. Uses PowerShell's Get-CimInstance to + /// read command lines without requiring System.Management. Best-effort: + /// returns an empty list on any failure (e.g. non-Windows). + /// + private List GetMountProcessIds() + { + List processIds = new List(); + try { - // Find GVFS.Mount processes whose command line contains this - // enlistment root. Uses PowerShell's Get-CimInstance to read - // command lines without requiring System.Management. - string filter = this.EnlistmentRoot.Replace("\\", "\\\\"); + // Match on the enlistment's unique leaf folder id rather than the + // full path. PowerShell's -like treats '\' as a literal (not an + // escape), so doubling backslashes in the full path would produce a + // pattern that never matches a real (single-backslash) command line. + // The leaf id is unique and free of path separators and wildcard + // metacharacters, so it needs no escaping. + string filter = Path.GetFileName(this.EnlistmentRoot.TrimEnd('\\', '/')); var psi = new System.Diagnostics.ProcessStartInfo("powershell.exe") { Arguments = $"-NoProfile -Command \"Get-CimInstance Win32_Process -Filter \\\"Name='GVFS.Mount.exe'\\\" | Where-Object {{ $_.CommandLine -like '*{filter}*' }} | ForEach-Object {{ $_.ProcessId }}\"", @@ -333,30 +458,67 @@ public void KillMountProcess() UseShellExecute = false, CreateNoWindow = true, }; - var proc = System.Diagnostics.Process.Start(psi); - string output = proc.StandardOutput.ReadToEnd(); - proc.WaitForExit(10000); - foreach (string line in output.Split('\n', StringSplitOptions.RemoveEmptyEntries)) + var output = new System.Text.StringBuilder(); + + // Read output asynchronously via the event, rather than a blocking ReadToEnd() before + // WaitForExit(): ReadToEnd() blocks until the process closes its stdout handle, so if the + // helper itself hangs, the later WaitForExit(10000) timeout is never reached at all. With + // async reads, WaitForExit is the only blocking call, so it enforces a real timeout and we + // can kill the helper if it does not exit in time. + using (var proc = new System.Diagnostics.Process { StartInfo = psi }) { - if (int.TryParse(line.Trim(), out int pid)) + proc.OutputDataReceived += (sender, args) => { - Console.Error.WriteLine($"[TEARDOWN] Killing GVFS.Mount (PID {pid}) for {this.EnlistmentRoot}"); + if (args.Data != null) + { + output.AppendLine(args.Data); + } + }; + + proc.Start(); + proc.BeginOutputReadLine(); + + if (!proc.WaitForExit(10000)) + { + Console.Error.WriteLine("[TEARDOWN] GetMountProcessIds helper timed out; killing it"); try { - System.Diagnostics.Process.GetProcessById(pid)?.Kill(); + proc.Kill(); + proc.WaitForExit(2000); } - catch (Exception ex) + catch (Exception killEx) { - Console.Error.WriteLine($"[TEARDOWN] Failed to kill PID {pid}: {ex.Message}"); + Console.Error.WriteLine($"[TEARDOWN] Failed to kill GetMountProcessIds helper: {killEx.Message}"); } } + else + { + // WaitForExit(int) only guarantees the process has exited - it does NOT guarantee + // that all queued OutputDataReceived callbacks have run yet, since those fire on + // the thread pool as data arrives. Reading `output` right here could race the last + // callback(s) and silently drop a trailing PID line. The parameterless WaitForExit() + // is documented to block until the redirected stream's async reads have completed, + // so calling it again (a no-op once the process has exited) drains any pending + // callbacks before we parse output below. + proc.WaitForExit(); + } + } + + foreach (string line in output.ToString().Split('\n', StringSplitOptions.RemoveEmptyEntries)) + { + if (int.TryParse(line.Trim(), out int pid)) + { + processIds.Add(pid); + } } } catch (Exception ex) { - Console.Error.WriteLine($"[TEARDOWN] KillMountProcess failed: {ex.Message}"); + Console.Error.WriteLine($"[TEARDOWN] GetMountProcessIds failed: {ex.Message}"); } + + return processIds; } public string GetVirtualPathTo(string path) diff --git a/GVFS/GVFS.FunctionalTests/Tools/MiniDump.cs b/GVFS/GVFS.FunctionalTests/Tools/MiniDump.cs new file mode 100644 index 0000000000..57356f44cd --- /dev/null +++ b/GVFS/GVFS.FunctionalTests/Tools/MiniDump.cs @@ -0,0 +1,88 @@ +using System; +using System.Diagnostics; +using System.IO; +using System.Runtime.InteropServices; + +namespace GVFS.FunctionalTests.Tools +{ + /// + /// Best-effort process minidump writer used to capture post-mortem state of a + /// (potentially hung) GVFS.Mount process when a functional test fails. Windows + /// only; a no-op that returns false on other platforms. Never throws. + /// + public static class MiniDump + { + [Flags] + private enum MiniDumpType : uint + { + Normal = 0x00000000, + WithFullMemory = 0x00000002, + WithHandleData = 0x00000004, + WithFullMemoryInfo = 0x00000800, + WithThreadInfo = 0x00001000, + } + + /// + /// Writes a full-memory minidump of the process with the given id to + /// . A full-memory dump is required so + /// that managed call stacks are resolvable in WinDbg/SOS, which is what we + /// need to diagnose a mount deadlock. Returns true on success. + /// + public static bool TryWrite(int processId, string destinationPath) + { + if (!RuntimeInformation.IsOSPlatform(OSPlatform.Windows)) + { + Console.Error.WriteLine($"[DIAGNOSTICS] MiniDump skipped (non-Windows) for PID {processId}"); + return false; + } + + try + { + using (Process process = Process.GetProcessById(processId)) + using (FileStream dumpFile = new FileStream(destinationPath, FileMode.Create, FileAccess.ReadWrite, FileShare.Write)) + { + MiniDumpType dumpType = + MiniDumpType.WithFullMemory | + MiniDumpType.WithHandleData | + MiniDumpType.WithThreadInfo | + MiniDumpType.WithFullMemoryInfo; + + bool succeeded = MiniDumpWriteDump( + process.Handle, + (uint)process.Id, + dumpFile.SafeFileHandle, + dumpType, + IntPtr.Zero, + IntPtr.Zero, + IntPtr.Zero); + + if (!succeeded) + { + int error = Marshal.GetLastWin32Error(); + Console.Error.WriteLine($"[DIAGNOSTICS] MiniDumpWriteDump failed for PID {processId} (Win32 error {error})"); + return false; + } + + Console.Error.WriteLine($"[DIAGNOSTICS] Wrote minidump for GVFS.Mount PID {processId} to {destinationPath}"); + return true; + } + } + catch (Exception ex) + { + Console.Error.WriteLine($"[DIAGNOSTICS] Failed to write minidump for PID {processId}: {ex.Message}"); + return false; + } + } + + [DllImport("dbghelp.dll", SetLastError = true)] + [return: MarshalAs(UnmanagedType.Bool)] + private static extern bool MiniDumpWriteDump( + IntPtr hProcess, + uint processId, + SafeHandle hFile, + MiniDumpType dumpType, + IntPtr exceptionParam, + IntPtr userStreamParam, + IntPtr callbackParam); + } +} diff --git a/GVFS/GVFS.Hooks/GVFS.Hooks.csproj b/GVFS/GVFS.Hooks/GVFS.Hooks.csproj index 69988ac802..3b996578e7 100644 --- a/GVFS/GVFS.Hooks/GVFS.Hooks.csproj +++ b/GVFS/GVFS.Hooks/GVFS.Hooks.csproj @@ -118,4 +118,3 @@ - diff --git a/GVFS/GVFS.Hooks/Program.cs b/GVFS/GVFS.Hooks/Program.cs index 00db23872f..940b2cf37d 100644 --- a/GVFS/GVFS.Hooks/Program.cs +++ b/GVFS/GVFS.Hooks/Program.cs @@ -171,10 +171,11 @@ private static bool HasShortFlag(string arg, string flag) private static bool ConfigurationAllowsHydrationStatus() { - using (LibGit2RepoInvoker repo = new LibGit2RepoInvoker(NullTracer.Instance, normalizedCurrentDirectory)) - { - return repo.GetConfigBoolOrDefault(GVFSConstants.GitConfig.ShowHydrationStatus, GVFSConstants.GitConfig.ShowHydrationStatusDefault); - } + return LibGit2Repo.GetConfigBoolOrDefault( + NullTracer.Instance, + normalizedCurrentDirectory, + GVFSConstants.GitConfig.ShowHydrationStatus, + GVFSConstants.GitConfig.ShowHydrationStatusDefault); } /// diff --git a/GVFS/GVFS.Mount/InProcessMount.cs b/GVFS/GVFS.Mount/InProcessMount.cs index 8cf3c386fc..0a5c930b5f 100644 --- a/GVFS/GVFS.Mount/InProcessMount.cs +++ b/GVFS/GVFS.Mount/InProcessMount.cs @@ -353,7 +353,10 @@ private void MountWithLockAcquired(EventLevel verbosity, Keywords keywords) this.mountProgressMessage = "Resolving cache server"; CacheServerResolver cacheServerResolver = new CacheServerResolver(this.tracer, this.enlistment); - this.cacheServer = cacheServerResolver.ResolveNameFromRemote(this.cacheServer.Url, serverGVFSConfig); + CacheServerInfo cacheServerFromConfig = this.cacheServer; + this.cacheServer = cacheServerResolver + .ResolveNameFromRemote(cacheServerFromConfig.Url, serverGVFSConfig) + .WithEndpointOverridesFrom(cacheServerFromConfig); this.tracer.RelatedEvent( EventLevel.Informational, @@ -486,27 +489,11 @@ private GVFSContext CreateContext() private bool IsBackgroundCacheAuthEnabled() { - // Read the flag via libgit2 (in-process) rather than spawning git.exe. - // The GVFSContext (and its shared libgit2 repo) is not created until - // later in mount, so open a short-lived repo here just for the config - // read. Default to off on any failure. - try - { - using (LibGit2Repo repo = new LibGit2Repo(this.tracer, this.enlistment.WorkingDirectoryBackingRoot)) - { - return repo.GetConfigBool(GVFSConstants.GitConfig.BackgroundCacheAuth) - ?? GVFSConstants.GitConfig.BackgroundCacheAuthDefault; - } - } - catch (Exception e) - { - this.tracer.RelatedWarning( - "Failed to read {0} config, defaulting to {1}: {2}", - GVFSConstants.GitConfig.BackgroundCacheAuth, - GVFSConstants.GitConfig.BackgroundCacheAuthDefault, - e.Message); - return GVFSConstants.GitConfig.BackgroundCacheAuthDefault; - } + return LibGit2Repo.GetConfigBoolOrDefault( + this.tracer, + this.enlistment.WorkingDirectoryBackingRoot, + GVFSConstants.GitConfig.BackgroundCacheAuth, + GVFSConstants.GitConfig.BackgroundCacheAuthDefault); } private void ValidateMountPoints() diff --git a/GVFS/GVFS.Platform.Windows/EnumerationFailureTracker.cs b/GVFS/GVFS.Platform.Windows/EnumerationFailureTracker.cs new file mode 100644 index 0000000000..04d02d700b --- /dev/null +++ b/GVFS/GVFS.Platform.Windows/EnumerationFailureTracker.cs @@ -0,0 +1,230 @@ +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Threading; + +namespace GVFS.Platform.Windows +{ + /// + /// Why a directory-enumeration Get failed to find its enumeration ID. Recorded on the failure + /// telemetry so self-inflicted causes can be told apart from ProjFS races outside gvfs.exe's + /// control. These values are a case-sensitive contract consumed by the release-readiness + /// telemetry dashboard; keep them in sync with its cause bucketing. + /// + public enum EnumerationFailureReason + { + NeverSeen = 0, // ProjFS delivered an ID GVFS never held: never started, or from before a provider restart (outside gvfs.exe's control). + Evicted, // GVFS's own stale-enumeration eviction removed a live enumeration (self-inflicted). + EndedRecently, // ProjFS delivered a Get racing or following the End for the same enumeration - a benign close/query race (outside gvfs.exe's control). + } + + /// + /// Tracks the state needed to classify and rate-limit "Failed to find active enumeration ID" + /// failures, keyed by ProjFS enumeration GUID: + /// + /// - Recently ended IDs, so a Get that races or follows the End for the same enumeration is + /// attributed to a benign close/query race () + /// rather than an ID GVFS never held. + /// - Recently reported IDs, so the error is emitted once per ID within a window instead of once + /// per retry when a caller re-enumerates a lost handle in a loop. + /// + /// Eviction (a separate concern owned by the virtualizer) is passed in to + /// as a flag rather than tracked here. + /// + /// Thread-safety: the enumeration callbacks run concurrently on many ProjFS worker threads, so + /// this deliberately uses lock-free state rather + /// than a coarse lock, which would serialize the hot enumeration path. GUIDs are never reused, so + /// entries are bounded purely by age. + /// + public class EnumerationFailureTracker + { + // ProjFS can deliver a Get that races the End for the same handle (a query in flight while the + // directory handle is closing, or the querying process dying mid-enumeration). Ended IDs are + // retained this long so such a Get is attributed to a recently-ended enumeration. + private static readonly TimeSpan DefaultRecentlyEndedRetention = TimeSpan.FromSeconds(30); + + // A Get miss for the same ID can repeat in a tight loop (a caller re-enumerating a handle + // whose Start GVFS lost, e.g. across a provider restart). The error is emitted once per ID + // within this window so the machine-based signal survives without the per-machine event storm. + private static readonly TimeSpan DefaultReportedMissingRetention = TimeSpan.FromMinutes(5); + + // GVFS's own stale-enumeration eviction removes a live enumeration that ProjFS never ended. + // Evicted IDs are retained this long so a later Get for one is attributed to eviction rather + // than a never-held ID. This is twice the default stale-enumeration timeout (5 minutes), the + // window the virtualizer's eviction sweep uses to decide an enumeration is stale. + private static readonly TimeSpan DefaultRecentlyEvictedRetention = TimeSpan.FromMinutes(10); + + // Throttle for the age-based prune. The prune runs from every record point (RecordEnded, + // RecordEvicted, TryReserveReport), so the maps stay bounded even if one callback (e.g. End) + // stops arriving. + private static readonly TimeSpan DefaultPruneInterval = TimeSpan.FromSeconds(30); + + // Key: the ProjFS enumeration GUID that was ended. Value: the Environment.TickCount64 + // (monotonic milliseconds) at which EndDirectoryEnumeration recorded it. + private readonly ConcurrentDictionary recentlyEnded = new ConcurrentDictionary(); + + // Key: the ProjFS enumeration GUID for which a miss error was already emitted. Value: the + // Environment.TickCount64 (monotonic milliseconds) of that first report. + private readonly ConcurrentDictionary recentlyReportedMissing = new ConcurrentDictionary(); + + // Key: the ProjFS enumeration GUID that GVFS's stale-enumeration eviction removed. Value: the + // Environment.TickCount64 (monotonic milliseconds) at which it was evicted. + private readonly ConcurrentDictionary recentlyEvicted = new ConcurrentDictionary(); + + private readonly TimeSpan recentlyEndedRetention; + private readonly TimeSpan reportedMissingRetention; + private readonly TimeSpan recentlyEvictedRetention; + private readonly TimeSpan pruneInterval; + + // Monotonic (Environment.TickCount64, milliseconds) timestamp of the last prune. + private long lastPruneTickCount = Environment.TickCount64; + + public EnumerationFailureTracker() + : this(DefaultRecentlyEndedRetention, DefaultReportedMissingRetention, DefaultRecentlyEvictedRetention, DefaultPruneInterval) + { + } + + public EnumerationFailureTracker( + TimeSpan recentlyEndedRetention, + TimeSpan reportedMissingRetention, + TimeSpan recentlyEvictedRetention, + TimeSpan pruneInterval) + { + this.recentlyEndedRetention = recentlyEndedRetention; + this.reportedMissingRetention = reportedMissingRetention; + this.recentlyEvictedRetention = recentlyEvictedRetention; + this.pruneInterval = pruneInterval; + } + + /// + /// Records that an enumeration has ended. The caller MUST call this before removing the ID from + /// its active-enumeration collection, so a Get that races the removal always finds the ID in + /// one collection or the other and is never mis-attributed to a never-held ID. + /// + public void RecordEnded(Guid enumerationId) + { + this.MaybePrune(); + this.recentlyEnded[enumerationId] = Environment.TickCount64; + } + + /// + /// Undoes a when the End did not actually remove a live enumeration + /// (GVFS never held the ID), so a later miss is classified + /// rather than skewed to . + /// + public void UndoEnded(Guid enumerationId) + { + this.recentlyEnded.TryRemove(enumerationId, out _); + } + + /// + /// Records that GVFS's stale-enumeration eviction removed . + /// The caller MUST call this before removing the ID from its active-enumeration collection so a + /// racing Get always finds the ID in one collection or the other; if the removal then loses the + /// race (e.g. a normal End removed it first), call to undo. + /// + public void RecordEvicted(Guid enumerationId) + { + this.MaybePrune(); + this.recentlyEvicted[enumerationId] = Environment.TickCount64; + } + + /// + /// Undoes a when the eviction lost the race to remove the ID from + /// the active collection, so a miss is not mis-attributed to eviction. + /// + public void UndoEvicted(Guid enumerationId) + { + this.recentlyEvicted.TryRemove(enumerationId, out _); + } + + /// + /// Whether is currently tracked as recently evicted. + /// + public bool IsRecentlyEvicted(Guid enumerationId) + { + return this.recentlyEvicted.ContainsKey(enumerationId); + } + + /// + /// Classifies why a Get failed to find in the active + /// collection. Eviction is the most actionable (self-inflicted) cause and wins; otherwise a + /// recently-ended ID is a benign close/query race, and anything else was never held. + /// + public EnumerationFailureReason ClassifyMiss(Guid enumerationId) + { + if (this.recentlyEvicted.ContainsKey(enumerationId)) + { + return EnumerationFailureReason.Evicted; + } + + if (this.recentlyEnded.ContainsKey(enumerationId)) + { + return EnumerationFailureReason.EndedRecently; + } + + return EnumerationFailureReason.NeverSeen; + } + + /// + /// Reserves the single error report allowed for within the + /// reporting window. Returns true the first time the ID is seen missing and false for repeats, + /// so a caller's retry loop cannot produce a telemetry storm. + /// + public bool TryReserveReport(Guid enumerationId) + { + this.MaybePrune(); + return this.recentlyReportedMissing.TryAdd(enumerationId, Environment.TickCount64); + } + + // Prunes all three maps if the throttle interval has elapsed. Called from every record point so + // the maps stay bounded regardless of which callback is active. + private void MaybePrune() + { + if (this.recentlyEnded.IsEmpty && this.recentlyReportedMissing.IsEmpty && this.recentlyEvicted.IsEmpty) + { + return; + } + + long now = Environment.TickCount64; + long last = Interlocked.Read(ref this.lastPruneTickCount); + if (now - last < (long)this.pruneInterval.TotalMilliseconds) + { + return; + } + + if (Interlocked.CompareExchange(ref this.lastPruneTickCount, now, last) != last) + { + // Another thread just claimed this prune interval. + return; + } + + PruneByAge(this.recentlyEnded, now - (long)this.recentlyEndedRetention.TotalMilliseconds); + PruneByAge(this.recentlyReportedMissing, now - (long)this.reportedMissingRetention.TotalMilliseconds); + PruneByAge(this.recentlyEvicted, now - (long)this.recentlyEvictedRetention.TotalMilliseconds); + } + + private static void PruneByAge(ConcurrentDictionary map, long cutoffTickCount) + { + foreach (KeyValuePair tracked in map) + { + if (tracked.Value < cutoffTickCount) + { + map.TryRemove(tracked.Key, out _); + } + } + } + + /// + /// Test-only: runs the prune immediately, bypassing the throttle, so retention behavior can be + /// exercised deterministically. + /// + internal void PruneForTest() + { + Interlocked.Exchange( + ref this.lastPruneTickCount, + Environment.TickCount64 - (long)this.pruneInterval.TotalMilliseconds - 1); + this.MaybePrune(); + } + } +} diff --git a/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs b/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs index c99a602056..cc4ff66863 100644 --- a/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs +++ b/GVFS/GVFS.Platform.Windows/WindowsFileSystemVirtualizer.cs @@ -59,23 +59,15 @@ 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(); + // Classifies and rate-limits "Failed to find active enumeration ID" failures (evicted vs + // recently-ended vs never-seen, and once-per-ID error de-duplication). The eviction sweep in + // this class records evictions into it via RecordEvicted. + private readonly EnumerationFailureTracker enumerationFailureTracker = new EnumerationFailureTracker(); - /// - /// 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). - } + // Test-only seam: invoked inside EndDirectoryEnumerationCallback after the ended ID is + // recorded but before it is removed from activeEnumerations, so a test can interleave a + // GetDirectoryEnumeration and verify the record-before-remove ordering. Null in production. + private Action enumerationEndBeforeRemoveHookForTest; public WindowsFileSystemVirtualizer(GVFSContext context, GVFSGitObjects gitObjects) : this( @@ -207,24 +199,6 @@ 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; @@ -237,9 +211,9 @@ private void EvictStaleEnumerations() if (entry.Value.LastActivityTickCount < cutoff) { // 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; + // GetDirectoryEnumeration for this ID always finds it in one collection or the + // other, and is never mis-attributed to a ProjFS unknown-ID delivery. + this.enumerationFailureTracker.RecordEvicted(entry.Key); if (this.activeEnumerations.TryRemove(entry.Key, out _)) { evictedCount++; @@ -248,7 +222,7 @@ private void EvictStaleEnumerations() { // 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 _); + this.enumerationFailureTracker.UndoEvicted(entry.Key); } } } @@ -278,6 +252,18 @@ internal int MaxActiveEnumerationsForTest set { this.maxActiveEnumerations = value; } } + internal Action EnumerationEndBeforeRemoveHookForTest + { + set { this.enumerationEndBeforeRemoveHookForTest = value; } + } + + internal bool ActiveEnumerationsContainsForTest(Guid enumerationId) + { + return this.activeEnumerations.ContainsKey(enumerationId); + } + + internal EnumerationFailureTracker EnumerationFailureTrackerForTest => this.enumerationFailureTracker; + /// /// Test-only: resets the sweep throttle and runs the same eviction path the enumeration hot /// callback runs, so eviction behavior can be exercised deterministically. @@ -511,20 +497,25 @@ public HResult GetDirectoryEnumerationCallback( ActiveEnumeration activeEnumeration = null; if (!this.activeEnumerations.TryGetValue(enumerationId, out activeEnumeration)) { - 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"); + // Distinguish why the ID is absent so self-inflicted causes can be told apart from + // ProjFS races outside gvfs.exe's control. The tracker attributes eviction (the + // only cause GVFS can act on), a recent End (a benign close/query race), or a + // never-held ID. + EnumerationFailureReason enumerationFailureReason = this.enumerationFailureTracker.ClassifyMiss(enumerationId); + + // Emit the full error only the first time a given ID is seen missing; the tracker + // suppresses the duplicate telemetry a caller's retry loop would otherwise generate + // (a single stuck enumeration has produced a very large number of events per machine + // in the field). The machine-based regression signal is preserved because the first + // occurrence still logs at Error. + if (this.enumerationFailureTracker.TryReserveReport(enumerationId)) + { + EventMetadata metadata = this.CreateEventMetadata(enumerationId); + metadata.Add("filterFileName", filterFileName); + metadata.Add("restartScan", restartScan); + metadata.Add(nameof(EnumerationFailureReason), enumerationFailureReason.ToString()); + this.Context.Tracer.RelatedError(metadata, nameof(this.GetDirectoryEnumerationCallback) + ": Failed to find active enumeration ID"); + } return HResult.InternalError; } @@ -597,9 +588,29 @@ public HResult EndDirectoryEnumerationCallback(Guid enumerationId) { try { + // Record the end BEFORE removing from activeEnumerations so a GetDirectoryEnumeration + // that races this end - ProjFS can deliver an in-flight Get concurrently with the + // handle-close End for the same enumeration - is attributed to a recently-ended + // enumeration rather than an ID GVFS never held. RecordEnded also prunes the tracking + // maps on a throttle, so they stay bounded from this path. + this.enumerationFailureTracker.RecordEnded(enumerationId); + + this.enumerationEndBeforeRemoveHookForTest?.Invoke(); + ActiveEnumeration activeEnumeration; if (!this.activeEnumerations.TryRemove(enumerationId, out activeEnumeration)) { + // This End removed nothing from the active set. If GVFS's own eviction removed the + // ID, keep the ended marker (Evicted wins classification regardless). Otherwise GVFS + // never actually held this ID, so undo the marker recorded above, so a later Get is + // classified NeverSeen rather than skewed to EndedRecently. The record-before-remove + // ordering still holds for the normal successful-remove path, so a Get racing a real + // End stays race-safe. + if (!this.enumerationFailureTracker.IsRecentlyEvicted(enumerationId)) + { + this.enumerationFailureTracker.UndoEnded(enumerationId); + } + this.Context.Tracer.RelatedWarning( this.CreateEventMetadata(enumerationId), nameof(this.EndDirectoryEnumerationCallback) + ": Failed to remove enumeration ID from active collection", diff --git a/GVFS/GVFS.UnitTests/Common/CacheServerResolverTests.cs b/GVFS/GVFS.UnitTests/Common/CacheServerResolverTests.cs index 852ecb908a..f338fedadf 100644 --- a/GVFS/GVFS.UnitTests/Common/CacheServerResolverTests.cs +++ b/GVFS/GVFS.UnitTests/Common/CacheServerResolverTests.cs @@ -13,6 +13,10 @@ public class CacheServerResolverTests { private const string CacheServerUrl = "https://cache/server"; private const string CacheServerName = "TestCacheServer"; + private const string PrefetchCacheServerUrl = "https://prefetch-cache/server"; + private const string GetCacheServerUrl = "https://get-cache/server"; + private const string PostCacheServerUrl = "https://post-cache/server"; + private const string SizesCacheServerUrl = "https://sizes-cache/server"; [TestCase] public void CanGetCacheServerFromNewConfig() @@ -43,6 +47,90 @@ public void CanGetCacheServerWithNoConfig() CacheServerResolver.GetUrlFromConfig(enlistment).ShouldEqual(enlistment.RepoUrl); } + [TestCase] + public void EndpointSpecificCacheServersOverrideGlobalCacheServer() + { + MockGVFSEnlistment enlistment = this.CreateEnlistment( + CacheServerUrl, + prefetchCacheServerUrl: PrefetchCacheServerUrl, + getCacheServerUrl: GetCacheServerUrl, + postCacheServerUrl: PostCacheServerUrl, + sizesCacheServerUrl: SizesCacheServerUrl); + + CacheServerInfo cacheServer = CacheServerResolver.GetCacheServerFromConfig(enlistment); + + cacheServer.PrefetchEndpointUrl.ShouldEqual(PrefetchCacheServerUrl + "/gvfs/prefetch"); + cacheServer.ObjectsGetEndpointUrl.ShouldEqual(GetCacheServerUrl + "/gvfs/objects"); + cacheServer.ObjectsPostEndpointUrl.ShouldEqual(PostCacheServerUrl + "/gvfs/objects"); + cacheServer.SizesEndpointUrl.ShouldEqual(SizesCacheServerUrl + "/gvfs/sizes"); + } + + [TestCase] + public void EndpointSpecificCacheServersFallBackToGlobalCacheServer() + { + CacheServerInfo cacheServer = CacheServerResolver.GetCacheServerFromConfig(this.CreateEnlistment(CacheServerUrl)); + + cacheServer.PrefetchEndpointUrl.ShouldEqual(CacheServerUrl + "/gvfs/prefetch"); + cacheServer.ObjectsGetEndpointUrl.ShouldEqual(CacheServerUrl + "/gvfs/objects"); + cacheServer.ObjectsPostEndpointUrl.ShouldEqual(CacheServerUrl + "/gvfs/objects"); + cacheServer.SizesEndpointUrl.ShouldEqual(CacheServerUrl + "/gvfs/sizes"); + } + + [TestCase] + public void EndpointSpecificCacheServersArePreservedWhenGlobalCacheServerIsResolved() + { + CacheServerInfo configuredCacheServer = new CacheServerInfo(CacheServerUrl, CacheServerName) + .WithEndpointOverrides(PrefetchCacheServerUrl, GetCacheServerUrl, PostCacheServerUrl, SizesCacheServerUrl); + CacheServerInfo resolvedCacheServer = new CacheServerInfo("https://resolved-cache/server", "ResolvedCache") + .WithEndpointOverridesFrom(configuredCacheServer); + + resolvedCacheServer.PrefetchCacheServerUrl.ShouldEqual(PrefetchCacheServerUrl); + resolvedCacheServer.GetCacheServerUrl.ShouldEqual(GetCacheServerUrl); + resolvedCacheServer.PostCacheServerUrl.ShouldEqual(PostCacheServerUrl); + resolvedCacheServer.SizesCacheServerUrl.ShouldEqual(SizesCacheServerUrl); + resolvedCacheServer.HasValidUrl().ShouldEqual(true); + } + + [TestCase] + public void InvalidEndpointSpecificCacheServerIsRejected() + { + MockGVFSEnlistment enlistment = this.CreateEnlistment( + CacheServerUrl, + prefetchCacheServerUrl: "not-a-url"); + + InvalidRepoException exception = Assert.Throws( + () => CacheServerResolver.GetCacheServerFromConfig(enlistment)); + + exception.Message.ShouldContain(GVFSConstants.GitConfig.PrefetchCacheServer); + exception.Message.ShouldContain("not an absolute URL"); + } + + [TestCase] + public void CanSaveEndpointSpecificCacheServers() + { + MockGVFSEnlistment enlistment = this.CreateEnlistment(); + MockGitProcess git = (MockGitProcess)enlistment.CreateGitProcess(); + git.SetExpectedCommandResult( + "config --local --replace-all \"gvfs.prefetch.cache-server\" \"https://prefetch-cache/server\"", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + git.SetExpectedCommandResult( + "config --local --replace-all \"gvfs.get.cache-server\" \"https://get-cache/server\"", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + git.SetExpectedCommandResult( + "config --local --replace-all \"gvfs.post.cache-server\" \"https://post-cache/server\"", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + git.SetExpectedCommandResult( + "config --local --replace-all \"gvfs.sizes.cache-server\" \"https://sizes-cache/server\"", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + + CacheServerInfo cacheServer = new CacheServerInfo(CacheServerUrl, CacheServerName) + .WithEndpointOverrides(PrefetchCacheServerUrl, GetCacheServerUrl, PostCacheServerUrl, SizesCacheServerUrl); + + new CacheServerResolver(new MockTracer(), enlistment) + .TrySaveEndpointUrlsToLocalConfig(cacheServer, out string error) + .ShouldEqual(true, error); + } + [TestCase] public void CanResolveUrlForKnownName() { @@ -190,7 +278,13 @@ private void ValidateIsNone(Enlistment enlistment, CacheServerInfo cacheServer) cacheServer.Name.ShouldEqual(CacheServerInfo.ReservedNames.None); } - private MockGVFSEnlistment CreateEnlistment(string newConfigValue = null, string oldConfigValue = null) + private MockGVFSEnlistment CreateEnlistment( + string newConfigValue = null, + string oldConfigValue = null, + string prefetchCacheServerUrl = null, + string getCacheServerUrl = null, + string postCacheServerUrl = null, + string sizesCacheServerUrl = null) { MockGitProcess gitProcess = new MockGitProcess(); gitProcess.SetExpectedCommandResult( @@ -199,6 +293,18 @@ private MockGVFSEnlistment CreateEnlistment(string newConfigValue = null, string gitProcess.SetExpectedCommandResult( "config gvfs.mock:..repourl.cache-server-url", () => new GitProcess.Result(oldConfigValue ?? string.Empty, string.Empty, oldConfigValue != null ? GitProcess.Result.SuccessCode : GitProcess.Result.GenericFailureCode)); + gitProcess.SetExpectedCommandResult( + "config --local gvfs.prefetch.cache-server", + () => new GitProcess.Result(prefetchCacheServerUrl ?? string.Empty, string.Empty, prefetchCacheServerUrl != null ? GitProcess.Result.SuccessCode : GitProcess.Result.GenericFailureCode)); + gitProcess.SetExpectedCommandResult( + "config --local gvfs.get.cache-server", + () => new GitProcess.Result(getCacheServerUrl ?? string.Empty, string.Empty, getCacheServerUrl != null ? GitProcess.Result.SuccessCode : GitProcess.Result.GenericFailureCode)); + gitProcess.SetExpectedCommandResult( + "config --local gvfs.post.cache-server", + () => new GitProcess.Result(postCacheServerUrl ?? string.Empty, string.Empty, postCacheServerUrl != null ? GitProcess.Result.SuccessCode : GitProcess.Result.GenericFailureCode)); + gitProcess.SetExpectedCommandResult( + "config --local gvfs.sizes.cache-server", + () => new GitProcess.Result(sizesCacheServerUrl ?? string.Empty, string.Empty, sizesCacheServerUrl != null ? GitProcess.Result.SuccessCode : GitProcess.Result.GenericFailureCode)); return new MockGVFSEnlistment(gitProcess); } diff --git a/GVFS/GVFS.UnitTests/Common/LibGit2RepoConfigLookupTests.cs b/GVFS/GVFS.UnitTests/Common/LibGit2RepoConfigLookupTests.cs new file mode 100644 index 0000000000..843d423b5f --- /dev/null +++ b/GVFS/GVFS.UnitTests/Common/LibGit2RepoConfigLookupTests.cs @@ -0,0 +1,136 @@ +using GVFS.Common.Git; +using GVFS.Tests.Should; +using GVFS.UnitTests.Mock.Common; +using NUnit.Framework; +using System; +using System.IO; + +namespace GVFS.UnitTests.Common +{ + [TestFixture] + public class LibGit2RepoConfigLookupTests + { + [TestCase] + public void GetConfigBoolOrDefaultOnRepoReturnsConfiguredValue() + { + MockTracer tracer = new MockTracer(); + + using (MockConfigRepo repo = new MockConfigRepo(tracer, true)) + { + bool value = repo.GetConfigBoolOrDefault("gvfs.test", false); + + value.ShouldEqual(true); + tracer.RelatedWarningEvents.Count.ShouldEqual(0); + } + } + + [TestCase] + public void GetConfigBoolOrDefaultOnRepoReturnsDefaultWhenKeyIsUnset() + { + MockTracer tracer = new MockTracer(); + + using (MockConfigRepo repo = new MockConfigRepo(tracer, (bool?)null)) + { + bool value = repo.GetConfigBoolOrDefault("gvfs.test", true); + + value.ShouldEqual(true); + tracer.RelatedWarningEvents.Count.ShouldEqual(0); + } + } + + [TestCase] + public void GetConfigBoolOrDefaultOnRepoReturnsDefaultOnLibGit2ExceptionAndLogsOnce() + { + MockTracer tracer = new MockTracer(); + + using (MockConfigRepo repo = new MockConfigRepo(tracer, new LibGit2Exception("boom"))) + { + bool value = repo.GetConfigBoolOrDefault("gvfs.test", false); + + value.ShouldEqual(false); + tracer.RelatedWarningEvents.Count.ShouldEqual(1); + tracer.RelatedWarningEvents[0].ShouldContain("Failed to read gvfs.test config, using default: boom"); + } + } + + [TestCase] + public void GetConfigBoolOrDefaultOnRepoReturnsDefaultOnInvalidDataExceptionAndLogsOnce() + { + MockTracer tracer = new MockTracer(); + + using (MockConfigRepo repo = new MockConfigRepo(tracer, new InvalidDataException("corrupt config"))) + { + bool value = repo.GetConfigBoolOrDefault("gvfs.test", false); + + value.ShouldEqual(false); + tracer.RelatedWarningEvents.Count.ShouldEqual(1); + tracer.RelatedWarningEvents[0].ShouldContain("Failed to read gvfs.test config, using default: corrupt config"); + } + } + + [TestCase] + public void GetConfigBoolOrDefaultOnPathReturnsDefaultForMissingRepoAndLogsExactlyOnce() + { + MockTracer tracer = new MockTracer(); + + // A GUID-suffixed path under the OS temp directory is guaranteed not to exist and + // does not depend on any particular drive letter being unmapped (unlike a + // hardcoded "Z:\..." path, which could resolve on a host with that drive mapped). + string missingRepoPath = Path.Combine( + Path.GetTempPath(), + "LibGit2RepoConfigLookupTests_" + Guid.NewGuid().ToString("N")); + + bool value = LibGit2Repo.GetConfigBoolOrDefault( + tracer, + missingRepoPath, + "gvfs.test", + false); + + value.ShouldEqual(false); + + // The LibGit2Repo constructor logs a RelatedWarning with the native open-failure + // reason before throwing InvalidDataException; the static helper's catch does not + // log a second time for that case (see LibGit2Repo.GetConfigBoolOrDefault), so + // exactly one warning is expected here. + tracer.RelatedWarningEvents.Count.ShouldEqual(1); + tracer.RelatedWarningEvents[0].ShouldContain("Couldn't open repo at"); + } + + private class MockConfigRepo : LibGit2Repo + { + private readonly bool? value; + private readonly Exception exceptionToThrow; + + public MockConfigRepo(MockTracer tracer, bool? value) + : base(tracer) + { + this.value = value; + } + + public MockConfigRepo(MockTracer tracer, Exception exceptionToThrow) + : base(tracer) + { + this.exceptionToThrow = exceptionToThrow; + } + + public override bool? GetConfigBool(string name) + { + if (this.exceptionToThrow != null) + { + throw this.exceptionToThrow; + } + + return this.value; + } + + // This mock never calls the base LibGit2Repo(tracer, repoPath) constructor, so it + // never initializes native libgit2 state or a real RepoHandle. Override Dispose(bool) + // to skip the base implementation's native Free/Shutdown calls, which would otherwise + // run on an uninitialized handle without a matching Init (same pattern as + // LibGit2RepoInvokerTests.MockLibGit2Repo and LibGit2RepoSafeDirectoryTests.MockSafeDirectoryRepo). + protected override void Dispose(bool disposing) + { + } + } + } +} diff --git a/GVFS/GVFS.UnitTests/Git/GitObjectsTests.cs b/GVFS/GVFS.UnitTests/Git/GitObjectsTests.cs index 88be433806..78236a37bc 100644 --- a/GVFS/GVFS.UnitTests/Git/GitObjectsTests.cs +++ b/GVFS/GVFS.UnitTests/Git/GitObjectsTests.cs @@ -1,13 +1,19 @@ 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.FileSystem; using NUnit.Framework; +using System; using System.Collections.Generic; using System.IO; +using System.Net; +using System.Net.Http; +using System.Net.Http.Headers; using System.Security; +using System.Threading; namespace GVFS.UnitTests.Git { @@ -124,6 +130,61 @@ public void WriteLooseObject_Success() moved.ShouldBeTrue("File was not moved"); } + [TestCase] + public void PrefetchFailureTelemetryReportsOnlyRequestAuthority() + { + const string RequestUrl = "https://user:secret@cache.example:8443/gvfs/prefetch?token=sensitive"; + MockTracer tracer = new MockTracer(); + MockGVFSEnlistment enlistment = new MockGVFSEnlistment(); + TestPrefetchRequestor requestor = new TestPrefetchRequestor( + tracer, + enlistment, + HttpStatusCode.ServiceUnavailable, + new Uri(RequestUrl)); + GitObjects gitObjects = new GVFSGitObjects( + new GVFSContext(tracer, new MockFileSystemWithCallbacks(), null, enlistment), + requestor); + + gitObjects.TryDownloadPrefetchPacks( + gitProcess: null, + latestTimestamp: 0, + trustPackIndexes: false, + out List _) + .ShouldEqual(false); + + tracer.StartActivityTracer.RelatedWarningEvents.Count.ShouldEqual(1); + tracer.StartActivityTracer.RelatedWarningEvents[0].ShouldContain("\"PrefetchEndpointUrl\":\"cache.example:8443\""); + tracer.StartActivityTracer.RelatedWarningEvents[0].IndexOf("user", StringComparison.Ordinal).ShouldEqual(-1); + tracer.StartActivityTracer.RelatedWarningEvents[0].IndexOf("secret", StringComparison.Ordinal).ShouldEqual(-1); + tracer.StartActivityTracer.RelatedWarningEvents[0].IndexOf("sensitive", StringComparison.Ordinal).ShouldEqual(-1); + } + + [TestCase] + public void UnsupportedPrefetchTelemetryReportsOnlyRequestAuthority() + { + const string RequestUrl = "https://user:secret@cache.example:8443/gvfs/prefetch?token=sensitive"; + MockTracer tracer = new MockTracer(); + MockGVFSEnlistment enlistment = new MockGVFSEnlistment(); + TestPrefetchRequestor requestor = new TestPrefetchRequestor( + tracer, + enlistment, + HttpStatusCode.NotFound, + new Uri(RequestUrl)); + GitObjects gitObjects = new GVFSGitObjects( + new GVFSContext(tracer, new MockFileSystemWithCallbacks(), null, enlistment), + requestor); + + gitObjects.TryDownloadPrefetchPacks( + gitProcess: null, + latestTimestamp: 0, + trustPackIndexes: false, + out List _) + .ShouldEqual(false); + + EventMetadata metadata = tracer.StartActivityTracer.RelatedEventMetadata[0]; + metadata["PrefetchEndpointUrl"].ShouldEqual("cache.example:8443"); + } + private Stream OnOpenFileStream(string path, FileMode mode, FileAccess access) { this.openedPaths.Add(path); @@ -144,5 +205,40 @@ private bool OnFileExists(string path) { return this.pathsToData.TryGetValue(path, out _); } + + private class TestPrefetchRequestor : GitObjectsHttpRequestor + { + private readonly HttpStatusCode statusCode; + private readonly Uri requestUri; + + public TestPrefetchRequestor( + ITracer tracer, + Enlistment enlistment, + HttpStatusCode statusCode, + Uri requestUri) + : base(tracer, enlistment, new CacheServerInfo("https://cache.example/server", "cache"), new RetryConfig(0)) + { + this.statusCode = statusCode; + this.requestUri = requestUri; + } + + public override RetryWrapper.InvocationResult TrySendProtocolRequest( + long requestId, + Func.CallbackResult> onSuccess, + Action.ErrorEventArgs> onFailure, + HttpMethod method, + Func endPointGenerator, + Func requestBodyGenerator, + CancellationToken cancellationToken, + MediaTypeWithQualityHeaderValue acceptType = null, + bool retryOnFailure = true, + Func fallbackEndPointGenerator = null) + { + return new RetryWrapper.InvocationResult( + tryCount: 1, + new GitObjectsHttpException(this.statusCode, "Test failure"), + new GitObjectTaskResult(this.statusCode, this.requestUri)); + } + } } } diff --git a/GVFS/GVFS.UnitTests/Http/GitObjectsHttpRequestorTests.cs b/GVFS/GVFS.UnitTests/Http/GitObjectsHttpRequestorTests.cs new file mode 100644 index 0000000000..ee89a68ae2 --- /dev/null +++ b/GVFS/GVFS.UnitTests/Http/GitObjectsHttpRequestorTests.cs @@ -0,0 +1,485 @@ +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 NUnit.Framework; +using System; +using System.Collections.Generic; +using System.IO; +using System.Net; +using System.Net.Http; +using System.Net.Http.Headers; +using System.Text; +using System.Threading; + +namespace GVFS.UnitTests.Http +{ + [TestFixture] + public class GitObjectsHttpRequestorTests + { + private const string GlobalCacheServerUrl = "https://global-cache/server"; + private const string EndpointCacheServerUrl = "https://endpoint-cache/server"; + + [SetUp] + public void SetUp() + { + RetryCircuitBreaker.Reset(); + } + + [TearDown] + public void TearDown() + { + RetryCircuitBreaker.Reset(); + } + + [TestCase] + public void LooseObjectFallsBackToGlobalCacheServerWhenEndpointRequestFails() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueResponse(HttpStatusCode.NotFound); + requestor.EnqueueResponse(HttpStatusCode.OK); + + RetryWrapper.InvocationResult result = + requestor.TryDownloadLooseObject( + "0123456789abcdef", + retryOnFailure: false, + CancellationToken.None, + requestSource: "test", + onSuccess: SuccessfulRequest); + + result.Succeeded.ShouldEqual(true); + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/objects/0123456789abcdef"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/objects/0123456789abcdef"); + requestor.TestTracer.RelatedEventNames.ShouldContain(name => name == "CacheServerFallback"); + requestor.TestTracer.RelatedEventKeywords.ShouldContain( + keywords => (keywords & Keywords.Telemetry) == Keywords.Telemetry); + } + + [TestCase] + public void BatchedObjectRequestFallsBackToGlobalCacheServer() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueResponse(HttpStatusCode.ServiceUnavailable, shouldRetry: true); + requestor.EnqueueResponse(HttpStatusCode.NotFound); + + RetryWrapper.InvocationResult result = + requestor.TryDownloadObjects( + new[] { "0123456789abcdef" }, + onSuccess: SuccessfulRequest, + onFailure: null, + preferBatchedLooseObjects: false); + + result.Succeeded.ShouldEqual(false); + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/objects"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/objects"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + [TestCase] + public void PrefetchRequestFallsBackToGlobalCacheServer() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueResponse(HttpStatusCode.BadRequest); + requestor.EnqueueResponse(HttpStatusCode.OK); + + RetryWrapper.InvocationResult result = + requestor.TrySendProtocolRequest( + requestId: 1, + onSuccess: SuccessfulRequest, + onFailure: null, + method: HttpMethod.Get, + endPointGenerator: () => new Uri(EndpointCacheServerUrl + "/gvfs/prefetch?lastPackTimestamp=0"), + fallbackEndPointGenerator: () => new Uri(GlobalCacheServerUrl + "/gvfs/prefetch?lastPackTimestamp=0"), + requestBodyGenerator: () => null, + cancellationToken: CancellationToken.None); + + result.Succeeded.ShouldEqual(true); + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/prefetch?lastPackTimestamp=0"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/prefetch?lastPackTimestamp=0"); + } + + [TestCase] + public void TransportExceptionFallsBackToGlobalCacheServer() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueException(new HttpRequestException("Test failure")); + requestor.EnqueueResponse(HttpStatusCode.NotFound); + + RetryWrapper.InvocationResult result = + requestor.TryDownloadObjects( + new[] { "0123456789abcdef" }, + onSuccess: SuccessfulRequest, + onFailure: null, + preferBatchedLooseObjects: false); + + result.Succeeded.ShouldEqual(false); + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/objects"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/objects"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + [TestCase] + public void ResponseBodyReadFailureFallsBackToGlobalCacheServer() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueResponse(new ThrowingReadStream()); + requestor.EnqueueResponse(HttpStatusCode.NotFound); + + RetryWrapper.InvocationResult result = + requestor.TryDownloadObjects( + new[] { "0123456789abcdef" }, + onSuccess: (tryCount, response) => + { + response.Stream.ReadByte(); + return SuccessfulRequest(tryCount, response); + }, + onFailure: null, + preferBatchedLooseObjects: false); + + result.Succeeded.ShouldEqual(false); + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/objects"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/objects"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + [TestCase] + public void ResponseBodyReadFailureReportedByHandlerFallsBackToGlobalCacheServer() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueResponse(new ThrowingReadStream()); + requestor.EnqueueResponse(HttpStatusCode.OK); + + RetryWrapper.InvocationResult result = + requestor.TryDownloadObjects( + new[] { "0123456789abcdef" }, + onSuccess: (tryCount, response) => + { + try + { + response.Stream.ReadByte(); + return SuccessfulRequest(tryCount, response); + } + catch (IOException e) + { + return new RetryWrapper.CallbackResult( + e, + shouldRetry: true); + } + }, + onFailure: null, + preferBatchedLooseObjects: false); + + result.Succeeded.ShouldEqual(true); + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/objects"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/objects"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + [TestCase] + public void ResponseBodyCancellationIsNotRetriedOrReportedAsFallback() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 1); + requestor.EnqueueResponse(new CancelingReadStream()); + + Assert.Throws( + () => requestor.TryDownloadObjects( + new[] { "0123456789abcdef" }, + onSuccess: (tryCount, response) => + { + response.RetryableReadToEnd(); + return SuccessfulRequest(tryCount, response); + }, + onFailure: null, + preferBatchedLooseObjects: false)); + + requestor.RequestUris.Count.ShouldEqual(1); + requestor.TestTracer.RelatedEventNames.ShouldNotContain(name => name == "CacheServerFallback"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + [TestCase] + public void FallbackTelemetryExcludesCredentialsAndRequestPath() + { + const string CredentialedGlobalUrl = "https://global-user:global-secret@global-cache:8443/server"; + const string CredentialedEndpointUrl = "https://endpoint-user:endpoint-secret@endpoint-cache:9443/server"; + TestGitObjectsHttpRequestor requestor = this.CreateRequestor( + maxRetries: 0, + globalCacheServerUrl: CredentialedGlobalUrl, + endpointCacheServerUrl: CredentialedEndpointUrl); + requestor.EnqueueResponse(HttpStatusCode.NotFound); + requestor.EnqueueResponse(HttpStatusCode.OK); + + requestor.TryDownloadLooseObject( + "0123456789abcdef", + retryOnFailure: false, + CancellationToken.None, + requestSource: "test", + onSuccess: SuccessfulRequest); + + int fallbackEventIndex = requestor.TestTracer.RelatedEventNames.IndexOf("CacheServerFallback"); + EventMetadata metadata = requestor.TestTracer.RelatedEventMetadata[fallbackEventIndex]; + metadata["SourceAuthority"].ShouldEqual("endpoint-cache:9443"); + metadata["TargetAuthority"].ShouldEqual("global-cache:8443"); + } + + [TestCase] + public void NoEndpointOverrideUsesNormalGlobalCacheRetries() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 1, endpointOverrides: false); + requestor.EnqueueResponse(HttpStatusCode.ServiceUnavailable, shouldRetry: true); + requestor.EnqueueResponse(HttpStatusCode.OK); + + RetryWrapper.InvocationResult result = + requestor.TryDownloadObjects( + new[] { "0123456789abcdef" }, + onSuccess: SuccessfulRequest, + onFailure: null, + preferBatchedLooseObjects: false); + + result.Succeeded.ShouldEqual(true); + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/objects"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/objects"); + requestor.TestTracer.RelatedEventNames.ShouldNotContain(name => name == "CacheServerFallback"); + } + + [TestCase] + public void TerminalFallbackFailureReportsGlobalCacheServer() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueResponse(HttpStatusCode.ServiceUnavailable); + requestor.EnqueueResponse(HttpStatusCode.NotFound); + + RetryWrapper.InvocationResult result = + requestor.TryDownloadObjects( + new[] { "0123456789abcdef" }, + onSuccess: SuccessfulRequest, + onFailure: null, + preferBatchedLooseObjects: false); + + result.Succeeded.ShouldEqual(false); + result.Attempts.ShouldEqual(2); + result.Result.HttpStatusCodeResult.ShouldEqual(HttpStatusCode.NotFound); + result.Result.RequestUri.AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/objects"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + [TestCase] + public void SuccessHandlerFailureRetriesTheEndpointSpecificServer() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 1); + requestor.EnqueueResponse(HttpStatusCode.OK); + requestor.EnqueueResponse(HttpStatusCode.OK); + int successHandlerCalls = 0; + + RetryWrapper.InvocationResult result = + requestor.TryDownloadObjects( + new[] { "0123456789abcdef" }, + onSuccess: (tryCount, response) => + { + if (++successHandlerCalls == 1) + { + throw new RetryableException("Local write failed"); + } + + return SuccessfulRequest(tryCount, response); + }, + onFailure: null, + preferBatchedLooseObjects: false); + + result.Succeeded.ShouldEqual(true); + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/objects"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/objects"); + requestor.TestTracer.RelatedEventNames.ShouldNotContain(name => name == "CacheServerFallback"); + } + + [TestCase] + public void SizesRequestFallsBackThroughGlobalCacheServerToOrigin() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueResponse(HttpStatusCode.ServiceUnavailable); + requestor.EnqueueResponse(HttpStatusCode.NotFound); + requestor.EnqueueResponse(HttpStatusCode.OK, "[]"); + + requestor.QueryForFileSizes(new[] { "0123456789abcdef" }, CancellationToken.None); + + requestor.RequestUris.Count.ShouldEqual(3); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/sizes"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/sizes"); + requestor.RequestUris[2].AbsoluteUri.ShouldEqual("mock://repourl/gvfs/sizes"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + [TestCase] + public void SizesHttpFallbackDoesNotChargeCircuitBreaker() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueResponse(HttpStatusCode.ServiceUnavailable, shouldRetry: true); + requestor.EnqueueResponse(HttpStatusCode.ServiceUnavailable); + + requestor.QueryForFileSizes(new[] { "0123456789abcdef" }, CancellationToken.None); + + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/sizes"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/sizes"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + [TestCase] + public void SizesTransportFallbackDoesNotChargeCircuitBreaker() + { + TestGitObjectsHttpRequestor requestor = this.CreateRequestor(maxRetries: 0); + requestor.EnqueueException(new HttpRequestException("Test failure")); + requestor.EnqueueResponse(HttpStatusCode.ServiceUnavailable); + + requestor.QueryForFileSizes(new[] { "0123456789abcdef" }, CancellationToken.None); + + requestor.RequestUris.Count.ShouldEqual(2); + requestor.RequestUris[0].AbsoluteUri.ShouldEqual(EndpointCacheServerUrl + "/gvfs/sizes"); + requestor.RequestUris[1].AbsoluteUri.ShouldEqual(GlobalCacheServerUrl + "/gvfs/sizes"); + RetryCircuitBreaker.ConsecutiveFailures.ShouldEqual(0); + } + + private static RetryWrapper.CallbackResult SuccessfulRequest( + int tryCount, + GitEndPointResponseData response) + { + return new RetryWrapper.CallbackResult( + new GitObjectsHttpRequestor.GitObjectTaskResult(true)); + } + + private TestGitObjectsHttpRequestor CreateRequestor( + int maxRetries, + bool endpointOverrides = true, + string globalCacheServerUrl = GlobalCacheServerUrl, + string endpointCacheServerUrl = EndpointCacheServerUrl) + { + CacheServerInfo cacheServer = new CacheServerInfo(globalCacheServerUrl, "global"); + if (endpointOverrides) + { + cacheServer = cacheServer.WithEndpointOverrides( + endpointCacheServerUrl, + endpointCacheServerUrl, + endpointCacheServerUrl, + endpointCacheServerUrl); + } + + return new TestGitObjectsHttpRequestor( + new MockGVFSEnlistment(), + cacheServer, + new RetryConfig(maxRetries)); + } + + private class TestGitObjectsHttpRequestor : GitObjectsHttpRequestor + { + private readonly Queue responses = new Queue(); + + public TestGitObjectsHttpRequestor( + Enlistment enlistment, + CacheServerInfo cacheServer, + RetryConfig retryConfig) + : this(new MockTracer(), enlistment, cacheServer, retryConfig) + { + } + + private TestGitObjectsHttpRequestor( + MockTracer tracer, + Enlistment enlistment, + CacheServerInfo cacheServer, + RetryConfig retryConfig) + : base(tracer, enlistment, cacheServer, retryConfig) + { + this.TestTracer = tracer; + this.RequestUris = new List(); + } + + public MockTracer TestTracer { get; } + public List RequestUris { get; } + + public void EnqueueResponse(HttpStatusCode statusCode, string body = "", bool shouldRetry = false) + { + this.responses.Enqueue(Tuple.Create(statusCode, body, shouldRetry)); + } + + public void EnqueueException(Exception exception) + { + this.responses.Enqueue(exception); + } + + public void EnqueueResponse(Stream stream) + { + this.responses.Enqueue(stream); + } + + protected override GitEndPointResponseData SendProtocolRequest( + long requestId, + Uri requestUri, + HttpMethod httpMethod, + string requestContent, + CancellationToken cancellationToken, + MediaTypeWithQualityHeaderValue acceptType = null) + { + this.RequestUris.Add(requestUri); + object nextResponse = this.responses.Dequeue(); + if (nextResponse is Exception exception) + { + throw exception; + } + + if (nextResponse is Stream stream) + { + return new GitEndPointResponseData( + HttpStatusCode.OK, + "application/json", + stream, + message: null, + onResponseDisposed: null); + } + + Tuple response = (Tuple)nextResponse; + + if (response.Item1 == HttpStatusCode.OK) + { + return new GitEndPointResponseData( + response.Item1, + "application/json", + new MemoryStream(Encoding.UTF8.GetBytes(response.Item2)), + message: null, + onResponseDisposed: null); + } + + return new GitEndPointResponseData( + response.Item1, + new GitObjectsHttpException(response.Item1, "Test failure"), + shouldRetry: response.Item3, + message: null, + onResponseDisposed: null); + } + } + + private class ThrowingReadStream : MemoryStream + { + public override int ReadByte() + { + throw new IOException("Response body read failed"); + } + } + + private class CancelingReadStream : MemoryStream + { + public override int Read(byte[] buffer, int offset, int count) + { + throw new OperationCanceledException("Response body read canceled"); + } + } + } +} diff --git a/GVFS/GVFS.UnitTests/Http/HttpRequestorTests.cs b/GVFS/GVFS.UnitTests/Http/HttpRequestorTests.cs new file mode 100644 index 0000000000..e81b81170d --- /dev/null +++ b/GVFS/GVFS.UnitTests/Http/HttpRequestorTests.cs @@ -0,0 +1,88 @@ +using GVFS.Common.Http; +using GVFS.Tests.Should; +using NUnit.Framework; +using System; +using System.Net; + +namespace GVFS.UnitTests.Http +{ + [TestFixture] + public class HttpRequestorTests + { + [TestCase] + public void Unauthorized401RejectsCredentials() + { + HttpRequestor.ShouldRejectCredentials(HttpStatusCode.Unauthorized, responseBody: null) + .ShouldEqual(true, "A 401 is a definitive auth failure and must reject credentials"); + } + + [TestCase] + public void Redirect302RejectsCredentials() + { + HttpRequestor.ShouldRejectCredentials(HttpStatusCode.Redirect, responseBody: null) + .ShouldEqual(true, "A 302 is the Azure DevOps sign-in redirect and must reject credentials"); + } + + [TestCase] + public void BadRequest400WithAuthRequiredMessageRejectsCredentials() + { + // The GVFS cache server returns a 400 (instead of a 401) when the request carried + // no parseable Basic Authorization header. That single 400 genuinely means + // "authentication required", so it must reject credentials. We recognize it by the + // cache server's response body. + HttpRequestor.ShouldRejectCredentials( + HttpStatusCode.BadRequest, + HttpRequestor.CacheServerAuthRequiredBadRequestMessage) + .ShouldEqual(true, "A 400 whose body is the cache server's auth-required message must reject credentials"); + } + + [TestCase] + public void BadRequest400AuthRequiredMessageMatchIsCaseInsensitiveAndSubstring() + { + // The match is a case-insensitive substring so it stays robust if the server + // wraps or prefixes the text. + HttpRequestor.ShouldRejectCredentials( + HttpStatusCode.BadRequest, + "Error: a valid basic authorization header is required. (request 123)") + .ShouldEqual(true, "The auth-required message match must be a case-insensitive substring"); + } + + [TestCase] + public void BadRequest400WithNonAuthBodyDoesNotRejectCredentials() + { + // The storm case: a corrupt placeholder SHA makes the cache server return a 400 + // with an "Invalid ObjectId" body. That is NOT an auth failure and must not erase + // a valid credential. + HttpRequestor.ShouldRejectCredentials( + HttpStatusCode.BadRequest, + "Error processing GVFS request: Invalid ObjectId in the URI.") + .ShouldEqual(false, "A non-auth 400 (e.g. invalid object id) must NOT reject credentials"); + } + + [TestCase] + public void BadRequest400WithNullBodyDoesNotRejectCredentials() + { + HttpRequestor.ShouldRejectCredentials(HttpStatusCode.BadRequest, responseBody: null) + .ShouldEqual(false, "A 400 with no body must NOT reject credentials"); + } + + [TestCase] + public void CommonNonAuthStatusesDoNotRejectCredentials() + { + HttpRequestor.ShouldRejectCredentials(HttpStatusCode.NotFound, responseBody: null) + .ShouldEqual(false, "A 404 must NOT reject credentials"); + HttpRequestor.ShouldRejectCredentials(HttpStatusCode.InternalServerError, responseBody: null) + .ShouldEqual(false, "A 500 must NOT reject credentials"); + HttpRequestor.ShouldRejectCredentials(HttpStatusCode.RequestTimeout, responseBody: null) + .ShouldEqual(false, "A 408 must NOT reject credentials"); + } + + [TestCase] + public void AuthorityForTelemetryExcludesCredentialsAndRequestPath() + { + Uri uri = new Uri("https://alice:secret@cache.example.com:8443/private/path?token=sensitive#fragment"); + + HttpRequestor.GetAuthorityForTelemetry(uri).ShouldEqual("cache.example.com:8443"); + } + } +} diff --git a/GVFS/GVFS.UnitTests/Maintenance/PackfileMaintenanceStepTests.cs b/GVFS/GVFS.UnitTests/Maintenance/PackfileMaintenanceStepTests.cs index 811b55e15b..7f7aab9076 100644 --- a/GVFS/GVFS.UnitTests/Maintenance/PackfileMaintenanceStepTests.cs +++ b/GVFS/GVFS.UnitTests/Maintenance/PackfileMaintenanceStepTests.cs @@ -11,6 +11,7 @@ using System; using System.Collections.Generic; using System.IO; +using System.Linq; namespace GVFS.UnitTests.Maintenance { @@ -28,6 +29,8 @@ public class PackfileMaintenanceStepTests private string WriteCommand => $"-c core.multiPackIndex=true multi-pack-index write --object-dir=\"{this.context.Enlistment.GitObjectsRoot}\" --no-progress"; private string RepackCommand => $"-c pack.threads=1 -c repack.packKeptObjects=true multi-pack-index repack --object-dir=\"{this.context.Enlistment.GitObjectsRoot}\" --batch-size=2g --no-progress"; + private string VerifyPackCommand(string idxName) => $"verify-pack \"{Path.Combine(this.context.Enlistment.GitPackRoot, idxName)}\""; + [TestCase] public void PackfileMaintenanceIgnoreTimeRestriction() { @@ -142,6 +145,177 @@ public void PackfileMaintenanceRewriteOnBadVerify() commands[6].ShouldEqual(this.WriteCommand); } + [TestCase] + public void PackfileMaintenanceRemovesCorruptPackWhenVerifyReportsPackLoadFailure() + { + this.TestSetup(DateTime.UtcNow); + this.SetupVerifyFailsOnceWithPackLoadError(); + + // Per-pack verification: pack-2 is the corrupt one, the rest are healthy. + this.gitProcess.SetExpectedCommandResult( + "verify-pack ", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode), + matchPrefix: true); + this.gitProcess.SetExpectedCommandResult( + this.VerifyPackCommand("pack-2.idx"), + () => new GitProcess.Result(string.Empty, "error: could not load pack\n", GitProcess.Result.GenericFailureCode)); + + PackfileMaintenanceStep step = new TestablePackfileMaintenanceStep(this.context, recoveryEnabled: true); + step.Execute(); + + this.tracer.StartActivityTracer.RelatedErrorEvents.Count.ShouldEqual(0); + + List commands = this.gitProcess.CommandsRun; + commands.Count(c => c.StartsWith("verify-pack ")).ShouldEqual(3); + + string packRoot = this.context.Enlistment.GitPackRoot; + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-2.pack")).ShouldBeFalse(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-2.idx")).ShouldBeFalse(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-1.pack")).ShouldBeTrue(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-3.pack")).ShouldBeTrue(); + + this.WarningsContain("FoundCorruptPack").ShouldBeTrue(); + this.WarningsContain("DeletedCorruptPack").ShouldBeTrue(); + } + + [TestCase] + public void PackfileMaintenanceFastPathVerifiesOnlyNamedPackWhenErrorNamesIt() + { + this.TestSetup(DateTime.UtcNow); + this.SetupVerifyFailsOnceWithNamedPackError("pack-2.pack"); + + // Only pack-2 should be verified via the fast path - no other pack's verify-pack result is + // even registered, so the test would fail with an unexpected-command error if the fallback + // full scan ran instead. + this.gitProcess.SetExpectedCommandResult( + this.VerifyPackCommand("pack-2.idx"), + () => new GitProcess.Result(string.Empty, "error: could not load pack\n", GitProcess.Result.GenericFailureCode)); + + PackfileMaintenanceStep step = new TestablePackfileMaintenanceStep(this.context, recoveryEnabled: true); + step.Execute(); + + this.tracer.StartActivityTracer.RelatedErrorEvents.Count.ShouldEqual(0); + + List commands = this.gitProcess.CommandsRun; + commands.Count(c => c.StartsWith("verify-pack ")).ShouldEqual(1); + commands.Where(c => c.StartsWith("verify-pack ")).Single().ShouldEqual(this.VerifyPackCommand("pack-2.idx")); + + string packRoot = this.context.Enlistment.GitPackRoot; + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-2.pack")).ShouldBeFalse(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-1.pack")).ShouldBeTrue(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-3.pack")).ShouldBeTrue(); + + this.WarningsContain("FoundCorruptPack").ShouldBeTrue(); + this.WarningsContain("DeletedCorruptPack").ShouldBeTrue(); + } + + [TestCase] + public void PackfileMaintenanceFallsBackToFullScanWhenNamedPackIsHealthy() + { + this.TestSetup(DateTime.UtcNow); + + // The verify failure text names pack-1, but pack-1 turns out to verify successfully; the + // real corrupt pack (pack-2) is only found once the code falls back to the full scan. + this.SetupVerifyFailsOnceWithNamedPackError("pack-1.pack"); + + this.gitProcess.SetExpectedCommandResult( + "verify-pack ", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode), + matchPrefix: true); + this.gitProcess.SetExpectedCommandResult( + this.VerifyPackCommand("pack-2.idx"), + () => new GitProcess.Result(string.Empty, "error: could not load pack\n", GitProcess.Result.GenericFailureCode)); + + PackfileMaintenanceStep step = new TestablePackfileMaintenanceStep(this.context, recoveryEnabled: true); + step.Execute(); + + this.tracer.StartActivityTracer.RelatedErrorEvents.Count.ShouldEqual(0); + + List commands = this.gitProcess.CommandsRun; + + // 1 fast-path verify-pack (pack-1, healthy) + 3 full-scan verify-pack (pack-1/2/3). + commands.Count(c => c.StartsWith("verify-pack ")).ShouldEqual(4); + + string packRoot = this.context.Enlistment.GitPackRoot; + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-2.pack")).ShouldBeFalse(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-1.pack")).ShouldBeTrue(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-3.pack")).ShouldBeTrue(); + + this.WarningsContain("FoundCorruptPack").ShouldBeTrue(); + this.WarningsContain("DeletedCorruptPack").ShouldBeTrue(); + } + + [TestCase] + public void PackfileMaintenanceDetectsButDoesNotDeleteWhenRecoveryDisabled() + { + this.TestSetup(DateTime.UtcNow); + this.SetupVerifyFailsOnceWithPackLoadError(); + + this.gitProcess.SetExpectedCommandResult( + "verify-pack ", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode), + matchPrefix: true); + this.gitProcess.SetExpectedCommandResult( + this.VerifyPackCommand("pack-2.idx"), + () => new GitProcess.Result(string.Empty, "error: could not load pack\n", GitProcess.Result.GenericFailureCode)); + + PackfileMaintenanceStep step = new TestablePackfileMaintenanceStep(this.context, recoveryEnabled: false); + step.Execute(); + + this.tracer.StartActivityTracer.RelatedErrorEvents.Count.ShouldEqual(0); + + List commands = this.gitProcess.CommandsRun; + + // Detection still runs (verify-pack on each pack), but nothing is deleted. + commands.Count(c => c.StartsWith("verify-pack ")).ShouldEqual(3); + + string packRoot = this.context.Enlistment.GitPackRoot; + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-2.pack")).ShouldBeTrue(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "pack-2.idx")).ShouldBeTrue(); + + this.WarningsContain("FoundCorruptPack").ShouldBeTrue(); + this.WarningsContain("CorruptPackRecoverySkipped").ShouldBeTrue(); + this.WarningsContain("DeletedCorruptPack").ShouldBeFalse(); + } + + [TestCase] + public void PackfileMaintenanceRemovesLaterPrefetchPacksAndRequestsPrefetch() + { + this.PrefetchTestSetup(DateTime.UtcNow); + this.SetupVerifyFailsOnceWithPackLoadError(); + + this.gitProcess.SetExpectedCommandResult( + "verify-pack ", + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode), + matchPrefix: true); + this.gitProcess.SetExpectedCommandResult( + this.VerifyPackCommand("prefetch-2-bbb.idx"), + () => new GitProcess.Result(string.Empty, "error: could not load pack\n", GitProcess.Result.GenericFailureCode)); + + bool prefetchRequested = false; + PackfileMaintenanceStep step = new TestablePackfileMaintenanceStep( + this.context, + recoveryEnabled: true, + requestPrefetch: () => prefetchRequested = true); + step.Execute(); + + this.tracer.StartActivityTracer.RelatedErrorEvents.Count.ShouldEqual(0); + + string packRoot = this.context.Enlistment.GitPackRoot; + + // The corrupt prefetch pack and every later prefetch pack are removed; the earlier healthy + // prefetch pack is kept. + this.context.FileSystem.FileExists(Path.Combine(packRoot, "prefetch-2-bbb.pack")).ShouldBeFalse(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "prefetch-3-ccc.pack")).ShouldBeFalse(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "prefetch-3-ccc.keep")).ShouldBeFalse(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "prefetch-1-aaa.pack")).ShouldBeTrue(); + this.context.FileSystem.FileExists(Path.Combine(packRoot, "prefetch-1-aaa.idx")).ShouldBeTrue(); + + this.WarningsContain("DeletedCorruptPack").ShouldBeTrue(); + this.WarningsContain("DeletedHealthyPrefetchPack").ShouldBeTrue(); + prefetchRequested.ShouldBeTrue(); + } + [TestCase] public void CountPackFiles() { @@ -240,5 +414,111 @@ private void TestSetup(DateTime lastRun, bool failOnVerify = false) this.RepackCommand, () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); } + + private void PrefetchTestSetup(DateTime lastRun) + { + string lastRunTime = EpochConverter.ToUnixEpochSeconds(lastRun).ToString(); + + this.gitProcess = new MockGitProcess(); + GVFSEnlistment enlistment = new MockGVFSEnlistment(this.gitProcess); + + MockFile timeFile = new MockFile(Path.Combine(enlistment.GitObjectsRoot, "info", PackfileMaintenanceStep.PackfileLastRunFileName), lastRunTime); + MockDirectory info = new MockDirectory( + Path.Combine(enlistment.GitObjectsRoot, "info"), + null, + new List() { timeFile }); + + // Three prefetch packs in ascending timestamp order, newest .keep'd (as GVFS does). + MockDirectory pack = new MockDirectory( + enlistment.GitPackRoot, + null, + new List() + { + new MockFile(Path.Combine(enlistment.GitPackRoot, "prefetch-1-aaa.pack"), "one"), + new MockFile(Path.Combine(enlistment.GitPackRoot, "prefetch-1-aaa.idx"), "1"), + new MockFile(Path.Combine(enlistment.GitPackRoot, "prefetch-2-bbb.pack"), "two"), + new MockFile(Path.Combine(enlistment.GitPackRoot, "prefetch-2-bbb.idx"), "2"), + new MockFile(Path.Combine(enlistment.GitPackRoot, "prefetch-3-ccc.pack"), "three"), + new MockFile(Path.Combine(enlistment.GitPackRoot, "prefetch-3-ccc.idx"), "3"), + new MockFile(Path.Combine(enlistment.GitPackRoot, "prefetch-3-ccc.keep"), string.Empty), + }); + + MockDirectory gitObjectsRoot = new MockDirectory(enlistment.GitObjectsRoot, new List() { info, pack }, null); + List directories = new List() { gitObjectsRoot }; + PhysicalFileSystem fileSystem = new MockFileSystem(new MockDirectory(enlistment.PrimaryEnlistmentRoot, directories, null)); + + this.tracer = new MockTracer(); + MockGitRepo repository = new MockGitRepo(this.tracer, enlistment, fileSystem); + this.context = new GVFSContext(this.tracer, fileSystem, repository, enlistment); + + this.gitProcess.SetExpectedCommandResult( + this.WriteCommand, + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + this.gitProcess.SetExpectedCommandResult( + this.ExpireCommand, + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + this.gitProcess.SetExpectedCommandResult( + this.RepackCommand, + () => new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode)); + } + + /// + /// Makes the multi-pack-index verify fail the first time with a "could not load pack" error + /// (the corrupt-pack signature) and succeed afterwards. + /// + private void SetupVerifyFailsOnceWithPackLoadError() + { + int verifyCount = 0; + this.gitProcess.SetExpectedCommandResult( + this.VerifyCommand, + () => + { + verifyCount++; + return verifyCount == 1 + ? new GitProcess.Result(string.Empty, "failed to load pack in position 0\n", GitProcess.Result.GenericFailureCode) + : new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode); + }); + } + + /// + /// Makes the multi-pack-index verify fail the first time with an error that names + /// directly (as real git verify failures do - e.g. "failed to + /// load pack entry for oid[0] = ..." followed by "packfile pack-2.pack does not match index"), + /// and succeed afterwards. + /// + private void SetupVerifyFailsOnceWithNamedPackError(string packFileName) + { + int verifyCount = 0; + this.gitProcess.SetExpectedCommandResult( + this.VerifyCommand, + () => + { + verifyCount++; + return verifyCount == 1 + ? new GitProcess.Result(string.Empty, $"failed to load pack entry for oid[0] = abc\nerror: packfile {packFileName} does not match index\n", GitProcess.Result.GenericFailureCode) + : new GitProcess.Result(string.Empty, string.Empty, GitProcess.Result.SuccessCode); + }); + } + + private bool WarningsContain(string operation) + { + return this.tracer.StartActivityTracer.RelatedWarningEvents.Any(e => e.Contains(operation)); + } + + private class TestablePackfileMaintenanceStep : PackfileMaintenanceStep + { + private readonly bool recoveryEnabled; + + public TestablePackfileMaintenanceStep(GVFSContext context, bool recoveryEnabled, Action requestPrefetch = null) + : base(context, requireObjectCacheLock: false, forceRun: true, requestPrefetch: requestPrefetch) + { + this.recoveryEnabled = recoveryEnabled; + } + + protected override bool IsPackfileRecoveryEnabled() + { + return this.recoveryEnabled; + } + } } } diff --git a/GVFS/GVFS.UnitTests/Mock/Common/MockTracer.cs b/GVFS/GVFS.UnitTests/Mock/Common/MockTracer.cs index d933584e94..47ad66e295 100644 --- a/GVFS/GVFS.UnitTests/Mock/Common/MockTracer.cs +++ b/GVFS/GVFS.UnitTests/Mock/Common/MockTracer.cs @@ -17,6 +17,8 @@ public MockTracer() this.RelatedWarningEvents = new List(); this.RelatedErrorEvents = new List(); this.RelatedEventNames = new List(); + this.RelatedEventKeywords = new List(); + this.RelatedEventMetadata = new List(); } public MockTracer StartActivityTracer { get; private set; } @@ -29,6 +31,8 @@ public MockTracer() // Names of events reported via RelatedEvent (which, unlike RelatedInfo/Warning/Error, // do not otherwise get recorded). Lets tests assert a specific diagnostic event fired. public List RelatedEventNames { get; } + public List RelatedEventKeywords { get; } + public List RelatedEventMetadata { get; } public void WaitForRelatedEvent() { @@ -38,6 +42,8 @@ public void WaitForRelatedEvent() public void RelatedEvent(EventLevel error, string eventName, EventMetadata metadata) { this.RelatedEventNames.Add(eventName); + this.RelatedEventKeywords.Add(Keywords.None); + this.RelatedEventMetadata.Add(metadata); if (eventName == this.WaitRelatedEventName) { this.waitEvent.Set(); @@ -47,6 +53,8 @@ public void RelatedEvent(EventLevel error, string eventName, EventMetadata metad public void RelatedEvent(EventLevel error, string eventName, EventMetadata metadata, Keywords keyword) { this.RelatedEventNames.Add(eventName); + this.RelatedEventKeywords.Add(keyword); + this.RelatedEventMetadata.Add(metadata); if (eventName == this.WaitRelatedEventName) { this.waitEvent.Set(); diff --git a/GVFS/GVFS.UnitTests/Windows/EnumerationFailureTrackerTests.cs b/GVFS/GVFS.UnitTests/Windows/EnumerationFailureTrackerTests.cs new file mode 100644 index 0000000000..7db8a6f9c5 --- /dev/null +++ b/GVFS/GVFS.UnitTests/Windows/EnumerationFailureTrackerTests.cs @@ -0,0 +1,190 @@ +using System; +using GVFS.Platform.Windows; +using GVFS.Tests.Should; +using NUnit.Framework; + +namespace GVFS.UnitTests.Windows +{ + [TestFixture] + public class EnumerationFailureTrackerTests + { + // Retention/interval used by the classification and dedup tests, where entries must survive + // for the duration of the test (the default 30s throttle keeps the auto-prune from firing). + private static EnumerationFailureTracker CreateTracker() + { + return new EnumerationFailureTracker(); + } + + // Retention set to already-expired so a forced prune reclaims every entry deterministically, + // without any Thread.Sleep. The interval is left at a normal value; PruneForTest bypasses it. + private static EnumerationFailureTracker CreateImmediatelyExpiringTracker() + { + return new EnumerationFailureTracker( + recentlyEndedRetention: TimeSpan.FromMilliseconds(-1), + reportedMissingRetention: TimeSpan.FromMilliseconds(-1), + recentlyEvictedRetention: TimeSpan.FromMilliseconds(-1), + pruneInterval: TimeSpan.FromSeconds(30)); + } + + [TestCase] + public void ClassifyMiss_UnknownIdIsNeverSeen() + { + EnumerationFailureTracker tracker = CreateTracker(); + + tracker.ClassifyMiss(Guid.NewGuid()).ShouldEqual(EnumerationFailureReason.NeverSeen); + } + + [TestCase] + public void ClassifyMiss_RecordedEndIsEndedRecently() + { + EnumerationFailureTracker tracker = CreateTracker(); + Guid id = Guid.NewGuid(); + + tracker.RecordEnded(id); + + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.EndedRecently); + } + + [TestCase] + public void ClassifyMiss_RecordedEvictionIsEvicted() + { + EnumerationFailureTracker tracker = CreateTracker(); + Guid id = Guid.NewGuid(); + + tracker.RecordEvicted(id); + + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.Evicted); + } + + [TestCase] + public void ClassifyMiss_EvictionWinsOverRecordedEnd() + { + EnumerationFailureTracker tracker = CreateTracker(); + Guid id = Guid.NewGuid(); + + // Same ID present as both evicted and ended (the real case: eviction removed it, then a + // late End recorded it). Eviction is the more actionable cause and must win. + tracker.RecordEvicted(id); + tracker.RecordEnded(id); + + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.Evicted); + } + + [TestCase] + public void UndoEvicted_UndoesEviction() + { + EnumerationFailureTracker tracker = CreateTracker(); + Guid id = Guid.NewGuid(); + + // Eviction recorded the ID before removing it from the active set, then lost the race, so + // it undoes the record. The ID must no longer be attributed to eviction. + tracker.RecordEvicted(id); + tracker.UndoEvicted(id); + + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.NeverSeen); + } + + [TestCase] + public void UndoEnded_ReclassifiesAsNeverSeen() + { + EnumerationFailureTracker tracker = CreateTracker(); + Guid id = Guid.NewGuid(); + + // End recorded the ID before removing it, but the removal found nothing (GVFS never held + // it), so it undoes the record. The ID must classify NeverSeen, not EndedRecently. + tracker.RecordEnded(id); + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.EndedRecently); + + tracker.UndoEnded(id); + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.NeverSeen); + } + + [TestCase] + public void IsRecentlyEvicted_TrueOnlyAfterRecordEvicted() + { + EnumerationFailureTracker tracker = CreateTracker(); + Guid id = Guid.NewGuid(); + + tracker.IsRecentlyEvicted(id).ShouldBeFalse(); + tracker.RecordEvicted(id); + tracker.IsRecentlyEvicted(id).ShouldBeTrue(); + tracker.UndoEvicted(id); + tracker.IsRecentlyEvicted(id).ShouldBeFalse(); + } + + [TestCase] + public void TryReserveReport_ReturnsTrueOnceThenFalseForSameId() + { + EnumerationFailureTracker tracker = CreateTracker(); + Guid id = Guid.NewGuid(); + + tracker.TryReserveReport(id).ShouldBeTrue(); + tracker.TryReserveReport(id).ShouldBeFalse(); + tracker.TryReserveReport(id).ShouldBeFalse(); + } + + [TestCase] + public void TryReserveReport_IndependentPerId() + { + EnumerationFailureTracker tracker = CreateTracker(); + + tracker.TryReserveReport(Guid.NewGuid()).ShouldBeTrue(); + tracker.TryReserveReport(Guid.NewGuid()).ShouldBeTrue(); + } + + [TestCase] + public void PruneRemovesAgedEntries() + { + EnumerationFailureTracker tracker = CreateImmediatelyExpiringTracker(); + Guid id = Guid.NewGuid(); + + // Populate the maps. The default-interval throttle keeps the auto-prune inside RecordEnded, + // RecordEvicted and TryReserveReport from firing yet, so the entries are present. + tracker.RecordEnded(id); + tracker.TryReserveReport(id).ShouldBeTrue(); + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.EndedRecently); + tracker.TryReserveReport(id).ShouldBeFalse(); + + // Force the prune past the throttle: both aged entries are reclaimed. + tracker.PruneForTest(); + + // The ended entry is gone (now NeverSeen) and the dedup entry is gone (can report again). + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.NeverSeen); + tracker.TryReserveReport(id).ShouldBeTrue(); + } + + [TestCase] + public void PruneRemovesAgedEviction() + { + EnumerationFailureTracker tracker = CreateImmediatelyExpiringTracker(); + Guid id = Guid.NewGuid(); + + tracker.RecordEvicted(id); + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.Evicted); + + tracker.PruneForTest(); + + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.NeverSeen); + } + + [TestCase] + public void PruneKeepsEntriesWithinRetention() + { + // Long retention: a forced prune must NOT remove fresh entries. + EnumerationFailureTracker tracker = new EnumerationFailureTracker( + recentlyEndedRetention: TimeSpan.FromMinutes(10), + reportedMissingRetention: TimeSpan.FromMinutes(10), + recentlyEvictedRetention: TimeSpan.FromMinutes(10), + pruneInterval: TimeSpan.FromSeconds(30)); + Guid id = Guid.NewGuid(); + + tracker.RecordEnded(id); + tracker.TryReserveReport(id).ShouldBeTrue(); + + tracker.PruneForTest(); + + tracker.ClassifyMiss(id).ShouldEqual(EnumerationFailureReason.EndedRecently); + tracker.TryReserveReport(id).ShouldBeFalse(); + } + } +} diff --git a/GVFS/GVFS.UnitTests/Windows/Virtualization/WindowsFileSystemVirtualizerTests.cs b/GVFS/GVFS.UnitTests/Windows/Virtualization/WindowsFileSystemVirtualizerTests.cs index bfd4a0e094..3a98649b7e 100644 --- a/GVFS/GVFS.UnitTests/Windows/Virtualization/WindowsFileSystemVirtualizerTests.cs +++ b/GVFS/GVFS.UnitTests/Windows/Virtualization/WindowsFileSystemVirtualizerTests.cs @@ -328,7 +328,7 @@ public void StaleEnumerationsAreEvictedWhenEnabledButLiveOnesAreKept() } [TestCase] - public void GetDirectoryEnumerationTagsEvictedVersusUnknownId() + public void GetDirectoryEnumerationTagsMissReasonAndDeduplicates() { using (WindowsFileSystemVirtualizerTester tester = new WindowsFileSystemVirtualizerTester(this.Repo, new[] { "test" })) { @@ -355,11 +355,121 @@ public void GetDirectoryEnumerationTagsEvictedVersusUnknownId() 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. + // A Get for an ID GVFS never held is attributed to a never-seen 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(); + e => e.Contains("Failed to find active enumeration ID") && e.Contains("\"EnumerationFailureReason\":\"NeverSeen\"")).ShouldBeTrue(); + + // A Get that races/follows the End for the same enumeration is attributed to a benign + // close/query race, not a never-seen delivery. + Guid endedId = Guid.NewGuid(); + tester.MockVirtualization.RequiredCallbacks.StartDirectoryEnumerationCallback(5, endedId, "test", TriggeringProcessId, TriggeringProcessImageFileName).ShouldEqual(HResult.Ok); + tester.MockVirtualization.RequiredCallbacks.EndDirectoryEnumerationCallback(endedId).ShouldEqual(HResult.Ok); + tester.MockVirtualization.RequiredCallbacks.GetDirectoryEnumerationCallback(6, endedId, string.Empty, false, null).ShouldEqual(HResult.InternalError); + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("Failed to find active enumeration ID") && e.Contains("\"EnumerationFailureReason\":\"EndedRecently\"")).ShouldBeTrue(); + + // Repeated Gets for the same missing ID are de-duplicated: the error is emitted once, + // so a caller's retry loop cannot produce a telemetry storm. + int errorsForNeverSeenId = mockTracker.RelatedErrorEvents.Count(e => e.Contains("\"EnumerationFailureReason\":\"NeverSeen\"")); + tester.MockVirtualization.RequiredCallbacks.GetDirectoryEnumerationCallback(7, neverSeenId, string.Empty, false, null).ShouldEqual(HResult.InternalError); + tester.MockVirtualization.RequiredCallbacks.GetDirectoryEnumerationCallback(8, neverSeenId, string.Empty, false, null).ShouldEqual(HResult.InternalError); + mockTracker.RelatedErrorEvents.Count(e => e.Contains("\"EnumerationFailureReason\":\"NeverSeen\"")).ShouldEqual(errorsForNeverSeenId); + } + } + + [TestCase] + public void EndDirectoryEnumerationRecordsEndedBeforeRemovingFromActive() + { + using (WindowsFileSystemVirtualizerTester tester = new WindowsFileSystemVirtualizerTester(this.Repo, new[] { "test" })) + { + tester.GitIndexProjection.EnumerationInMemory = true; + MockTracer mockTracker = this.Repo.Context.Tracer as MockTracer; + + Guid endedId = Guid.NewGuid(); + tester.MockVirtualization.RequiredCallbacks.StartDirectoryEnumerationCallback(1, endedId, "test", TriggeringProcessId, TriggeringProcessImageFileName).ShouldEqual(HResult.Ok); + + // Capture the state at the exact interleaving point a concurrent Get would observe: + // after End records the ended ID but before it removes it from activeEnumerations. This + // is the ordering the fix guarantees; a remove-before-record regression would fail it. + bool activeAtHook = false; + bool recentlyEndedAtHook = false; + tester.WindowsVirtualizer.EnumerationEndBeforeRemoveHookForTest = () => + { + activeAtHook = tester.WindowsVirtualizer.ActiveEnumerationsContainsForTest(endedId); + recentlyEndedAtHook = tester.WindowsVirtualizer.EnumerationFailureTrackerForTest.ClassifyMiss(endedId) == EnumerationFailureReason.EndedRecently; + }; + + tester.MockVirtualization.RequiredCallbacks.EndDirectoryEnumerationCallback(endedId).ShouldEqual(HResult.Ok); + + // The end was recorded before the removal, and the entry was still live at that point, + // so there is no window where the ID is absent from BOTH maps - a racing Get can never + // be misclassified NeverSeen. + recentlyEndedAtHook.ShouldBeTrue(); + activeAtHook.ShouldBeTrue(); + + // After End completes the ID is out of the active set but still tracked as recently ended. + tester.WindowsVirtualizer.ActiveEnumerationsContainsForTest(endedId).ShouldBeFalse(); + tester.WindowsVirtualizer.EnumerationFailureTrackerForTest.ClassifyMiss(endedId).ShouldEqual(EnumerationFailureReason.EndedRecently); + mockTracker.RelatedErrorEvents.Any(e => e.Contains("Failed to find active enumeration ID")).ShouldBeFalse(); + } + } + + [TestCase] + public void GetDirectoryEnumerationPrefersEvictedWhenIdIsBothEvictedAndEnded() + { + 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); + + // Evict staleId: it lands in the recently-evicted map and leaves the active set. + tester.WindowsVirtualizer.ForceEnumerationEvictionSweepForTest(); + + // A late End for the same ID also records it in the recently-ended map (the removal + // itself fails because eviction already removed it), so the ID is now in BOTH maps. + tester.MockVirtualization.RequiredCallbacks.EndDirectoryEnumerationCallback(staleId).ShouldEqual(HResult.InternalError); + + MockTracer mockTracker = this.Repo.Context.Tracer as MockTracer; + + // The classifier checks eviction first, so the more actionable self-inflicted cause wins. + 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(); + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("Failed to find active enumeration ID") && e.Contains("\"EnumerationFailureReason\":\"EndedRecently\"")).ShouldBeFalse(); + } + } + + [TestCase] + public void EndForNeverHeldIdDoesNotSkewLaterGetToEndedRecently() + { + using (WindowsFileSystemVirtualizerTester tester = new WindowsFileSystemVirtualizerTester(this.Repo, new[] { "test" })) + { + tester.GitIndexProjection.EnumerationInMemory = true; + MockTracer mockTracker = this.Repo.Context.Tracer as MockTracer; + + // End arrives for an ID GVFS never held (no prior Start), so the removal finds nothing + // and it was not evicted. The ended marker recorded before the removal must be undone. + Guid neverHeldId = Guid.NewGuid(); + tester.MockVirtualization.RequiredCallbacks.EndDirectoryEnumerationCallback(neverHeldId).ShouldEqual(HResult.InternalError); + + // A later Get for that ID is therefore classified NeverSeen, not skewed to EndedRecently. + tester.MockVirtualization.RequiredCallbacks.GetDirectoryEnumerationCallback(1, neverHeldId, string.Empty, false, null).ShouldEqual(HResult.InternalError); + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("Failed to find active enumeration ID") && e.Contains("\"EnumerationFailureReason\":\"NeverSeen\"")).ShouldBeTrue(); + mockTracker.RelatedErrorEvents.Any( + e => e.Contains("Failed to find active enumeration ID") && e.Contains("\"EnumerationFailureReason\":\"EndedRecently\"")).ShouldBeFalse(); } } diff --git a/GVFS/GVFS/CommandLine/CloneVerb.cs b/GVFS/GVFS/CommandLine/CloneVerb.cs index 977c5b0823..2e9bb52762 100644 --- a/GVFS/GVFS/CommandLine/CloneVerb.cs +++ b/GVFS/GVFS/CommandLine/CloneVerb.cs @@ -24,6 +24,14 @@ public class CloneVerb : GVFSVerb public string CacheServerUrl { get; set; } + public string PrefetchCacheServerUrl { get; set; } + + public string GetCacheServerUrl { get; set; } + + public string PostCacheServerUrl { get; set; } + + public string SizesCacheServerUrl { get; set; } + public string Branch { get; set; } public bool SingleBranch { get; set; } @@ -56,6 +64,22 @@ public static System.CommandLine.Command CreateCommand() System.CommandLine.Option cacheServerOption = new System.CommandLine.Option("--cache-server-url") { Description = "The url or friendly name of the cache server" }; cmd.Add(cacheServerOption); + System.CommandLine.Option prefetchCacheServerOption = new System.CommandLine.Option("--prefetch-cache-server-url") { Description = "The cache server URL for the prefetch endpoint" }; + AddEndpointCacheServerUrlValidator(prefetchCacheServerOption); + cmd.Add(prefetchCacheServerOption); + + System.CommandLine.Option getCacheServerOption = new System.CommandLine.Option("--get-cache-server-url") { Description = "The cache server URL for the objects GET endpoint" }; + AddEndpointCacheServerUrlValidator(getCacheServerOption); + cmd.Add(getCacheServerOption); + + System.CommandLine.Option postCacheServerOption = new System.CommandLine.Option("--post-cache-server-url") { Description = "The cache server URL for the objects POST endpoint" }; + AddEndpointCacheServerUrlValidator(postCacheServerOption); + cmd.Add(postCacheServerOption); + + System.CommandLine.Option sizesCacheServerOption = new System.CommandLine.Option("--sizes-cache-server-url") { Description = "The cache server URL for the sizes endpoint" }; + AddEndpointCacheServerUrlValidator(sizesCacheServerOption); + cmd.Add(sizesCacheServerOption); + System.CommandLine.Option branchOption = new System.CommandLine.Option("--branch", new[] { "-b" }) { Description = "Branch to checkout after clone" }; cmd.Add(branchOption); @@ -86,6 +110,10 @@ public static System.CommandLine.Command CreateCommand() } verb.CacheServerUrl = result.GetValue(cacheServerOption); + verb.PrefetchCacheServerUrl = result.GetValue(prefetchCacheServerOption); + verb.GetCacheServerUrl = result.GetValue(getCacheServerOption); + verb.PostCacheServerUrl = result.GetValue(postCacheServerOption); + verb.SizesCacheServerUrl = result.GetValue(sizesCacheServerOption); verb.Branch = result.GetValue(branchOption); verb.SingleBranch = result.GetValue(singleBranchOption); verb.NoMount = result.GetValue(noMountOption); @@ -107,6 +135,19 @@ public static System.CommandLine.Command CreateCommand() return cmd; } + private static void AddEndpointCacheServerUrlValidator(System.CommandLine.Option option) + { + option.Validators.Add( + result => + { + string url = result.GetValueOrDefault(); + if (url != null && !CacheServerInfo.IsValidUrl(url)) + { + result.AddError($"Option '{option.Name}' requires an absolute URL."); + } + }); + } + protected override string VerbName { get { return CloneVerbName; } @@ -144,6 +185,14 @@ public override void Execute() this.CheckKernelDriverSupported(normalizedEnlistmentRootPath); this.CheckNotInsideExistingRepo(normalizedEnlistmentRootPath); this.BlockEmptyCacheServerUrl(this.CacheServerUrl); + this.BlockEmptyCacheServerUrl(this.PrefetchCacheServerUrl); + this.BlockEmptyCacheServerUrl(this.GetCacheServerUrl); + this.BlockEmptyCacheServerUrl(this.PostCacheServerUrl); + this.BlockEmptyCacheServerUrl(this.SizesCacheServerUrl); + this.BlockInvalidEndpointCacheServerUrl("--prefetch-cache-server-url", this.PrefetchCacheServerUrl); + this.BlockInvalidEndpointCacheServerUrl("--get-cache-server-url", this.GetCacheServerUrl); + this.BlockInvalidEndpointCacheServerUrl("--post-cache-server-url", this.PostCacheServerUrl); + this.BlockInvalidEndpointCacheServerUrl("--sizes-cache-server-url", this.SizesCacheServerUrl); try { @@ -152,7 +201,7 @@ public override void Execute() CacheServerInfo cacheServer = null; ServerGVFSConfig serverGVFSConfig = null; - bool trustPackIndexes; + bool trustPackIndexes = GVFSConstants.GitConfig.TrustPackIndexesDefault; using (JsonTracer tracer = new JsonTracer(GVFSConstants.GVFSEtwProviderName, "GVFSClone")) { @@ -231,6 +280,11 @@ public override void Execute() } cacheServer = this.ResolveCacheServer(tracer, cacheServer, cacheServerResolver, serverGVFSConfig); + cacheServer = cacheServer.WithEndpointOverrides( + this.PrefetchCacheServerUrl, + this.GetCacheServerUrl, + this.PostCacheServerUrl, + this.SizesCacheServerUrl); this.ValidateClientVersions(tracer, enlistment, serverGVFSConfig, showWarnings: true); @@ -248,10 +302,13 @@ public override void Execute() { tracer.RelatedError(cloneResult.ErrorMessage); } - - using (var repo = new LibGit2RepoInvoker(tracer, enlistment.WorkingDirectoryBackingRoot)) + else { - trustPackIndexes = repo.GetConfigBoolOrDefault(GVFSConstants.GitConfig.TrustPackIndexes, GVFSConstants.GitConfig.TrustPackIndexesDefault); + trustPackIndexes = LibGit2Repo.GetConfigBoolOrDefault( + tracer, + enlistment.WorkingDirectoryBackingRoot, + GVFSConstants.GitConfig.TrustPackIndexes, + GVFSConstants.GitConfig.TrustPackIndexesDefault); } } @@ -593,6 +650,14 @@ private bool TryDetermineLocalCacheAndInitializePaths( return true; } + private void BlockInvalidEndpointCacheServerUrl(string optionName, string url) + { + if (url != null && !CacheServerInfo.IsValidUrl(url)) + { + this.ReportErrorAndExit($"Option '{optionName}' requires an absolute URL."); + } + } + private Result CreateClone( ITracer tracer, GVFSEnlistment enlistment, @@ -640,6 +705,11 @@ private Result CreateClone( return new Result("Unable to configure cache server: " + errorMessage); } + if (!cacheServerResolver.TrySaveEndpointUrlsToLocalConfig(objectRequestor.CacheServer, out errorMessage)) + { + return new Result("Unable to configure endpoint-specific cache servers: " + errorMessage); + } + GitProcess git = new GitProcess(enlistment); string originBranchName = "origin/" + branch; GitProcess.Result createBranchResult = git.CreateBranchWithUpstream(branch, originBranchName); diff --git a/GVFS/GVFS/CommandLine/GVFSVerb.cs b/GVFS/GVFS/CommandLine/GVFSVerb.cs index 51b693578d..84a4c678bf 100644 --- a/GVFS/GVFS/CommandLine/GVFSVerb.cs +++ b/GVFS/GVFS/CommandLine/GVFSVerb.cs @@ -475,6 +475,7 @@ protected CacheServerInfo ResolveCacheServer( resolvedCacheServer = cacheServerResolver.ResolveNameFromRemote(cacheServer.Url, serverGVFSConfig); } + resolvedCacheServer = resolvedCacheServer.WithEndpointOverridesFrom(cacheServer); this.Output.WriteLine("Using cache server: " + resolvedCacheServer); return resolvedCacheServer; } @@ -526,7 +527,7 @@ protected bool TryDownloadCommit( if (!gitObjects.TryDownloadCommit(commitId)) { - error = "Could not download commit " + commitId + " from: " + Uri.EscapeDataString(objectRequestor.CacheServer.ObjectsEndpointUrl); + error = "Could not download commit " + commitId + " from: " + Uri.EscapeDataString(objectRequestor.CacheServer.ObjectsPostEndpointUrl); return false; } diff --git a/GVFS/GVFS/CommandLine/PrefetchVerb.cs b/GVFS/GVFS/CommandLine/PrefetchVerb.cs index 945984d62c..f82f4c0898 100644 --- a/GVFS/GVFS/CommandLine/PrefetchVerb.cs +++ b/GVFS/GVFS/CommandLine/PrefetchVerb.cs @@ -340,7 +340,9 @@ private void InitializeServerConnection( CacheServerResolver cacheServerResolver = new CacheServerResolver(tracer, enlistment); - resolvedCacheServer = cacheServerResolver.ResolveNameFromRemote(cacheServerFromConfig.Url, serverGVFSConfig); + resolvedCacheServer = cacheServerResolver + .ResolveNameFromRemote(cacheServerFromConfig.Url, serverGVFSConfig) + .WithEndpointOverridesFrom(cacheServerFromConfig); if (!this.SkipVersionCheck) { @@ -700,19 +702,11 @@ private string GetCacheServerDisplay(CacheServerInfo cacheServer, string repoUrl private bool IsPrefetchOffloadEnabled(ITracer tracer, GVFSEnlistment enlistment) { - try - { - using (LibGit2Repo repo = new LibGit2Repo(tracer, enlistment.WorkingDirectoryBackingRoot)) - { - bool? enabled = repo.GetConfigBool(GVFSConstants.GitConfig.PrefetchOffload); - return enabled ?? GVFSConstants.GitConfig.PrefetchOffloadDefault; - } - } - catch (Exception ex) - { - tracer.RelatedWarning($"Failed to read '{GVFSConstants.GitConfig.PrefetchOffload}' config; defaulting to {GVFSConstants.GitConfig.PrefetchOffloadDefault}: {ex.GetType().Name}: {ex.Message}"); - return GVFSConstants.GitConfig.PrefetchOffloadDefault; - } + return LibGit2Repo.GetConfigBoolOrDefault( + tracer, + enlistment.WorkingDirectoryBackingRoot, + GVFSConstants.GitConfig.PrefetchOffload, + GVFSConstants.GitConfig.PrefetchOffloadDefault); } /// diff --git a/docs/getting-started.md b/docs/getting-started.md index aee8b93844..75899bb0ae 100644 --- a/docs/getting-started.md +++ b/docs/getting-started.md @@ -38,6 +38,20 @@ These options allow a user to customize their initial enlistment. cache servers via the `/gvfs/config` endpoint, then the `clone` command will select a nearby cache server from that list. +* `--prefetch-cache-server-url=`, + `--get-cache-server-url=`, `--post-cache-server-url=`, and + `--sizes-cache-server-url=`: Prefer the specified absolute cache server + URL for `/gvfs/prefetch`, loose-object GET requests, batched-object POST + requests, or `/gvfs/sizes`, respectively. If a dedicated server fails, VFS + for Git retries the request against the server selected by + `--cache-server-url`. Sizes requests retain their additional fallback to the + origin server when the global cache does not support `/gvfs/sizes`. + + These values are saved in the local Git configuration as + `gvfs.prefetch.cache-server`, `gvfs.get.cache-server`, + `gvfs.post.cache-server`, and `gvfs.sizes.cache-server`. They continue to + apply to later mount, hydration, and prefetch operations. + * `--branch=`: Specify the branch to checkout after clone. * `--local-cache-path=`: Use this option to override the path for the diff --git a/docs/troubleshooting.md b/docs/troubleshooting.md index 44fa175482..8b91ed346a 100644 --- a/docs/troubleshooting.md +++ b/docs/troubleshooting.md @@ -237,6 +237,26 @@ Run `gvfs cache-server --list` to see the available cache server URLs. Run `gvfs cache-server --set=` to set your cache server to ``. +Individual GVFS protocol endpoints can prefer dedicated cache servers through +these local Git configuration values: + +| Configuration | Requests | +| --- | --- | +| `gvfs.prefetch.cache-server` | `/gvfs/prefetch` | +| `gvfs.get.cache-server` | Loose-object GET requests under `/gvfs/objects` | +| `gvfs.post.cache-server` | Batched-object POST requests to `/gvfs/objects` | +| `gvfs.sizes.cache-server` | `/gvfs/sizes` | + +Each value must be an absolute URL. A dedicated endpoint server is attempted +before `gvfs.cache-server`; if that request fails, VFS for Git falls back to +the global cache server. Sizes requests also fall back from the global cache +to the origin server when `/gvfs/sizes` is not supported. + +`gvfs cache-server --get` and `--set` operate on the global +`gvfs.cache-server` value. Setting the global server does not clear the four +endpoint-specific values. Inspect or change those values with `git config +--local []`. + ### System-wide Config The `gvfs config` command allows customizing some behavior.