diff --git a/docs/claude-reference.md b/docs/claude-reference.md index 0c15e02a..b64325fe 100644 --- a/docs/claude-reference.md +++ b/docs/claude-reference.md @@ -23,6 +23,14 @@ verwalteten WinRM-Pfad. Ohne Maschine beziehungsweise bei Loopback ohne Credenti läuft es lokal auf dem API-Host. `engine: auto` startet Nutzerskripte in Windows PowerShell 5.1. Eingebaute Activities verwenden lokal den In-Process-Pool. +`Engine:MaxCapturedOutputChars` begrenzt die während einer Skriptausführung gesammelte +Ausgabe über alle Streams auf insgesamt 16.777.216 Zeichen (positiver Wert, Neustart erforderlich). +Der Standard lässt Platz für die beiden auf je 1 MiB begrenzten Ausgaben von `startProgram` +einschließlich JSON-Escaping. Kleinere Werte begrenzen auch diese Aktivität entsprechend. +Das gemeinsame Limit gilt für Prozess-, Runspace- und WinRM-Ausführung. Überschreitung +beendet den Schritt mit einem Ausgabelimit-Fehler; das spätere Kürzen gespeicherter Ergebnisse +ist davon unabhängig. Prozess-Pipes werden auch nach Erreichen des Limits weiter geleert. + Selbst aufgebautes Remoting innerhalb eines lokalen Skripts liegt außerhalb der verwalteten WinRM-Verbindung. Dabei entfallen deren Credential-Anbindung, Target-Zuordnung, Telemetrie und Transport-Hardening. Das Skript muss seine diff --git a/src/NodePilot.Api/appsettings.json b/src/NodePilot.Api/appsettings.json index 98bfc01d..0b1c6fa4 100644 --- a/src/NodePilot.Api/appsettings.json +++ b/src/NodePilot.Api/appsettings.json @@ -161,6 +161,7 @@ }, "MaxConcurrentSteps": 600, "IsolatedDrainGraceSeconds": 5, + "MaxCapturedOutputChars": 16777216, "Runspace": { "MinRunspaces": 256, "MaxRunspaces": 768 diff --git a/src/NodePilot.Core/Execution/ScriptOutputBudget.cs b/src/NodePilot.Core/Execution/ScriptOutputBudget.cs new file mode 100644 index 00000000..3eb3c4aa --- /dev/null +++ b/src/NodePilot.Core/Execution/ScriptOutputBudget.cs @@ -0,0 +1,64 @@ +using System.Text; + +namespace NodePilot.Core.Execution; + +/// A shared character budget for all output streams of one script invocation. +public sealed class ScriptOutputBudget : IDisposable +{ + public const string ConfigurationKey = "Engine:MaxCapturedOutputChars"; + // Fits Start Program's two capped 1 MiB streams, including JSON escape expansion. + public const int DefaultLimit = 16 * 1024 * 1024; + private readonly object _gate = new(); + private readonly CancellationTokenSource _limitReached = new(); + private readonly int _limit; + private int _captured; + private bool _disposed; + + public ScriptOutputBudget(int limit = DefaultLimit) + { + ArgumentOutOfRangeException.ThrowIfNegativeOrZero(limit); + _limit = limit; + } + + public CancellationToken LimitReached => _limitReached.Token; + public bool Exceeded { get; private set; } + public string Error => $"Script output limit of {_limit} characters exceeded ({ConfigurationKey})."; + public Buffer CreateBuffer() => new(this); + + public sealed class Buffer(ScriptOutputBudget budget) + { + private readonly StringBuilder _text = new(); + public string Text { get { lock (budget._gate) return _text.ToString(); } } + + public void Append(ReadOnlySpan value) + { + lock (budget._gate) + { + if (budget._disposed || budget.Exceeded) return; + var count = Math.Min(value.Length, budget._limit - budget._captured); + _text.Append(value[..count]); + budget._captured += count; + if (count < value.Length) + { + budget.Exceeded = true; + budget._limitReached.Cancel(); + } + } + } + + public void AppendLine(string value) + { + Append(value); + Append(Environment.NewLine); + } + } + + public void Dispose() + { + lock (_gate) + { + _disposed = true; + _limitReached.Dispose(); + } + } +} diff --git a/src/NodePilot.Engine/PowerShell/PowerShellEngineFactory.cs b/src/NodePilot.Engine/PowerShell/PowerShellEngineFactory.cs index 34c45ea8..cf0cc3be 100644 --- a/src/NodePilot.Engine/PowerShell/PowerShellEngineFactory.cs +++ b/src/NodePilot.Engine/PowerShell/PowerShellEngineFactory.cs @@ -1,6 +1,7 @@ using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Logging; using NodePilot.Core.Configuration; +using NodePilot.Core.Execution; namespace NodePilot.Engine.PowerShell; @@ -43,8 +44,9 @@ public PowerShellEngineFactory( var drainGraceSeconds = configuration?.GetValue("Engine:IsolatedDrainGraceSeconds") ?? 5; var isolatedDrainGrace = drainGraceSeconds > 0 ? TimeSpan.FromSeconds(drainGraceSeconds) : (TimeSpan?)null; - _pwsh = ProcessExecutionEngine.CreatePwsh(logger, isolatedDrainGrace); - _windowsPowerShell = ProcessExecutionEngine.CreateWindowsPowerShell(logger, isolatedDrainGrace); + var outputLimit = configuration?.GetValue(ScriptOutputBudget.ConfigurationKey) ?? ScriptOutputBudget.DefaultLimit; + _pwsh = ProcessExecutionEngine.CreatePwsh(logger, isolatedDrainGrace, outputLimit); + _windowsPowerShell = ProcessExecutionEngine.CreateWindowsPowerShell(logger, isolatedDrainGrace, outputLimit); ProcessExecutionEngine.DeleteOrphanedTempScripts(logger); // Runspace pool sizing belongs to the process-wide PerformancePlan (hardware-derived, @@ -56,7 +58,7 @@ public PowerShellEngineFactory( new Dictionary()); var minRunspaces = plan.MinRunspaces.Value; var maxRunspaces = plan.MaxRunspaces.Value; - _runspace = new RunspaceExecutionEngine(logger, minRunspaces, maxRunspaces); + _runspace = new RunspaceExecutionEngine(logger, minRunspaces, maxRunspaces, outputLimit); logger.LogInformation("PowerShell engines: pwsh={PwshAvailable}, powershell={PSAvailable}, runspace=true (min={Min}, max={Max})", _pwsh.IsAvailable, _windowsPowerShell.IsAvailable, minRunspaces, maxRunspaces); diff --git a/src/NodePilot.Engine/PowerShell/ProcessExecutionEngine.cs b/src/NodePilot.Engine/PowerShell/ProcessExecutionEngine.cs index 3cc888ed..f2802643 100644 --- a/src/NodePilot.Engine/PowerShell/ProcessExecutionEngine.cs +++ b/src/NodePilot.Engine/PowerShell/ProcessExecutionEngine.cs @@ -4,6 +4,7 @@ using System.Security.Principal; using System.Text; using Microsoft.Extensions.Logging; +using NodePilot.Core.Execution; using NodePilot.Engine.Security; namespace NodePilot.Engine.PowerShell; @@ -17,6 +18,7 @@ public class ProcessExecutionEngine : IPowerShellExecutionEngine { private readonly string _executable; private readonly ILogger _logger; + private readonly int _maxCapturedOutputChars; // Grace period for the stdout/stderr drain AFTER the script process has exited (isolated: and // its job tree has been terminated). A read still open then is held by an inherited pipe @@ -114,25 +116,29 @@ internal static void DeleteOrphanedTempScripts(ILogger logger, string? directory // NodePilot.Engine.Tests access; production still uses the CreatePwsh/CreateWindowsPowerShell // factory methods. internal ProcessExecutionEngine(string engineType, string executable, bool available, ILogger logger, - TimeSpan? isolatedDrainGrace = null) + TimeSpan? isolatedDrainGrace = null, int maxCapturedOutputChars = ScriptOutputBudget.DefaultLimit) { EngineType = engineType; _executable = executable; IsAvailable = available; _logger = logger; + ArgumentOutOfRangeException.ThrowIfNegativeOrZero(maxCapturedOutputChars); + _maxCapturedOutputChars = maxCapturedOutputChars; _isolatedDrainGrace = isolatedDrainGrace is { } g && g > TimeSpan.Zero ? g : TimeSpan.FromSeconds(5); } - public static ProcessExecutionEngine CreatePwsh(ILogger logger, TimeSpan? isolatedDrainGrace = null) + public static ProcessExecutionEngine CreatePwsh(ILogger logger, TimeSpan? isolatedDrainGrace = null, + int maxCapturedOutputChars = ScriptOutputBudget.DefaultLimit) { var path = FindExecutable("pwsh.exe", "pwsh"); - return new ProcessExecutionEngine("pwsh", path ?? "pwsh.exe", path is not null, logger, isolatedDrainGrace); + return new ProcessExecutionEngine("pwsh", path ?? "pwsh.exe", path is not null, logger, isolatedDrainGrace, maxCapturedOutputChars); } - public static ProcessExecutionEngine CreateWindowsPowerShell(ILogger logger, TimeSpan? isolatedDrainGrace = null) + public static ProcessExecutionEngine CreateWindowsPowerShell(ILogger logger, TimeSpan? isolatedDrainGrace = null, + int maxCapturedOutputChars = ScriptOutputBudget.DefaultLimit) { var path = FindExecutable("powershell.exe", "powershell"); - return new ProcessExecutionEngine("powershell", path ?? "powershell.exe", path is not null, logger, isolatedDrainGrace); + return new ProcessExecutionEngine("powershell", path ?? "powershell.exe", path is not null, logger, isolatedDrainGrace, maxCapturedOutputChars); } public async Task ExecuteAsync(PowerShellExecutionRequest request, CancellationToken ct) @@ -181,14 +187,9 @@ public async Task ExecuteAsync(PowerShellExecutionReq // background program the script started without a new window (Start-Process // -NoNewWindow, cmd /c start) inherits the pipes and would hold the step until it exits. using var process = new Process { StartInfo = psi, EnableRaisingEvents = true }; - var stdout = new StringBuilder(); - var stderr = new StringBuilder(); - var stdoutClosed = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); - var stderrClosed = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + using var budget = new ScriptOutputBudget(_maxCapturedOutputChars); var exited = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); - process.OutputDataReceived += (_, e) => Collect(stdout, stdoutClosed, e.Data); - process.ErrorDataReceived += (_, e) => Collect(stderr, stderrClosed, e.Data); process.Exited += (_, _) => exited.TrySetResult(); _logger.LogDebug("Starting {Engine}: {File}", EngineType, tempScript); @@ -200,10 +201,10 @@ public async Task ExecuteAsync(PowerShellExecutionReq { process.Start(); } - process.BeginOutputReadLine(); - process.BeginErrorReadLine(); + var stdout = new OutputCapture(process.StandardOutput, ct, budget.CreateBuffer()); + var stderr = new OutputCapture(process.StandardError, ct, budget.CreateBuffer()); - using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct); + using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct, budget.LimitReached); if (request.Timeout is { } configuredTimeout) cts.CancelAfter(configuredTimeout); @@ -220,11 +221,16 @@ public async Task ExecuteAsync(PowerShellExecutionReq // The process is killed either way; only the verdict differs. if (ct.IsCancellationRequested) throw new OperationCanceledException(IPowerShellExecutionEngine.CancelledMessage, ct); + if (budget.Exceeded) + { + await DrainReadsAsync(stdout, stderr, _isolatedDrainGrace, ct); + return EngineFailure(budget.Error, sw.Elapsed); + } return new PowerShellExecutionResult { Success = false, ExitCode = -1, - Output = Snapshot(stdout).TrimEnd(), + Output = stdout.Text.TrimEnd(), Error = $"Script execution timed out after {request.Timeout!.Value.TotalSeconds:0}s", TimedOut = true, Duration = sw.Elapsed, @@ -233,11 +239,8 @@ public async Task ExecuteAsync(PowerShellExecutionReq // The script has exited, so everything it wrote is in the pipes. A read still open // after the grace is held by a background program; keep what has been collected. - try - { - await Task.WhenAll(stdoutClosed.Task, stderrClosed.Task).WaitAsync(_isolatedDrainGrace, ct); - } - catch (TimeoutException) + var drain = await DrainReadsAsync(stdout, stderr, _isolatedDrainGrace, ct); + if (drain.DrainTimedOut) { _logger.LogDebug( "{Engine} (pid {Pid}): output stayed open {Grace:0}s after the script exited; a background " + @@ -246,8 +249,9 @@ public async Task ExecuteAsync(PowerShellExecutionReq } sw.Stop(); - var stdoutText = Snapshot(stdout); - var stderrText = StripSerializedStreams(Snapshot(stderr)).TrimEnd(); + if (budget.Exceeded) return EngineFailure(budget.Error, sw.Elapsed); + var stdoutText = stdout.Text; + var stderrText = StripSerializedStreams(stderr.Text).TrimEnd(); return new PowerShellExecutionResult { // Error-based success, as over WinRM (!HadErrors): the script failed if it wrote @@ -302,11 +306,12 @@ private async Task ExecuteIsolatedWindowsAsync(PowerS // Start draining the pipes IMMEDIATELY and concurrently with the wait — a noisy script // would otherwise deadlock once the pipe buffers fill (child blocks writing, we block - // on exit). Mirrors BeginOutputReadLine on the non-isolated path. - var stdoutCapture = new OutputCapture(launched.StandardOutput, ct); - var stderrCapture = new OutputCapture(launched.StandardError, ct); + // on exit). Both process paths use fixed-size reads, including lines without a newline. + using var budget = new ScriptOutputBudget(_maxCapturedOutputChars); + var stdoutCapture = new OutputCapture(launched.StandardOutput, ct, budget.CreateBuffer()); + var stderrCapture = new OutputCapture(launched.StandardError, ct, budget.CreateBuffer()); - using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct); + using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct, budget.LimitReached); if (request.Timeout is { } configuredTimeout) cts.CancelAfter(configuredTimeout); @@ -319,7 +324,7 @@ private async Task ExecuteIsolatedWindowsAsync(PowerS catch (OperationCanceledException) { userCancel = ct.IsCancellationRequested; - timedOut = !userCancel; + timedOut = !userCancel && !budget.Exceeded; } // Step-end semantics: the step ends when the ROOT process exits (or we time out / @@ -364,6 +369,8 @@ private async Task ExecuteIsolatedWindowsAsync(PowerS if (userCancel || ct.IsCancellationRequested) throw new OperationCanceledException(IPowerShellExecutionEngine.CancelledMessage, ct); + if (budget.Exceeded) return EngineFailure(budget.Error, sw.Elapsed); + if (timedOut) { return new PowerShellExecutionResult @@ -462,13 +469,15 @@ private async Task ExecuteIsolatedWindowsAsync(PowerS internal sealed class OutputCapture { - private readonly StringBuilder _output = new(); + private readonly ScriptOutputBudget.Buffer _output; internal Task Completion { get; } - internal string Text => Snapshot(_output); + internal string Text => _output.Text; - internal OutputCapture(TextReader reader, CancellationToken ct) + internal OutputCapture(TextReader reader, CancellationToken ct, ScriptOutputBudget.Buffer? output = null) { + _output = output ?? new ScriptOutputBudget().CreateBuffer(); Completion = ReadAsync(reader, ct); + ObserveAbandonedRead(Completion); } private async Task ReadAsync(TextReader reader, CancellationToken ct) @@ -477,24 +486,11 @@ private async Task ReadAsync(TextReader reader, CancellationToken ct) int count; while ((count = await reader.ReadAsync(buffer.AsMemory(), ct).ConfigureAwait(false)) != 0) { - lock (_output) _output.Append(buffer, 0, count); + _output.Append(buffer.AsSpan(0, count)); } } } - // Line callbacks of one stream arrive in order, but a snapshot may be taken while they still - // run, hence the lock. A null line is the stream's end. - private static void Collect(StringBuilder sink, TaskCompletionSource closed, string? line) - { - if (line is null) { closed.TrySetResult(); return; } - lock (sink) sink.AppendLine(line); - } - - private static string Snapshot(StringBuilder sink) - { - lock (sink) return sink.ToString(); - } - /// /// The engine never got far enough to have a script result: no exit code, no output, just /// the reason. Callers stop the stopwatch first so the reported duration excludes the diff --git a/src/NodePilot.Engine/PowerShell/RunspaceExecutionEngine.cs b/src/NodePilot.Engine/PowerShell/RunspaceExecutionEngine.cs index bf826737..bde4623d 100644 --- a/src/NodePilot.Engine/PowerShell/RunspaceExecutionEngine.cs +++ b/src/NodePilot.Engine/PowerShell/RunspaceExecutionEngine.cs @@ -1,8 +1,9 @@ using System.Diagnostics; using System.Management.Automation; using System.Management.Automation.Runspaces; -using System.Text; using Microsoft.Extensions.Logging; +using NodePilot.Core.Execution; +using NodePilot.Remote; namespace NodePilot.Engine.PowerShell; @@ -19,15 +20,19 @@ public sealed class RunspaceExecutionEngine : IPowerShellExecutionEngine, IDispo private readonly RunspacePool? _pool; private readonly bool _initFailed; private readonly string? _initError; + private readonly int _maxCapturedOutputChars; public string EngineType => "runspace"; public bool IsAvailable => !_initFailed; - public RunspaceExecutionEngine(ILogger logger, int minRunspaces = 1, int maxRunspaces = 5) + public RunspaceExecutionEngine(ILogger logger, int minRunspaces = 1, int maxRunspaces = 5, + int maxCapturedOutputChars = ScriptOutputBudget.DefaultLimit) { _logger = logger; _minRunspaces = minRunspaces; _maxRunspaces = maxRunspaces; + ArgumentOutOfRangeException.ThrowIfNegativeOrZero(maxCapturedOutputChars); + _maxCapturedOutputChars = maxCapturedOutputChars; try { @@ -124,10 +129,6 @@ public async Task ExecuteAsync(PowerShellExecutionReq private async Task ExecuteOnceAsync(PowerShellExecutionRequest request, CancellationToken ct) { var sw = Stopwatch.StartNew(); - var output = new StringBuilder(); - var errors = new StringBuilder(); - var warnings = new StringBuilder(); - var verbose = new StringBuilder(); if (ct.IsCancellationRequested) throw new OperationCanceledException(IPowerShellExecutionEngine.CancelledMessage, ct); @@ -137,14 +138,14 @@ private async Task ExecuteOnceAsync(PowerShellExecuti ps.RunspacePool = _pool; ps.AddScript(PowerShellScriptWrapper.Wrap(request.ScriptText, request.Parameters, _logger, request.OutputCaptureAllowlist)); - using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct); - if (request.Timeout is { } configuredTimeout) - cts.CancelAfter(configuredTimeout); - // BeginInvoke queues work without parking a ThreadPool worker. Stop can complete a // queued invocation without throwing, so both EndInvoke and the terminal state matter. // Own output buffer: it keeps what the script wrote before a terminating error. var results = new PSDataCollection(); + using var capture = new PowerShellOutputCapture(ps, results, _maxCapturedOutputChars); + using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct, capture.Budget.LimitReached); + if (request.Timeout is { } configuredTimeout) + cts.CancelAfter(configuredTimeout); IAsyncResult asyncResult; try { @@ -176,40 +177,36 @@ private async Task ExecuteOnceAsync(PowerShellExecuti var finished = await Task.WhenAny(invokeTask, GraceElapsedAfterCancelAsync(cts.Token, waitDone.Token)); waitDone.Cancel(); if (finished != invokeTask && !invokeTask.IsCompleted) - return AbandonPipeline(request, ct, ps, results, invokeTask, stopTask, sw); + return AbandonPipeline(request, ct, ps, results, invokeTask, stopTask, sw, capture.Budget); } try { await invokeTask; + if (ct.IsCancellationRequested) + throw new OperationCanceledException(IPowerShellExecutionEngine.CancelledMessage, ct); + if (capture.Budget.Exceeded) + return OutputLimitResult(capture.Budget, sw.Elapsed); var invocationState = ps.InvocationStateInfo; if (invocationState.State == PSInvocationState.Stopped) throw new PipelineStoppedException(); - foreach (var r in results) - output.AppendLine(SafeToString(r)); - foreach (var e in ps.Streams.Error) - errors.AppendLine(SafeToString(e)); - foreach (var w in ps.Streams.Warning) - warnings.AppendLine(SafeToString(w)); - foreach (var v in ps.Streams.Verbose) - verbose.AppendLine(SafeToString(v)); - sw.Stop(); // Non-terminating errors still indicate that the step did not complete cleanly. // Treating "any stdout" as success lets workflows continue after Write-Error. - var success = invocationState.State == PSInvocationState.Completed && !ps.HadErrors; - if (!success && errors.Length == 0) - errors.Append(invocationState.Reason?.Message - ?? $"Script execution ended in state '{invocationState.State}'."); + var error = capture.Errors.Text.TrimEnd(); + var success = invocationState.State == PSInvocationState.Completed && !ps.HadErrors && error.Length == 0; + if (!success && error.Length == 0) + error = invocationState.Reason?.Message + ?? $"Script execution ended in state '{invocationState.State}'."; return new PowerShellExecutionResult { Success = success, ExitCode = success ? 0 : 1, - Output = output.ToString().TrimEnd(), - Error = errors.ToString().TrimEnd(), - Warning = warnings.ToString().TrimEnd(), - Verbose = verbose.ToString().TrimEnd(), + Output = capture.Output.Text.TrimEnd(), + Error = error, + Warning = capture.Warnings.Text.TrimEnd(), + Verbose = capture.Verbose.Text.TrimEnd(), Duration = sw.Elapsed, }; } @@ -219,19 +216,22 @@ private async Task ExecuteOnceAsync(PowerShellExecuti // Caller cancellation reaches StepRunner as Cancelled; an internal timeout is Failed. if (ct.IsCancellationRequested) throw new OperationCanceledException(IPowerShellExecutionEngine.CancelledMessage, ct); + if (capture.Budget.Exceeded) + return OutputLimitResult(capture.Budget, sw.Elapsed); return StoppedResult(request, cts.IsCancellationRequested, sw.Elapsed); } catch (Exception ex) { sw.Stop(); - // A script that throws still published its output markers before the throw. - foreach (var r in results) - output.AppendLine(SafeToString(r)); + if (ct.IsCancellationRequested) + throw new OperationCanceledException(IPowerShellExecutionEngine.CancelledMessage, ct); + if (capture.Budget.Exceeded) + return OutputLimitResult(capture.Budget, sw.Elapsed); return new PowerShellExecutionResult { Success = false, ExitCode = -1, - Output = output.ToString().TrimEnd(), + Output = capture.Output.Text.TrimEnd(), Error = ex.Message, Duration = sw.Elapsed, }; @@ -248,7 +248,7 @@ private async Task ExecuteOnceAsync(PowerShellExecuti // so disposal waits for the pipeline to end, which also returns its runspace to the pool. private PowerShellExecutionResult AbandonPipeline( PowerShellExecutionRequest request, CancellationToken ct, System.Management.Automation.PowerShell ps, - PSDataCollection results, Task invokeTask, Task? stopTask, Stopwatch sw) + PSDataCollection results, Task invokeTask, Task? stopTask, Stopwatch sw, ScriptOutputBudget budget) { sw.Stop(); _logger.LogError( @@ -269,9 +269,18 @@ private PowerShellExecutionResult AbandonPipeline( if (ct.IsCancellationRequested) throw new OperationCanceledException(IPowerShellExecutionEngine.CancelledMessage, ct); + if (budget.Exceeded) return OutputLimitResult(budget, sw.Elapsed); return StoppedResult(request, stopRequested: true, sw.Elapsed); } + private static PowerShellExecutionResult OutputLimitResult(ScriptOutputBudget budget, TimeSpan duration) => new() + { + Success = false, + ExitCode = -1, + Error = budget.Error, + Duration = duration, + }; + private static PowerShellExecutionResult StoppedResult(PowerShellExecutionRequest request, bool stopRequested, TimeSpan duration) { var timedOut = stopRequested && request.Timeout.HasValue; @@ -302,25 +311,4 @@ public void Dispose() _pool?.Dispose(); } - // PSObject.ToString() can trigger the formatter (e.g. Format-Default) which itself needs a - // runspace. When the pool runspace is mid-recycle or the object's formatter chain throws, - // the bare ToString() call fails with "There is no Runspace available to run scripts in - // this thread." Empirically seen for New-Service's ServiceController output. We unwrap to - // BaseObject first (primitives, ServiceController.ServiceName etc. format safely) and fall - // back to a typed placeholder if every ToString path throws — never let formatter errors - // tear down step output. - private static string SafeToString(object? value) - { - if (value is null) return string.Empty; - if (value is PSObject ps) - { - var baseObj = ps.BaseObject; - if (baseObj is string s) return s; - try { return baseObj?.ToString() ?? string.Empty; } catch { /* fall through */ } - try { return ps.ToString() ?? string.Empty; } catch { /* fall through */ } - return $"<{baseObj?.GetType().Name ?? "PSObject"}: ToString failed>"; - } - try { return value.ToString() ?? string.Empty; } - catch { return $"<{value.GetType().Name}: ToString failed>"; } - } } diff --git a/src/NodePilot.Remote/PowerShellOutputCapture.cs b/src/NodePilot.Remote/PowerShellOutputCapture.cs new file mode 100644 index 00000000..b5cb5f5f --- /dev/null +++ b/src/NodePilot.Remote/PowerShellOutputCapture.cs @@ -0,0 +1,56 @@ +using System.Management.Automation; +using NodePilot.Core.Execution; + +namespace NodePilot.Remote; + +/// Drains SDK collections as records arrive, retaining only bounded text. +public sealed class PowerShellOutputCapture : IDisposable +{ + public ScriptOutputBudget Budget { get; } + public ScriptOutputBudget.Buffer Output { get; } + public ScriptOutputBudget.Buffer Errors { get; } + public ScriptOutputBudget.Buffer Warnings { get; } + public ScriptOutputBudget.Buffer Verbose { get; } + + public PowerShellOutputCapture(PowerShell ps, PSDataCollection results, int limit) + { + Budget = new ScriptOutputBudget(limit); + Output = Budget.CreateBuffer(); + Errors = Budget.CreateBuffer(); + Warnings = Budget.CreateBuffer(); + Verbose = Budget.CreateBuffer(); + Attach(results, Output); + Attach(ps.Streams.Error, Errors); + Attach(ps.Streams.Warning, Warnings); + Attach(ps.Streams.Verbose, Verbose); + Attach(ps.Streams.Debug, Budget.CreateBuffer()); + Attach(ps.Streams.Information, Budget.CreateBuffer()); + Attach(ps.Streams.Progress, Budget.CreateBuffer()); + } + + private void Attach(PSDataCollection stream, ScriptOutputBudget.Buffer buffer) + { + stream.DataAdded += (_, _) => + { + foreach (var value in stream.ReadAll()) + if (!Budget.Exceeded) buffer.AppendLine(SafeToString(value)); + }; + } + + private static string SafeToString(object? value) + { + if (value is null) return string.Empty; + if (value is PSObject ps) + { + var baseObj = ps.BaseObject; + if (baseObj is string s) return s; + try { return baseObj?.ToString() ?? string.Empty; } catch { } + try { return ps.ToString() ?? string.Empty; } catch { } + return $"<{baseObj?.GetType().Name ?? "PSObject"}: ToString failed>"; + } + try { return value.ToString() ?? string.Empty; } + catch { return $"<{value.GetType().Name}: ToString failed>"; } + } + + public void Dispose() => Budget.Dispose(); +} diff --git a/src/NodePilot.Remote/WinRmSession.cs b/src/NodePilot.Remote/WinRmSession.cs index ffdd9c40..6546cb36 100644 --- a/src/NodePilot.Remote/WinRmSession.cs +++ b/src/NodePilot.Remote/WinRmSession.cs @@ -3,6 +3,7 @@ using System.Management.Automation.Runspaces; using System.Text; using NodePilot.Core.Interfaces; +using NodePilot.Core.Execution; namespace NodePilot.Remote; @@ -10,6 +11,7 @@ public class WinRmSession : IRemoteSession { private readonly Runspace _runspace; private readonly string? _targetHostname; + private readonly int _maxCapturedOutputChars; // Set when a timeout or cancellation cut through ExecuteScriptAsync while it was still // running. PowerShell.Invoke() doesn't observe the cancellation token directly — Task.Run // only abandons the awaiter while the pipeline keeps running on the threadpool. Once that @@ -17,10 +19,13 @@ public class WinRmSession : IRemoteSession // pool consumer, so we mark the session poisoned and let the pool discard it on Return. private int _poisoned; - public WinRmSession(Runspace runspace, string? targetHostname = null) + public WinRmSession(Runspace runspace, string? targetHostname = null, + int maxCapturedOutputChars = ScriptOutputBudget.DefaultLimit) { _runspace = runspace; _targetHostname = targetHostname; + ArgumentOutOfRangeException.ThrowIfNegativeOrZero(maxCapturedOutputChars); + _maxCapturedOutputChars = maxCapturedOutputChars; } /// @@ -60,8 +65,6 @@ private async Task ExecuteOnceAsync(string script, int? t activity?.SetTag("nodepilot.remote.timeout_sec", timeoutSeconds); var sw = Stopwatch.StartNew(); - var output = new StringBuilder(); - var errors = new StringBuilder(); using var ps = PowerShell.Create(); ps.Runspace = _runspace; @@ -73,13 +76,14 @@ private async Task ExecuteOnceAsync(string script, int? t // // timeoutSeconds null or <=0 means "no timeout" — only the parent cancellation token (ct) // can cancel the call. - using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct); + using var results = new PSDataCollection(); + using var capture = new PowerShellOutputCapture(ps, results, _maxCapturedOutputChars); + using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct, capture.Budget.LimitReached); if (timeoutSeconds is { } secs && secs > 0) cts.CancelAfter(TimeSpan.FromSeconds(secs)); // Own output buffer: it keeps what the script wrote before a terminating error, which // EndInvoke's return value would lose when it throws. - using var results = new PSDataCollection(); IAsyncResult asyncResult; try { @@ -102,28 +106,21 @@ private async Task ExecuteOnceAsync(string script, int? t } using var ctRegistration = cts.Token.Register(() => - { - try { ps.Stop(); } catch { /* best-effort: pipeline may already be torn down */ } - }); + _ = Task.Run(() => { try { ps.Stop(); } catch { /* pipeline may already be torn down */ } })); try { await Task.Factory.FromAsync(asyncResult, ps.EndInvoke); - - foreach (var result in results) - output.AppendLine(result?.ToString()); - - foreach (var error in ps.Streams.Error) - errors.AppendLine(error.ToString()); + if (cts.IsCancellationRequested) throw new PipelineStoppedException(); sw.Stop(); - var stdout = output.ToString().TrimEnd(); - var stderr = errors.ToString().TrimEnd(); + var stdout = capture.Output.Text.TrimEnd(); + var stderr = capture.Errors.Text.TrimEnd(); activity?.SetTag("nodepilot.remote.stdout.bytes", Encoding.UTF8.GetByteCount(stdout)); activity?.SetTag("nodepilot.remote.stderr.bytes", Encoding.UTF8.GetByteCount(stderr)); - var success = !ps.HadErrors; + var success = !ps.HadErrors && stderr.Length == 0; if (success) activity?.SetStatus(ActivityStatusCode.Ok); else @@ -147,6 +144,13 @@ private async Task ExecuteOnceAsync(string script, int? t Volatile.Write(ref _poisoned, 1); sw.Stop(); var cancelled = ct.IsCancellationRequested; + if (capture.Budget.Exceeded && !cancelled) + { + activity?.SetStatus(ActivityStatusCode.Error, "output_limit"); + RemoteMetrics.ScriptDuration.Record(sw.Elapsed.TotalMilliseconds, + new KeyValuePair("result", "fail")); + return new RemoteExecutionResult { Success = false, ErrorOutput = capture.Budget.Error, Duration = sw.Elapsed }; + } activity?.SetStatus(ActivityStatusCode.Error, cancelled ? "cancelled" : "timeout"); activity?.SetTag("nodepilot.remote.timeout", true); RemoteMetrics.ScriptTimeouts.Add(1); @@ -174,13 +178,10 @@ private async Task ExecuteOnceAsync(string script, int? t activity?.SetTag("exception.type", ex.GetType().FullName); RemoteMetrics.ScriptDuration.Record(sw.Elapsed.TotalMilliseconds, new KeyValuePair("result", "fail")); - // A script that throws still published its output markers before the throw. - foreach (var result in results) - output.AppendLine(result?.ToString()); return new RemoteExecutionResult { Success = false, - Output = output.ToString().TrimEnd(), + Output = capture.Output.Text.TrimEnd(), ErrorOutput = ex.Message, Duration = sw.Elapsed }; diff --git a/src/NodePilot.Remote/WinRmSessionFactory.cs b/src/NodePilot.Remote/WinRmSessionFactory.cs index bf647838..936c3756 100644 --- a/src/NodePilot.Remote/WinRmSessionFactory.cs +++ b/src/NodePilot.Remote/WinRmSessionFactory.cs @@ -4,6 +4,7 @@ using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Logging; using NodePilot.Core.Exceptions; +using NodePilot.Core.Execution; using NodePilot.Core.Interfaces; using NodePilot.Core.Models; @@ -16,6 +17,7 @@ public class WinRmSessionFactory : IRemoteSessionFactory private readonly ICredentialStore _credentialStore; private readonly IConfiguration? _configuration; private readonly ILogger? _logger; + private readonly int _maxCapturedOutputChars; public WinRmSessionFactory(ICredentialStore credentialStore) : this(credentialStore, null, null) { } @@ -28,6 +30,8 @@ public WinRmSessionFactory( _credentialStore = credentialStore; _configuration = configuration; _logger = logger; + _maxCapturedOutputChars = configuration?.GetValue(ScriptOutputBudget.ConfigurationKey) ?? ScriptOutputBudget.DefaultLimit; + ArgumentOutOfRangeException.ThrowIfNegativeOrZero(_maxCapturedOutputChars); } // virtual: lets test subclasses replace the real WinRM connect logic without the pool having @@ -185,7 +189,7 @@ public virtual async Task CreateSessionAsync(ManagedMachine mach RemoteMetrics.SessionOpenDuration.Record(connectStopwatch.Elapsed.TotalMilliseconds, okTag, authTag); RemoteMetrics.SessionsActive.Add(1); - return new WinRmSession(runspace, machine.Hostname); + return new WinRmSession(runspace, machine.Hostname, _maxCapturedOutputChars); } /// diff --git a/tests/NodePilot.Engine.Tests/Activities/StartProgramResourceCleanupTests.cs b/tests/NodePilot.Engine.Tests/Activities/StartProgramResourceCleanupTests.cs index 9dd394df..8356bf14 100644 --- a/tests/NodePilot.Engine.Tests/Activities/StartProgramResourceCleanupTests.cs +++ b/tests/NodePilot.Engine.Tests/Activities/StartProgramResourceCleanupTests.cs @@ -130,14 +130,16 @@ public async Task SlowReader_AfterProcessExit_DrainsBufferedOutputWithinTheTotal await AssertResources(engine); } - [Fact] - public async Task OutputBeyondCap_DrainsBothPipesAndReportsTruncation() + [Theory] + [InlineData('x', 'y')] + [InlineData('\0', '\u0001')] + public async Task OutputBeyondCap_DrainsBothPipesAndReportsTruncation(char stdoutChar, char stderrChar) { using var engine = CreateEngine(); var count = StartProgramActivity.MaxOutputBytesPerStream + 4096; var result = await Execute(engine, new { filePath = PowerShellPath, - arguments = EncodedCommand($"[Console]::Out.Write(('x' * {count})); [Console]::Error.Write(('y' * {count}))"), + arguments = EncodedCommand($"[Console]::Out.Write(([string][char]{(int)stdoutChar} * {count})); [Console]::Error.Write(([string][char]{(int)stderrChar} * {count}))"), timeoutSeconds = CaptureBudgetSeconds }, CaptureBudgetSeconds); result.Success.Should().BeTrue(result.ErrorOutput); diff --git a/tests/NodePilot.Engine.Tests/PowerShell/RunspaceEngineQueuedCancellationTests.cs b/tests/NodePilot.Engine.Tests/PowerShell/RunspaceEngineQueuedCancellationTests.cs index 710ccd4e..1c5642a0 100644 --- a/tests/NodePilot.Engine.Tests/PowerShell/RunspaceEngineQueuedCancellationTests.cs +++ b/tests/NodePilot.Engine.Tests/PowerShell/RunspaceEngineQueuedCancellationTests.cs @@ -94,7 +94,7 @@ public async Task Execute_AlreadyCancelled_DoesNotInvokeScript() } [Fact] - public async Task Execute_CallerCancelsWhileCompletedOutputIsFormatted_PreservesSuccess() + public async Task Execute_CallerCancelsWhileOutputIsCaptured_PropagatesCancellation() { using var engine = new RunspaceExecutionEngine(NullLogger.Instance, 1, 1); using var cts = new CancellationTokenSource(); @@ -102,17 +102,16 @@ public async Task Execute_CallerCancelsWhileCompletedOutputIsFormatted_Preserves CancelOnFormat.Callbacks[key] = cts.Cancel; try { - // ToString runs in the engine after EndInvoke has returned the completed pipeline's output. - var result = await engine.ExecuteAsync(new PowerShellExecutionRequest + // Streaming capture formats each record while the pipeline is still running. + var error = await Assert.ThrowsAnyAsync(() => engine.ExecuteAsync(new PowerShellExecutionRequest { ScriptText = $"[NodePilot.Engine.Tests.PowerShell.RunspaceEngineQueuedCancellationTests+CancelOnFormat]::new('{key}')", Timeout = TimeSpan.FromSeconds(10), - }, cts.Token); + }, cts.Token)); - cts.IsCancellationRequested.Should().BeTrue("formatting must actually exercise the late cancellation"); - result.Success.Should().BeTrue(); - result.TimedOut.Should().BeFalse(); - result.Output.Should().Contain("completed-before-cancel"); + cts.IsCancellationRequested.Should().BeTrue("formatting must exercise cancellation during capture"); + error.CancellationToken.Should().Be(cts.Token); + error.Message.Should().Be(IPowerShellExecutionEngine.CancelledMessage); } finally { diff --git a/tests/NodePilot.Engine.Tests/PowerShell/ScriptOutputLimitTests.cs b/tests/NodePilot.Engine.Tests/PowerShell/ScriptOutputLimitTests.cs new file mode 100644 index 00000000..208c17e8 --- /dev/null +++ b/tests/NodePilot.Engine.Tests/PowerShell/ScriptOutputLimitTests.cs @@ -0,0 +1,108 @@ +using FluentAssertions; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.Logging.Abstractions; +using NodePilot.Core.Execution; +using NodePilot.Engine.PowerShell; +using NodePilot.Remote; +using System.Management.Automation.Runspaces; +using Xunit; + +namespace NodePilot.Engine.Tests.PowerShell; + +public class ScriptOutputLimitTests +{ + [Theory] + [InlineData("powershell", false, "[Console]::Out.Write(('x' * 20000))")] + [InlineData("powershell", true, "[Console]::Out.Write(('x' * 20000))")] + [InlineData("powershell", false, "[Console]::Error.Write(('x' * 20000))")] + [InlineData("powershell", true, "[Console]::Error.Write(('x' * 20000))")] + [InlineData("runspace", false, "1..10000 | ForEach-Object { 'line' }")] + [InlineData("runspace", false, "Write-Output ('x' * 20000)")] + [InlineData("runspace", false, "Write-Error ('x' * 20000) -ErrorAction Continue")] + [InlineData("runspace", false, "Write-Warning ('x' * 20000)")] + [InlineData("runspace", false, "$VerbosePreference='Continue'; Write-Verbose ('x' * 20000)")] + [InlineData("runspace", false, "Write-Information ('x' * 20000)")] + [InlineData("runspace", false, "while ($true) { 'more-output' }")] + [InlineData("powershell", false, "while ($true) { 'more-output' }")] + [InlineData("powershell", true, "while ($true) { 'more-output' }")] + public async Task ExecuteAsync_OutputExceedsLimit_FailsWithBoundedOutput(string engineName, bool isolated, string script) + { + var config = new ConfigurationBuilder().AddInMemoryCollection(new Dictionary + { + ["Engine:MaxCapturedOutputChars"] = "4096" + }).Build(); + var factory = new Engine.PowerShell.PowerShellEngineFactory(NullLoggerFactory.Instance, config); + var engine = factory.GetEngine(engineName, isolated); + try + { + var result = await engine.ExecuteAsync(new() + { + ScriptText = script, + Isolated = isolated, + Timeout = TimeSpan.FromSeconds(15) + }, TestContext.Current.CancellationToken); + + result.Success.Should().BeFalse(); + result.TimedOut.Should().BeFalse(); + result.Error.Should().Contain("output limit"); + result.Output.Length.Should().BeLessThanOrEqualTo(4096); + } + finally { (factory.GetEngine("runspace") as IDisposable)?.Dispose(); } + } + + [Theory] + [InlineData("Write-Output ('x' * 20000)")] + [InlineData("1..10000 | ForEach-Object { 'line' }")] + [InlineData("Write-Error ('x' * 20000) -ErrorAction Continue")] + [InlineData("Write-Warning ('x' * 20000)")] + [InlineData("while ($true) { 'more-output' }")] + public async Task ExecuteScriptAsync_OutputExceedsLimit_FailsAndPoisonsSession(string script) + { + using var runspace = RunspaceFactory.CreateRunspace(); + runspace.Open(); + await using var session = new WinRmSession(runspace, "test-local", maxCapturedOutputChars: 4096); + + var result = await session.ExecuteScriptAsync(script, 15, TestContext.Current.CancellationToken); + + result.Success.Should().BeFalse(); + result.ErrorOutput.Should().Contain("output limit"); + result.Output.Length.Should().BeLessThanOrEqualTo(4096); + session.IsAlive.Should().BeFalse(); + } + + [Theory] + [InlineData("powershell", false)] + [InlineData("powershell", true)] + [InlineData("runspace", false)] + public async Task ExecuteAsync_WithinLimit_PreservesStructuredOutput(string name, bool isolated) + { + var factory = new PowerShellEngineFactory(NullLoggerFactory.Instance); + try + { + var result = await factory.GetEngine(name, isolated).ExecuteAsync(new() + { + ScriptText = "$answer = 'forty-two'; Write-Output 'ok'", + Isolated = isolated, + Timeout = TimeSpan.FromSeconds(15) + }, TestContext.Current.CancellationToken); + result.Success.Should().BeTrue(result.Error); + var (clean, _, parameters) = PowerShellActivitySupport.ExtractMarkers(result.Output, "step", NullLogger.Instance); + clean.Should().Contain("ok"); + parameters.Should().ContainKey("answer").WhoseValue.Should().Be("forty-two"); + } + finally { (factory.GetEngine("runspace") as IDisposable)?.Dispose(); } + } + + [Fact] + public async Task Capture_ConcurrentStreams_ShareOneBudgetAndContinueDraining() + { + using var budget = new ScriptOutputBudget(4096); + var stdout = new ProcessExecutionEngine.OutputCapture(new StringReader(new string('o', 10000)), + TestContext.Current.CancellationToken, budget.CreateBuffer()); + var stderr = new ProcessExecutionEngine.OutputCapture(new StringReader(new string('e', 10000)), + TestContext.Current.CancellationToken, budget.CreateBuffer()); + await Task.WhenAll(stdout.Completion, stderr.Completion); + budget.Exceeded.Should().BeTrue(); + (stdout.Text.Length + stderr.Text.Length).Should().Be(4096); + } +}