| | | 1 | | using System.Management.Automation; |
| | | 2 | | using System.Diagnostics; |
| | | 3 | | using System.Management.Automation.Runspaces; |
| | | 4 | | using Kestrun.Languages; |
| | | 5 | | using Kestrun.Models; |
| | | 6 | | using Kestrun.Scripting; |
| | | 7 | | using Serilog.Events; |
| | | 8 | | using Kestrun.Hosting; |
| | | 9 | | using Kestrun.Logging; |
| | | 10 | | |
| | | 11 | | namespace Kestrun.Middleware; |
| | | 12 | | |
| | | 13 | | /// <summary> |
| | | 14 | | /// Initializes a new instance of the <see cref="PowerShellRunspaceMiddleware"/> class. |
| | | 15 | | /// </summary> |
| | | 16 | | /// <param name="next">The next middleware in the pipeline.</param> |
| | | 17 | | /// <param name="pool">The runspace pool manager.</param> |
| | 4 | 18 | | public sealed class PowerShellRunspaceMiddleware(RequestDelegate next, KestrunRunspacePoolManager pool) |
| | | 19 | | { |
| | 4 | 20 | | private readonly RequestDelegate _next = next ?? throw new ArgumentNullException(nameof(next)); |
| | 4 | 21 | | private readonly KestrunRunspacePoolManager _pool = pool ?? throw new ArgumentNullException(nameof(pool)); |
| | | 22 | | private static int _inFlight; // diagnostic concurrency counter |
| | | 23 | | |
| | 59 | 24 | | private KestrunHost Host => _pool.Host; |
| | 56 | 25 | | private Serilog.ILogger Log => Host.Logger; |
| | | 26 | | |
| | | 27 | | /// <summary> |
| | | 28 | | /// Processes an HTTP request using a PowerShell runspace from the pool. |
| | | 29 | | /// </summary> |
| | | 30 | | /// <param name="context">The HTTP context for the current request.</param> |
| | | 31 | | public async Task InvokeAsync(HttpContext context) |
| | | 32 | | { |
| | 4 | 33 | | var start = DateTime.UtcNow; |
| | 4 | 34 | | var current = BeginRequestDiagnostics(context, start); |
| | 4 | 35 | | Runspace? runspace = null; |
| | 4 | 36 | | PowerShell? ps = null; |
| | 4 | 37 | | var cleanupTransferredToResponse = false; |
| | | 38 | | |
| | | 39 | | try |
| | | 40 | | { |
| | 4 | 41 | | LogMiddlewareStarted(context); |
| | 4 | 42 | | runspace = await AcquireRunspaceAsync(context, current); |
| | 3 | 43 | | ps = CreatePowerShellInstance(runspace); |
| | 3 | 44 | | InitializeRequestContext(context, ps); |
| | 3 | 45 | | RegisterDeferredCleanup(context, ps, runspace); |
| | 3 | 46 | | cleanupTransferredToResponse = true; |
| | | 47 | | |
| | 3 | 48 | | LogPipelineContinuation(context); |
| | 3 | 49 | | await _next(context); // continue the pipeline |
| | 3 | 50 | | LogMiddlewareCompleted(context); |
| | 3 | 51 | | } |
| | 1 | 52 | | catch (Exception ex) |
| | | 53 | | { |
| | 1 | 54 | | Log.Error(ex, "Error occurred in PowerShellRunspaceMiddleware"); |
| | 1 | 55 | | throw; // allow ExceptionHandler to catch and handle (re-exec or JSON) |
| | | 56 | | } |
| | | 57 | | finally |
| | | 58 | | { |
| | 4 | 59 | | if (!cleanupTransferredToResponse) |
| | | 60 | | { |
| | 1 | 61 | | CleanupRequestResources(context, ps, runspace); |
| | | 62 | | } |
| | | 63 | | |
| | 4 | 64 | | CompleteRequestDiagnostics(context, start); |
| | | 65 | | } |
| | 3 | 66 | | } |
| | | 67 | | |
| | | 68 | | /// <summary> |
| | | 69 | | /// Records the initial request diagnostics and returns the current in-flight count. |
| | | 70 | | /// </summary> |
| | | 71 | | /// <param name="context">The current HTTP context.</param> |
| | | 72 | | /// <param name="start">The request start time in UTC.</param> |
| | | 73 | | /// <returns>The number of requests currently in flight.</returns> |
| | | 74 | | private int BeginRequestDiagnostics(HttpContext context, DateTime start) |
| | | 75 | | { |
| | 4 | 76 | | var current = Interlocked.Increment(ref _inFlight); |
| | 4 | 77 | | if (Log.IsEnabled(LogEventLevel.Debug)) |
| | | 78 | | { |
| | 4 | 79 | | Log.DebugSanitized("ENTER InvokeAsync path={Path} inFlight={InFlight} thread={Thread} time={Start}", |
| | 4 | 80 | | context.Request.Path, current, Environment.CurrentManagedThreadId, start.ToString("O")); |
| | | 81 | | } |
| | | 82 | | |
| | 4 | 83 | | return current; |
| | | 84 | | } |
| | | 85 | | |
| | | 86 | | /// <summary> |
| | | 87 | | /// Logs the middleware entry for the current request when debug logging is enabled. |
| | | 88 | | /// </summary> |
| | | 89 | | /// <param name="context">The current HTTP context.</param> |
| | | 90 | | private void LogMiddlewareStarted(HttpContext context) |
| | | 91 | | { |
| | 4 | 92 | | if (Log.IsEnabled(LogEventLevel.Debug)) |
| | | 93 | | { |
| | 4 | 94 | | Log.DebugSanitized("PowerShellRunspaceMiddleware started for {Path}", context.Request.Path); |
| | | 95 | | } |
| | 4 | 96 | | } |
| | | 97 | | |
| | | 98 | | /// <summary> |
| | | 99 | | /// Acquires a runspace for the request and logs the acquisition duration. |
| | | 100 | | /// </summary> |
| | | 101 | | /// <param name="context">The current HTTP context.</param> |
| | | 102 | | /// <param name="inFlight">The current in-flight request count.</param> |
| | | 103 | | /// <returns>The acquired runspace.</returns> |
| | | 104 | | private async Task<Runspace> AcquireRunspaceAsync(HttpContext context, int inFlight) |
| | | 105 | | { |
| | 4 | 106 | | var acquireStart = Stopwatch.GetTimestamp(); |
| | 4 | 107 | | var runspace = await _pool.AcquireAsync(context.RequestAborted); |
| | 3 | 108 | | var acquireMs = (Stopwatch.GetTimestamp() - acquireStart) * 1000.0 / Stopwatch.Frequency; |
| | 3 | 109 | | if (Log.IsEnabled(LogEventLevel.Debug)) |
| | | 110 | | { |
| | 3 | 111 | | Log.DebugSanitized("Runspace acquired for {Path} in {AcquireMs} ms (inFlight={InFlight})", context.Request.P |
| | | 112 | | } |
| | | 113 | | |
| | 3 | 114 | | return runspace; |
| | 3 | 115 | | } |
| | | 116 | | |
| | | 117 | | /// <summary> |
| | | 118 | | /// Creates a PowerShell instance bound to the provided runspace. |
| | | 119 | | /// </summary> |
| | | 120 | | /// <param name="runspace">The runspace assigned to the current request.</param> |
| | | 121 | | /// <returns>A PowerShell instance that uses the provided runspace.</returns> |
| | | 122 | | private static PowerShell CreatePowerShellInstance(Runspace runspace) |
| | | 123 | | { |
| | 3 | 124 | | var ps = PowerShell.Create(); |
| | 3 | 125 | | ps.Runspace = runspace; |
| | 3 | 126 | | return ps; |
| | | 127 | | } |
| | | 128 | | |
| | | 129 | | /// <summary> |
| | | 130 | | /// Initializes the request-specific PowerShell and Kestrun context state. |
| | | 131 | | /// </summary> |
| | | 132 | | /// <param name="context">The current HTTP context.</param> |
| | | 133 | | /// <param name="ps">The PowerShell instance serving the request.</param> |
| | | 134 | | private void InitializeRequestContext(HttpContext context, PowerShell ps) |
| | | 135 | | { |
| | 3 | 136 | | context.Items[PowerShellDelegateBuilder.PS_INSTANCE_KEY] = ps; |
| | | 137 | | |
| | 3 | 138 | | var kestrunContext = new KestrunContext(Host, context); |
| | 3 | 139 | | context.Items[PowerShellDelegateBuilder.KR_CONTEXT_KEY] = kestrunContext; |
| | | 140 | | |
| | 3 | 141 | | if (Log.IsEnabled(LogEventLevel.Debug)) |
| | | 142 | | { |
| | 3 | 143 | | Log.DebugSanitized("PowerShellRunspaceMiddleware - Setting KestrunContext in HttpContext.Items for {Path}", |
| | | 144 | | } |
| | | 145 | | |
| | 3 | 146 | | Log.Verbose("Setting PowerShell variables for Request and Response in the runspace."); |
| | 3 | 147 | | var sessionState = ps.Runspace.SessionStateProxy; |
| | 3 | 148 | | sessionState.SetVariable("Context", kestrunContext); |
| | | 149 | | |
| | 3 | 150 | | if (context.Items.TryGetValue("KrLocalizer", out var localizer)) |
| | | 151 | | { |
| | 0 | 152 | | sessionState.SetVariable("Localizer", localizer); |
| | | 153 | | } |
| | 3 | 154 | | } |
| | | 155 | | |
| | | 156 | | /// <summary> |
| | | 157 | | /// Registers response completion cleanup so the runspace remains available to later middleware. |
| | | 158 | | /// </summary> |
| | | 159 | | /// <param name="context">The current HTTP context.</param> |
| | | 160 | | /// <param name="ps">The PowerShell instance serving the request.</param> |
| | | 161 | | /// <param name="runspace">The runspace serving the request.</param> |
| | | 162 | | private void RegisterDeferredCleanup(HttpContext context, PowerShell ps, Runspace runspace) |
| | | 163 | | { |
| | 3 | 164 | | context.Response.OnCompleted(() => |
| | 3 | 165 | | { |
| | 1 | 166 | | CleanupPowerShellInstance(ps, "OnCompleted: Error disposing PowerShell instance", "OnCompleted: Disposing Po |
| | 1 | 167 | | ReleaseRunspace(runspace, "OnCompleted: Error returning runspace to pool", "OnCompleted: Returning runspace |
| | 1 | 168 | | ClearRequestItems(context); |
| | 1 | 169 | | return Task.CompletedTask; |
| | 3 | 170 | | }); |
| | 3 | 171 | | } |
| | | 172 | | |
| | | 173 | | /// <summary> |
| | | 174 | | /// Logs that the middleware is continuing to the next pipeline component. |
| | | 175 | | /// </summary> |
| | | 176 | | /// <param name="context">The current HTTP context.</param> |
| | | 177 | | private void LogPipelineContinuation(HttpContext context) |
| | | 178 | | { |
| | 3 | 179 | | if (Log.IsEnabled(LogEventLevel.Debug)) |
| | | 180 | | { |
| | 3 | 181 | | Log.DebugSanitized("PowerShellRunspaceMiddleware - Continuing Pipeline for {Path}", context.Request.Path); |
| | | 182 | | } |
| | 3 | 183 | | } |
| | | 184 | | |
| | | 185 | | /// <summary> |
| | | 186 | | /// Logs successful middleware completion for the current request. |
| | | 187 | | /// </summary> |
| | | 188 | | /// <param name="context">The current HTTP context.</param> |
| | | 189 | | private void LogMiddlewareCompleted(HttpContext context) |
| | | 190 | | { |
| | 3 | 191 | | if (Log.IsEnabled(LogEventLevel.Debug)) |
| | | 192 | | { |
| | 3 | 193 | | Log.DebugSanitized("PowerShellRunspaceMiddleware completed for {Path}", context.Request.Path); |
| | | 194 | | } |
| | 3 | 195 | | } |
| | | 196 | | |
| | | 197 | | /// <summary> |
| | | 198 | | /// Cleans up request resources immediately when response completion cleanup was not registered. |
| | | 199 | | /// </summary> |
| | | 200 | | /// <param name="context">The current HTTP context.</param> |
| | | 201 | | /// <param name="ps">The PowerShell instance serving the request.</param> |
| | | 202 | | /// <param name="runspace">The runspace serving the request.</param> |
| | | 203 | | private void CleanupRequestResources(HttpContext context, PowerShell? ps, Runspace? runspace) |
| | | 204 | | { |
| | 1 | 205 | | CleanupPowerShellInstance(ps, "Error disposing PowerShell instance during middleware cleanup"); |
| | 1 | 206 | | ReleaseRunspace(runspace, "Error returning runspace to pool during middleware cleanup"); |
| | 1 | 207 | | ClearRequestItems(context); |
| | 1 | 208 | | } |
| | | 209 | | |
| | | 210 | | /// <summary> |
| | | 211 | | /// Disposes the PowerShell instance with debug-level error handling. |
| | | 212 | | /// </summary> |
| | | 213 | | /// <param name="ps">The PowerShell instance to dispose.</param> |
| | | 214 | | /// <param name="errorMessage">The message to log if disposal fails.</param> |
| | | 215 | | /// <param name="successMessageTemplate">An optional debug log template used before disposal.</param> |
| | | 216 | | private void CleanupPowerShellInstance(PowerShell? ps, string errorMessage, string? successMessageTemplate = null) |
| | | 217 | | { |
| | | 218 | | try |
| | | 219 | | { |
| | 2 | 220 | | if (ps is null) |
| | | 221 | | { |
| | 1 | 222 | | return; |
| | | 223 | | } |
| | | 224 | | |
| | 1 | 225 | | if (successMessageTemplate is not null && Log.IsEnabled(LogEventLevel.Debug)) |
| | | 226 | | { |
| | 1 | 227 | | Log.Debug(successMessageTemplate, ps.InstanceId); |
| | | 228 | | } |
| | | 229 | | |
| | 1 | 230 | | ps.Dispose(); |
| | 1 | 231 | | } |
| | 0 | 232 | | catch (Exception ex) |
| | | 233 | | { |
| | 0 | 234 | | Log.Debug(ex, errorMessage); |
| | 0 | 235 | | } |
| | 2 | 236 | | } |
| | | 237 | | |
| | | 238 | | /// <summary> |
| | | 239 | | /// Returns the runspace to the pool with debug-level error handling. |
| | | 240 | | /// </summary> |
| | | 241 | | /// <param name="runspace">The runspace to release.</param> |
| | | 242 | | /// <param name="errorMessage">The message to log if release fails.</param> |
| | | 243 | | /// <param name="successMessageTemplate">An optional debug log template used before release.</param> |
| | | 244 | | private void ReleaseRunspace(Runspace? runspace, string errorMessage, string? successMessageTemplate = null) |
| | | 245 | | { |
| | | 246 | | try |
| | | 247 | | { |
| | 2 | 248 | | if (runspace is null) |
| | | 249 | | { |
| | 1 | 250 | | return; |
| | | 251 | | } |
| | | 252 | | |
| | 1 | 253 | | if (successMessageTemplate is not null && Log.IsEnabled(LogEventLevel.Debug)) |
| | | 254 | | { |
| | 1 | 255 | | Log.Debug(successMessageTemplate, runspace.InstanceId, runspace.Name, runspace.Id); |
| | | 256 | | } |
| | | 257 | | |
| | 1 | 258 | | _pool.Release(runspace); |
| | 1 | 259 | | } |
| | 0 | 260 | | catch (Exception ex) |
| | | 261 | | { |
| | 0 | 262 | | Log.Debug(ex, errorMessage); |
| | 0 | 263 | | } |
| | 2 | 264 | | } |
| | | 265 | | |
| | | 266 | | /// <summary> |
| | | 267 | | /// Removes request-scoped middleware state from the HTTP context. |
| | | 268 | | /// </summary> |
| | | 269 | | /// <param name="context">The current HTTP context.</param> |
| | | 270 | | private static void ClearRequestItems(HttpContext context) |
| | | 271 | | { |
| | 2 | 272 | | _ = context.Items.Remove(PowerShellDelegateBuilder.PS_INSTANCE_KEY); |
| | 2 | 273 | | _ = context.Items.Remove(PowerShellDelegateBuilder.KR_CONTEXT_KEY); |
| | 2 | 274 | | } |
| | | 275 | | |
| | | 276 | | /// <summary> |
| | | 277 | | /// Records the final request diagnostics after the middleware finishes processing. |
| | | 278 | | /// </summary> |
| | | 279 | | /// <param name="context">The current HTTP context.</param> |
| | | 280 | | /// <param name="start">The request start time in UTC.</param> |
| | | 281 | | private void CompleteRequestDiagnostics(HttpContext context, DateTime start) |
| | | 282 | | { |
| | 4 | 283 | | var remaining = Interlocked.Decrement(ref _inFlight); |
| | 4 | 284 | | var durationMs = (DateTime.UtcNow - start).TotalMilliseconds; |
| | 4 | 285 | | if (Log.IsEnabled(LogEventLevel.Debug)) |
| | | 286 | | { |
| | 4 | 287 | | Log.DebugSanitized("PowerShellRunspaceMiddleware ended for {Path} durationMs={durationMs} inFlight={remainin |
| | 4 | 288 | | context.Request.Path, durationMs, remaining); |
| | | 289 | | } |
| | 4 | 290 | | } |
| | | 291 | | } |