diff --git a/src/EventLogExpert.Runtime/DatabaseTools/Elevation/ElevatedDatabaseToolsRunner.cs b/src/EventLogExpert.Runtime/DatabaseTools/Elevation/ElevatedDatabaseToolsRunner.cs index c35221023..ef85dab00 100644 --- a/src/EventLogExpert.Runtime/DatabaseTools/Elevation/ElevatedDatabaseToolsRunner.cs +++ b/src/EventLogExpert.Runtime/DatabaseTools/Elevation/ElevatedDatabaseToolsRunner.cs @@ -248,7 +248,7 @@ private void HandleCallerCancellation(Stream pipeStream, SemaphoreSlim writeLock var graceCts = new CancellationTokenSource(); killState.SetGraceTimer(graceCts); - _ = Task.Run(async () => + var killTask = Task.Run(async () => { try { @@ -276,6 +276,8 @@ private void HandleCallerCancellation(Stream pipeStream, SemaphoreSlim writeLock _traceLogger.Warning($"{ElevatedHelperTag} kill-timer task threw {ex.GetType().Name}: {ex.Message}"); } }); + + killState.SetKillTask(killTask); } private void MirrorMessageToDebugLog(DatabaseToolsIpcMessage message) @@ -493,6 +495,13 @@ private async Task RunAsync( // Helper sent a terminal message (or pipe closed). Cancel the kill-timer so it doesn't fire on a clean finish. killState.CancelGraceTimer(); + // Join the kill-timer so its disposition write happens-before the TranslateOutcome read. + try { await killState.KillTaskOrCompleted.WaitAsync(_exitGrace); } + catch (TimeoutException) + { + _traceLogger.Warning($"{ElevatedHelperTag} kill-timer did not settle within {_exitGrace.TotalSeconds:N0}s; proceeding with current disposition."); + } + // 7) Wait for helper to exit (bounded by _exitGrace, then force-kill if it lingers and is killable). int exitCode; try @@ -684,6 +693,7 @@ private sealed class KillState private int _cancelRequested; private int _disposition; private CancellationTokenSource? _graceTimerCts; + private Task? _killTask; public KillDisposition Disposition => (KillDisposition)Volatile.Read(ref _disposition); @@ -711,5 +721,9 @@ public void MarkKillFailed() => Interlocked.CompareExchange( public void MarkKillSucceeded() => Interlocked.Exchange(ref _disposition, (int)KillDisposition.Succeeded); public void SetGraceTimer(CancellationTokenSource cts) => Volatile.Write(ref _graceTimerCts, cts); + + public void SetKillTask(Task task) => Volatile.Write(ref _killTask, task); + + public Task KillTaskOrCompleted => Volatile.Read(ref _killTask) ?? Task.CompletedTask; } } diff --git a/tests/Integration/EventLogExpert.ElevationHelper.IntegrationTests/TestUtils/TestElevatedHelperProcessHost.cs b/tests/Integration/EventLogExpert.ElevationHelper.IntegrationTests/TestUtils/TestElevatedHelperProcessHost.cs index 837869425..68d715d83 100644 --- a/tests/Integration/EventLogExpert.ElevationHelper.IntegrationTests/TestUtils/TestElevatedHelperProcessHost.cs +++ b/tests/Integration/EventLogExpert.ElevationHelper.IntegrationTests/TestUtils/TestElevatedHelperProcessHost.cs @@ -7,15 +7,17 @@ using System.Diagnostics; using System.IO.Pipes; using System.Runtime.InteropServices; +using System.Text; namespace EventLogExpert.ElevationHelper.IntegrationTests.TestUtils; internal sealed class TestElevatedHelperProcessHost(ITraceLogger logger) : IElevatedHelperProcessHost { private const int MaxClientPidRejections = 32; + private const int MaxStderrChars = 4096; private const int PipeBufferSize = 65536; - private static readonly TimeSpan s_connectTimeout = TimeSpan.FromSeconds(15); + private static readonly TimeSpan s_connectTimeout = TimeSpan.FromSeconds(60); internal enum PidVerifyResult { @@ -67,24 +69,72 @@ public async Task StartAsync(IReadOnlyList extra helperProcess = Process.Start(psi) ?? throw new InvalidOperationException("Process.Start returned null without throwing."); var capturedPid = helperProcess.Id; - helperProcess.ErrorDataReceived += (_, e) => { if (e.Data is not null) { logger.Warning($"helper[{capturedPid}] stderr: {e.Data}"); } }; + var stderrLock = new object(); + var stderrBuffer = new StringBuilder(); + + helperProcess.ErrorDataReceived += (_, e) => + { + if (e.Data is null) { return; } + + logger.Warning($"helper[{capturedPid}] stderr: {e.Data}"); + + lock (stderrLock) + { + var remaining = MaxStderrChars - stderrBuffer.Length; + + if (remaining <= 0) { return; } + + stderrBuffer.Append(e.Data.Length <= remaining ? e.Data : e.Data[..remaining]); + + if (stderrBuffer.Length < MaxStderrChars) { stderrBuffer.Append('\n'); } + } + }; helperProcess.OutputDataReceived += (_, e) => { if (e.Data is not null) { logger.Information($"helper[{capturedPid}] stdout: {e.Data}"); } }; helperProcess.BeginErrorReadLine(); helperProcess.BeginOutputReadLine(); + string SnapshotStderr() { lock (stderrLock) { return stderrBuffer.ToString(); } } + logger.Information($"{nameof(TestElevatedHelperProcessHost)}: spawned helper PID {helperProcess.Id} (pipe={pipeName}, dotnet {helperDllPath})"); using var connectCts = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); connectCts.CancelAfter(s_connectTimeout); + // Watch for early helper exit on its own source so a connect timeout cannot misreport it as an exit. + using var exitWatchCts = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); + + var acceptTask = AcceptAndVerifyClientPidAsync(pipeServer, helperProcess.Id, logger, connectCts.Token); + var exitTask = WaitForExitOrCancelAsync(helperProcess, exitWatchCts.Token); + try { - await AcceptAndVerifyClientPidAsync(pipeServer, helperProcess.Id, logger, connectCts.Token); + var winner = await Task.WhenAny(acceptTask, exitTask); + + if (winner == exitTask && exitTask.Result && !acceptTask.IsCompletedSuccessfully) + { + throw new InvalidOperationException( + $"Elevated helper PID {helperProcess.Id} exited (exit code {helperProcess.ExitCode}) before connecting. stderr tail: {SnapshotStderr()}"); + } + + await acceptTask; } - catch (OperationCanceledException) when (!cancellationToken.IsCancellationRequested) + catch (OperationCanceledException) when (connectCts.IsCancellationRequested && !cancellationToken.IsCancellationRequested) { + if (helperProcess.HasExited) + { + throw new InvalidOperationException( + $"Elevated helper PID {helperProcess.Id} exited (exit code {helperProcess.ExitCode}) before connecting. stderr tail: {SnapshotStderr()}"); + } + throw new TimeoutException( - $"Elevated helper PID {helperProcess.Id} did not connect within {s_connectTimeout.TotalSeconds:N0}s."); + $"Elevated helper PID {helperProcess.Id} did not connect within {s_connectTimeout.TotalSeconds:N0}s (helper still running). stderr tail: {SnapshotStderr()}"); + } + finally + { + exitWatchCts.Cancel(); + connectCts.Cancel(); + await ObserveQuietly(acceptTask); + await ObserveQuietly(exitTask); } var handle = new TestElevatedHelperProcess(helperProcess, pipeServer, logger); @@ -185,6 +235,12 @@ private static string BuildArgumentString(string runtimeConfigPath, string helpe return string.Join(' ', parts.Select(QuoteIfNeeded)); } + private static async Task ObserveQuietly(Task task) + { + try { await task; } + catch { /* losing-race tasks throw on cleanup cancellation; observed and dropped */ } + } + private static string QuoteIfNeeded(string arg) { if (string.IsNullOrEmpty(arg)) { return "\"\""; } @@ -210,6 +266,20 @@ private static string ResolveTestRuntimeConfig() return testRuntimeConfig; } + private static async Task WaitForExitOrCancelAsync(Process process, CancellationToken cancellationToken) + { + try + { + await process.WaitForExitAsync(cancellationToken); + + return true; + } + catch (OperationCanceledException) + { + return false; + } + } + private static class NativeMethods { [DllImport("kernel32.dll", SetLastError = true)]