diff --git a/.github/workflows/functional-tests.yaml b/.github/workflows/functional-tests.yaml index 9b14047aa..d4f1819d5 100644 --- a/.github/workflows/functional-tests.yaml +++ b/.github/workflows/functional-tests.yaml @@ -204,8 +204,18 @@ 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 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@v7 diff --git a/GVFS/GVFS.FunctionalTests/Tests/TestResultsHelper.cs b/GVFS/GVFS.FunctionalTests/Tests/TestResultsHelper.cs index e70adca78..3c197a1ec 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/GVFSFunctionalTestEnlistment.cs b/GVFS/GVFS.FunctionalTests/Tools/GVFSFunctionalTestEnlistment.cs index 15880551b..e5868a6c2 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; @@ -169,10 +171,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); @@ -293,6 +387,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(); @@ -310,12 +408,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 }}\"", @@ -323,30 +448,56 @@ 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}"); } } } + + 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 000000000..57356f44c --- /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); + } +}