diff --git a/Directory.Packages.props b/Directory.Packages.props index d8f854e..a26aea0 100644 --- a/Directory.Packages.props +++ b/Directory.Packages.props @@ -29,6 +29,7 @@ + diff --git a/docs/plans/2026-05-20-auditlog-m4-remaining-boundaries.md b/docs/plans/2026-05-20-auditlog-m4-remaining-boundaries.md new file mode 100644 index 0000000..909d98e --- /dev/null +++ b/docs/plans/2026-05-20-auditlog-m4-remaining-boundaries.md @@ -0,0 +1,24 @@ +# Audit Log #23 — M4 Remaining Boundary Emission Implementation Plan + +> **For Claude:** REQUIRED SUB-SKILL: Use superpowers-extended-cc:subagent-driven-development (bundled cadence). + +**Goal:** Close every remaining script-trust-boundary emission gap: sync DB writes/reads via Database.Connection().Execute*/ExecuteReader, Notification Outbox central dispatcher attempts + terminal, site-side Notify.Send submission, and Inbound API middleware. Audit-write failure NEVER aborts the user-facing action across all five new code paths. + +**Vocabulary (M3 reality-locked):** +- `AuditKind.DbWrite` (Channel=DbOutbound) for both Execute and ExecuteReader; `Extra` carries `{"op":"write"|"read","rowsAffected":N|"rowsReturned":N}`. +- `AuditKind.NotifyDeliver` for each Notification Outbox attempt; `AuditStatus.Attempted` on attempts, `AuditStatus.Delivered|Failed|Parked|Discarded` on terminal. +- `AuditKind.NotifySend` for site-emit at Notify.Send; `AuditStatus.Submitted`. +- `AuditKind.InboundRequest` for happy-path inbound; `AuditStatus.Delivered`. `AuditKind.InboundAuthFailure` for 401; `AuditStatus.Failed`. +- `AuditStatus.Failed` replaces "PermanentFailure" / "TransientFailure" terminal wording throughout. + +**Bundles:** +- Bundle A — DB sync emissions (T1, T2) +- Bundle B — NotificationOutbox central emissions (T3, T4, T5) +- Bundle C — Site Notify.Send emission (T6) +- Bundle D — Inbound API audit middleware (T7, T8) +- Bundle E — Integration tests (T9, T10, T11, T12) +- Final cross-bundle review + merge + +Each task follows the M2 Bundle F / M3 Bundle E emission pattern: capture timing, build AuditEvent with provenance, write via try/catch that swallows + logs, never propagate audit failure to the user-facing action. Mirror M2's ScriptRuntimeContext wrapper pattern where the emission is script-context-aware. + +Integration tests go in `tests/ScadaLink.AuditLog.Tests/Integration/` (component-level per M2 Bundle H + M3 Bundle G — the existing IntegrationTests factory disables Akka). diff --git a/src/ScadaLink.AuditLog/Central/CentralAuditWriter.cs b/src/ScadaLink.AuditLog/Central/CentralAuditWriter.cs new file mode 100644 index 0000000..fd0972d --- /dev/null +++ b/src/ScadaLink.AuditLog/Central/CentralAuditWriter.cs @@ -0,0 +1,82 @@ +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; + +namespace ScadaLink.AuditLog.Central; + +/// +/// Central-only direct-write implementation of . +/// Wraps as a best-effort +/// audit emission path for components that originate audit events ON the central +/// node (Notification Outbox dispatch, Inbound API) — NOT for site telemetry +/// ingest (that path is the SiteAudit → AuditLogIngestActor batched flow). +/// +/// +/// +/// Best-effort contract. Audit-write failures NEVER abort the user-facing +/// action (alog.md §13). The writer catches every exception thrown by repository +/// resolution or the insert call, logs at warning, and returns successfully. +/// Callers may still wrap the call in their own try/catch (defensive — the writer +/// is supposed to swallow). +/// +/// +/// Scope-per-call resolution. is a SCOPED +/// EF Core service (registered by ScadaLink.ConfigurationDatabase). The +/// writer itself is registered as a singleton (so all callers share one instance), +/// so it cannot hold a scope across calls — it opens a fresh +/// per invocation, mirroring +/// the per-message scope pattern used by AuditLogIngestActor and +/// NotificationOutboxActor. +/// +/// +/// Idempotency. Persistence is via InsertIfNotExistsAsync, so a +/// double-emitted event (same ) is a silent +/// no-op — the writer is safe to call from any number of dispatch paths. +/// +/// +public sealed class CentralAuditWriter : ICentralAuditWriter +{ + private readonly IServiceProvider _services; + private readonly ILogger _logger; + + public CentralAuditWriter(IServiceProvider services, ILogger logger) + { + _services = services ?? throw new ArgumentNullException(nameof(services)); + _logger = logger ?? throw new ArgumentNullException(nameof(logger)); + } + + /// + /// Persists into the central AuditLog table + /// idempotently on . Stamps + /// from the central-side clock. + /// Internal failures are logged and swallowed — never thrown. + /// + public async Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + if (evt is null) + { + // Defensive — a null event is a programming bug at the caller and + // produces no meaningful audit row. Log and return. + _logger.LogWarning("CentralAuditWriter.WriteAsync received null event; ignoring."); + return; + } + + try + { + await using var scope = _services.CreateAsyncScope(); + var repo = scope.ServiceProvider.GetRequiredService(); + var stamped = evt with { IngestedAtUtc = DateTime.UtcNow }; + await repo.InsertIfNotExistsAsync(stamped, ct).ConfigureAwait(false); + } + catch (Exception ex) + { + // Audit failure NEVER aborts the user-facing action — swallow and log. + _logger.LogWarning( + ex, + "CentralAuditWriter failed for EventId {EventId} (Kind={Kind}, Status={Status})", + evt.EventId, evt.Kind, evt.Status); + } + } +} diff --git a/src/ScadaLink.AuditLog/ServiceCollectionExtensions.cs b/src/ScadaLink.AuditLog/ServiceCollectionExtensions.cs index e420f4f..346ea0f 100644 --- a/src/ScadaLink.AuditLog/ServiceCollectionExtensions.cs +++ b/src/ScadaLink.AuditLog/ServiceCollectionExtensions.cs @@ -3,6 +3,7 @@ using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.DependencyInjection.Extensions; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; +using ScadaLink.AuditLog.Central; using ScadaLink.AuditLog.Configuration; using ScadaLink.AuditLog.Site; using ScadaLink.AuditLog.Site.Telemetry; @@ -129,6 +130,17 @@ public static class ServiceCollectionExtensions services.AddSingleton( sp => sp.GetRequiredService()); + // M4 Bundle B: central direct-write audit writer used by + // NotificationOutboxActor (Bundle B) and Inbound API (Bundle C/D) to + // emit AuditLog rows that originate ON central, not via site telemetry. + // Singleton — the writer is stateless; its per-call scope opens a fresh + // IAuditLogRepository (a SCOPED EF Core service registered by + // ScadaLink.ConfigurationDatabase). The interface (ICentralAuditWriter) + // is intentionally distinct from IAuditWriter so site composition roots + // do not accidentally bind it; central composition roots that include + // AddConfigurationDatabase get a working implementation transparently. + services.AddSingleton(); + return services; } diff --git a/src/ScadaLink.Host/Actors/AkkaHostedService.cs b/src/ScadaLink.Host/Actors/AkkaHostedService.cs index fe4fe15..b8c5171 100644 --- a/src/ScadaLink.Host/Actors/AkkaHostedService.cs +++ b/src/ScadaLink.Host/Actors/AkkaHostedService.cs @@ -275,11 +275,18 @@ akka {{ .GetRequiredService>().Value; var outboxLogger = _serviceProvider.GetRequiredService() .CreateLogger(); + // M4 Bundle B: central direct-write audit writer for dispatcher attempt + // + terminal events. Resolved once from the root provider — the writer + // is a singleton and stateless, opening per-call DI scopes internally + // to resolve the scoped IAuditLogRepository. + var outboxAuditWriter = _serviceProvider + .GetRequiredService(); var outboxSingletonProps = ClusterSingletonManager.Props( singletonProps: Props.Create(() => new ScadaLink.NotificationOutbox.NotificationOutboxActor( _serviceProvider, outboxOptions, + outboxAuditWriter, outboxLogger)), terminationMessage: PoisonPill.Instance, settings: ClusterSingletonManagerSettings.Create(_actorSystem!) diff --git a/src/ScadaLink.Host/Program.cs b/src/ScadaLink.Host/Program.cs index ed15327..b1119d1 100644 --- a/src/ScadaLink.Host/Program.cs +++ b/src/ScadaLink.Host/Program.cs @@ -12,6 +12,7 @@ using ScadaLink.Host; using ScadaLink.Host.Actors; using ScadaLink.Host.Health; using ScadaLink.InboundAPI; +using ScadaLink.InboundAPI.Middleware; using ScadaLink.ManagementService; using ScadaLink.NotificationOutbox; using ScadaLink.NotificationService; @@ -162,6 +163,18 @@ try app.UseAuthorization(); app.UseAntiforgery(); + // Audit Log #23 (M4 Bundle D, T8): emit one InboundRequest/InboundAuthFailure + // audit row per call into the inbound API. Placed AFTER UseAuthentication/ + // UseAuthorization so any HttpContext.User the framework populates is in + // place, and scoped to the /api/ prefix so it never observes the Central UI, + // Management API, SignalR hubs, or health endpoints. The endpoint handler + // is responsible for stashing the resolved API key name on + // HttpContext.Items (see AuditWriteMiddleware.AuditActorItemKey) AFTER its + // in-handler API key validation succeeds. + app.UseWhen( + ctx => ctx.Request.Path.StartsWithSegments("/api"), + branch => branch.UseAuditWriteMiddleware()); + // WP-12: Map readiness endpoint — returns 503 until ready, 200 when ready. // REQ-HOST-4a defines readiness as cluster membership + DB connectivity, // explicitly NOT cluster leadership. The leader-only "active-node" check is diff --git a/src/ScadaLink.InboundAPI/EndpointExtensions.cs b/src/ScadaLink.InboundAPI/EndpointExtensions.cs index 1749974..4daec2c 100644 --- a/src/ScadaLink.InboundAPI/EndpointExtensions.cs +++ b/src/ScadaLink.InboundAPI/EndpointExtensions.cs @@ -5,6 +5,7 @@ using Microsoft.AspNetCore.Routing; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; +using ScadaLink.InboundAPI.Middleware; namespace ScadaLink.InboundAPI; @@ -53,6 +54,13 @@ public static class EndpointExtensions var method = validationResult.Method!; + // Audit Log (#23 M4 Bundle D): publish the resolved API key name so + // AuditWriteMiddleware can populate AuditEvent.Actor in its finally + // block. Done AFTER validation succeeded — auth failures leave the + // slot empty and the middleware records the row with Actor=null. + httpContext.Items[AuditWriteMiddleware.AuditActorItemKey] = + validationResult.ApiKey!.Name; + // WP-2: Deserialize and validate parameters JsonElement? body = null; try diff --git a/src/ScadaLink.InboundAPI/Middleware/AuditWriteMiddleware.cs b/src/ScadaLink.InboundAPI/Middleware/AuditWriteMiddleware.cs new file mode 100644 index 0000000..eb0f9c9 --- /dev/null +++ b/src/ScadaLink.InboundAPI/Middleware/AuditWriteMiddleware.cs @@ -0,0 +1,266 @@ +using System.Diagnostics; +using System.Text; +using System.Text.Json; +using Microsoft.AspNetCore.Http; +using Microsoft.Extensions.Logging; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Enums; + +namespace ScadaLink.InboundAPI.Middleware; + +/// +/// Audit Log #23 (M4 Bundle D, T7) — emits one +/// row per inbound API request via covering the +/// full set of response shapes: +/// +/// +/// 2xx / non-error → with . +/// 401/403 → with . +/// 4xx (non-auth) / 5xx / thrown exception → with . +/// +/// +/// +/// Best-effort contract (alog.md §13). Audit emission NEVER alters the +/// user-facing HTTP response — a thrown writer or any other failure during +/// emission is caught, logged at warning, and dropped. A handler exception is +/// recorded on the audit row then re-thrown so the framework error path stays +/// authoritative. +/// +/// +/// +/// Actor resolution. Inbound API auth runs inside the endpoint handler +/// (no UseAuthentication-backed scheme populates +/// for X-API-Key callers), so the handler stashes the resolved API key name on +/// under after +/// ApiKeyValidator.ValidateAsync succeeds. The middleware reads it in +/// its finally block — on auth failures the key remains absent and +/// stays null (we never echo back an +/// unauthenticated principal). +/// +/// +/// +/// Body capture. The request body is buffered via +/// then +/// rewound so the downstream endpoint handler still sees the full payload. +/// Response body capture is deferred to M5 — wrapping Response.Body +/// requires a memory-stream swap that interacts awkwardly with Minimal API's +/// Results.Json/Results.Text writers; the M4 deliverable emits +/// the audit row with left null. +/// +/// +public sealed class AuditWriteMiddleware +{ + /// + /// key used by the endpoint handler to publish + /// the resolved API key name once ApiKeyValidator.ValidateAsync has + /// succeeded. Exposed as a constant so the handler and middleware share a + /// single source of truth (no stringly-typed coupling). + /// + public const string AuditActorItemKey = "ScadaLink.InboundAPI.AuditActor"; + + private readonly RequestDelegate _next; + private readonly ICentralAuditWriter _auditWriter; + private readonly ILogger _logger; + + public AuditWriteMiddleware( + RequestDelegate next, + ICentralAuditWriter auditWriter, + ILogger logger) + { + _next = next ?? throw new ArgumentNullException(nameof(next)); + _auditWriter = auditWriter ?? throw new ArgumentNullException(nameof(auditWriter)); + _logger = logger ?? throw new ArgumentNullException(nameof(logger)); + } + + public async Task InvokeAsync(HttpContext ctx) + { + var sw = Stopwatch.StartNew(); + + // Buffer the request body up front so we can both audit it and let the + // downstream handler still parse it. EnableBuffering swaps the request + // stream for a seekable wrapper that the framework rewinds at the end + // of the pipeline for us — but we also rewind to position 0 after our + // own read so the very next reader starts from the top. + ctx.Request.EnableBuffering(); + var requestBody = await ReadBufferedRequestBodyAsync(ctx.Request).ConfigureAwait(false); + + Exception? thrown = null; + try + { + await _next(ctx).ConfigureAwait(false); + } + catch (Exception ex) + { + thrown = ex; + // Re-throw — audit emission is BEST EFFORT, but the user-facing + // request's own error path must remain authoritative (alog.md §13). + throw; + } + finally + { + sw.Stop(); + EmitInboundAudit(ctx, sw.ElapsedMilliseconds, thrown, requestBody); + } + } + + /// + /// Builds and writes the row for the + /// request. Wrapped in try/catch so a thrown writer or any other emission + /// failure stays out of the user-facing response (alog.md §13). + /// + private void EmitInboundAudit( + HttpContext ctx, + long durationMs, + Exception? thrown, + string? requestBody) + { + try + { + var statusCode = ctx.Response.StatusCode; + var isAuthFailure = statusCode is 401 or 403; + + var kind = isAuthFailure + ? AuditKind.InboundAuthFailure + : AuditKind.InboundRequest; + + // A thrown handler exception is always Failed; otherwise any 4xx/5xx + // response signals failure. 2xx/3xx are Delivered. + var status = (thrown != null || statusCode >= 400) + ? AuditStatus.Failed + : AuditStatus.Delivered; + + var actor = isAuthFailure ? null : ResolveActor(ctx); + var methodName = ResolveMethodName(ctx); + + var extra = JsonSerializer.Serialize(new + { + remoteIp = ctx.Connection.RemoteIpAddress?.ToString(), + userAgent = ctx.Request.Headers.UserAgent.ToString(), + }); + + var evt = new AuditEvent + { + EventId = Guid.NewGuid(), + OccurredAtUtc = DateTime.UtcNow, + Channel = AuditChannel.ApiInbound, + Kind = kind, + Actor = actor, + Target = methodName, + Status = status, + HttpStatus = statusCode, + DurationMs = (int)Math.Min(durationMs, int.MaxValue), + ErrorMessage = thrown?.Message, + RequestSummary = requestBody, + // Response body capture is deferred to M5 (see XML doc above). + ResponseSummary = null, + PayloadTruncated = false, + Extra = extra, + // Central direct-write — no site-local forwarding state. + ForwardState = null, + }; + + // Fire-and-forget — the writer itself swallows; the additional + // try/catch around the fire still protects us if WriteAsync throws + // synchronously before returning a task. + _ = _auditWriter.WriteAsync(evt); + } + catch (Exception ex) + { + _logger.LogWarning( + ex, + "AuditWriteMiddleware emission failed for {Method} {Path} (status {Status})", + ctx.Request.Method, ctx.Request.Path, ctx.Response.StatusCode); + } + } + + /// + /// Reads the buffered request body fully into a string and rewinds the + /// stream so the downstream handler sees the unconsumed payload. Returns + /// null for empty/missing bodies so the audit row's + /// stays null rather than + /// containing an empty string. + /// + private static async Task ReadBufferedRequestBodyAsync(HttpRequest request) + { + if (request.ContentLength is 0) + { + return null; + } + + try + { + request.Body.Position = 0; + using var reader = new StreamReader( + request.Body, + Encoding.UTF8, + detectEncodingFromByteOrderMarks: false, + bufferSize: 1024, + leaveOpen: true); + var content = await reader.ReadToEndAsync().ConfigureAwait(false); + request.Body.Position = 0; + return string.IsNullOrEmpty(content) ? null : content; + } + catch + { + // A failed body read must not abort the request — fall through + // with a null RequestSummary; the audit row still records the + // outcome. + return null; + } + } + + /// + /// Reads the API key name the endpoint handler stashed on + /// after successful auth. Falls back to + /// the authenticated user name when an ASP.NET scheme has populated + /// (defensive — currently unused for inbound + /// API but cheap and forward-compatible). + /// + private static string? ResolveActor(HttpContext ctx) + { + if (ctx.Items.TryGetValue(AuditActorItemKey, out var stashed) + && stashed is string name + && !string.IsNullOrWhiteSpace(name)) + { + return name; + } + + var user = ctx.User; + if (user?.Identity is { IsAuthenticated: true, Name: { Length: > 0 } userName }) + { + return userName; + } + + return null; + } + + /// + /// Pulls the {methodName} route value off the request. Falls back to + /// the last segment of when no route value + /// is bound (e.g. when the request never reached the matched endpoint). + /// + private static string? ResolveMethodName(HttpContext ctx) + { + if (ctx.Request.RouteValues.TryGetValue("methodName", out var raw) + && raw is string method + && !string.IsNullOrWhiteSpace(method)) + { + return method; + } + + var path = ctx.Request.Path.Value; + if (string.IsNullOrEmpty(path)) + { + return null; + } + + var lastSlash = path.LastIndexOf('/'); + if (lastSlash < 0 || lastSlash == path.Length - 1) + { + return null; + } + + return path[(lastSlash + 1)..]; + } +} diff --git a/src/ScadaLink.InboundAPI/Middleware/AuditWriteMiddlewareExtensions.cs b/src/ScadaLink.InboundAPI/Middleware/AuditWriteMiddlewareExtensions.cs new file mode 100644 index 0000000..29cc10d --- /dev/null +++ b/src/ScadaLink.InboundAPI/Middleware/AuditWriteMiddlewareExtensions.cs @@ -0,0 +1,26 @@ +using Microsoft.AspNetCore.Builder; + +namespace ScadaLink.InboundAPI.Middleware; + +/// +/// extensions for wiring +/// into the ASP.NET Core request pipeline. +/// See for the placement contract (must run +/// after auth so the resolved API key name is available on +/// , and before the +/// inbound-API endpoint handler that owns script execution). +/// +public static class AuditWriteMiddlewareExtensions +{ + /// + /// Registers in the pipeline. + /// + /// must be registered in DI (typically via AddAuditLog) before this + /// middleware runs. + /// + public static IApplicationBuilder UseAuditWriteMiddleware(this IApplicationBuilder app) + { + ArgumentNullException.ThrowIfNull(app); + return app.UseMiddleware(); + } +} diff --git a/src/ScadaLink.NotificationOutbox/NotificationOutboxActor.cs b/src/ScadaLink.NotificationOutbox/NotificationOutboxActor.cs index bc17053..400f6d2 100644 --- a/src/ScadaLink.NotificationOutbox/NotificationOutboxActor.cs +++ b/src/ScadaLink.NotificationOutbox/NotificationOutboxActor.cs @@ -1,8 +1,10 @@ using Akka.Actor; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Logging; +using ScadaLink.Commons.Entities.Audit; using ScadaLink.Commons.Entities.Notifications; using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; using ScadaLink.Commons.Messages.Notification; using ScadaLink.Commons.Types.Enums; using ScadaLink.Commons.Types.Notifications; @@ -30,6 +32,7 @@ public class NotificationOutboxActor : ReceiveActor, IWithTimers private readonly IServiceProvider _serviceProvider; private readonly NotificationOutboxOptions _options; + private readonly ICentralAuditWriter _auditWriter; private readonly ILogger _logger; /// @@ -45,11 +48,13 @@ public class NotificationOutboxActor : ReceiveActor, IWithTimers public NotificationOutboxActor( IServiceProvider serviceProvider, NotificationOutboxOptions options, + ICentralAuditWriter auditWriter, ILogger logger) { - _serviceProvider = serviceProvider; - _options = options; - _logger = logger; + _serviceProvider = serviceProvider ?? throw new ArgumentNullException(nameof(serviceProvider)); + _options = options ?? throw new ArgumentNullException(nameof(options)); + _auditWriter = auditWriter ?? throw new ArgumentNullException(nameof(auditWriter)); + _logger = logger ?? throw new ArgumentNullException(nameof(logger)); Receive(HandleSubmit); Receive(HandleIngestPersisted); @@ -265,6 +270,26 @@ public class NotificationOutboxActor : ReceiveActor, IWithTimers /// status transition. A missing adapter parks the notification; otherwise the /// drives the transition. The updated row is always persisted. /// + /// + /// + /// M4 Bundle B2 + B3: a single + /// / + /// row is emitted with per attempt + /// (success, transient, permanent); when the post-outcome status is a + /// terminal one (Delivered, Parked) a SECOND row is emitted carrying + /// that terminal status. Both emissions are wrapped in a try/catch so a + /// thrown audit writer NEVER aborts the user-facing dispatch — the + /// itself swallows internal failures, + /// but the dispatcher wraps defensively per alog.md §13. The + /// missing-adapter park path also emits both rows because it IS an + /// attempt that resolved to a park from the dispatcher's point of view. + /// + /// + /// Attempt duration is measured around the adapter call and recorded on + /// the Attempted row so downstream KPIs can compute per-attempt latency + /// without joining to the row update timestamps. + /// + /// private async Task DeliverOneAsync( Notification notification, DateTimeOffset now, @@ -275,14 +300,29 @@ public class NotificationOutboxActor : ReceiveActor, IWithTimers { if (!adapters.TryGetValue(notification.Type, out var adapter)) { + // Missing-adapter park: from the dispatcher's perspective this is an + // attempt that resolved to a terminal park. Emit Attempted then the + // terminal Parked row, both carrying the same explanatory error. + var missingAdapterError = $"no delivery adapter for type {notification.Type}"; notification.Status = NotificationStatus.Parked; - notification.LastError = $"no delivery adapter for type {notification.Type}"; + notification.LastError = missingAdapterError; notification.LastAttemptAt = now; await outboxRepository.UpdateAsync(notification); + EmitAttemptAudit( + notification, + now, + durationMs: 0, + errorMessage: missingAdapterError); + EmitTerminalAudit(notification, now, errorMessage: missingAdapterError); return; } + // Measure the attempt duration around the adapter call so the + // Attempted row carries it for KPI use. + var attemptStart = DateTimeOffset.UtcNow; var outcome = await adapter.DeliverAsync(notification); + var durationMs = (int)Math.Min( + int.MaxValue, Math.Max(0, (DateTimeOffset.UtcNow - attemptStart).TotalMilliseconds)); switch (outcome.Result) { @@ -317,6 +357,158 @@ public class NotificationOutboxActor : ReceiveActor, IWithTimers } await outboxRepository.UpdateAsync(notification); + + // Emit the per-attempt Attempted row exactly once regardless of the + // outcome (B2). The error message comes from the outcome, not from + // notification.LastError, so a success row is null and a transient + // row carries the SMTP failure reason verbatim. + EmitAttemptAudit( + notification, + now, + durationMs: durationMs, + errorMessage: outcome.Result == DeliveryResult.Success ? null : outcome.Error); + + // If the post-outcome status is terminal (Delivered or Parked — the + // dispatcher never sets Discarded; that lives on the manual discard + // path), emit the terminal NotifyDeliver row (B3). The error message + // on a Delivered terminal is null; on Parked it carries the outcome's + // reason so downstream consumers can link Attempted+Parked rows. + if (IsTerminal(notification.Status)) + { + EmitTerminalAudit( + notification, + now, + errorMessage: outcome.Result == DeliveryResult.Success ? null : outcome.Error); + } + } + + /// + /// True for , + /// , or + /// — the three terminal states + /// on the central outbox lifecycle. Used by the dispatcher and the manual + /// discard handler to decide when to emit the terminal NotifyDeliver row. + /// + private static bool IsTerminal(NotificationStatus status) + { + return status is NotificationStatus.Delivered + or NotificationStatus.Parked + or NotificationStatus.Discarded; + } + + /// + /// Emits a single + /// / + /// audit row carrying the terminal status (Delivered, Parked, or + /// Discarded) of . Wrapped in try/catch + /// for the same defensive reason as . + /// + private void EmitTerminalAudit( + Notification notification, + DateTimeOffset now, + string? errorMessage) + { + try + { + var terminalStatus = MapNotificationStatusToAuditStatus(notification.Status); + var evt = BuildNotifyDeliverEvent(notification, now, terminalStatus, errorMessage); + _ = _auditWriter.WriteAsync(evt); + } + catch (Exception ex) + { + _logger.LogWarning( + ex, + "Failed to emit terminal {Status} audit row for notification {NotificationId}.", + notification.Status, notification.NotificationId); + } + } + + /// + /// Maps the central-outbox terminal + /// values onto the corresponding values used by + /// AuditLog (#23). Non-terminal statuses throw — the caller must gate on + /// . + /// + private static AuditStatus MapNotificationStatusToAuditStatus(NotificationStatus status) + { + return status switch + { + NotificationStatus.Delivered => AuditStatus.Delivered, + NotificationStatus.Parked => AuditStatus.Parked, + NotificationStatus.Discarded => AuditStatus.Discarded, + _ => throw new ArgumentOutOfRangeException( + nameof(status), status, "non-terminal status has no audit terminal mapping"), + }; + } + + /// + /// Emits a single + /// / + /// audit row with . Wrapped in + /// try/catch so an audit-write failure never propagates back into the + /// dispatcher loop — the already + /// swallows, this is defensive (alog.md §13). + /// + private void EmitAttemptAudit( + Notification notification, + DateTimeOffset now, + int durationMs, + string? errorMessage) + { + try + { + var evt = BuildNotifyDeliverEvent(notification, now, AuditStatus.Attempted, errorMessage) + with { DurationMs = durationMs }; + // Fire-and-forget — we do NOT await: the dispatcher loop must not + // be blocked by audit IO, and the writer swallows its own faults. + // PipeTo is not used because the writer never throws. + _ = _auditWriter.WriteAsync(evt); + } + catch (Exception ex) + { + _logger.LogWarning( + ex, + "Failed to emit Attempted audit row for notification {NotificationId}.", + notification.NotificationId); + } + } + + /// + /// Builds a / + /// row with the per-notification provenance fields (correlation id, list + /// name, source site/instance/script) populated from + /// . + /// parses the notification's id as a Guid; sites generate the id with + /// Guid.NewGuid().ToString("N") so the parse always succeeds, but + /// a non-Guid id is recorded as null rather than crashing the dispatcher. + /// + private static AuditEvent BuildNotifyDeliverEvent( + Notification notification, + DateTimeOffset now, + AuditStatus status, + string? errorMessage) + { + Guid? correlationId = Guid.TryParse(notification.NotificationId, out var parsed) + ? parsed + : null; + + return new AuditEvent + { + EventId = Guid.NewGuid(), + OccurredAtUtc = now.UtcDateTime, + Channel = AuditChannel.Notification, + Kind = AuditKind.NotifyDeliver, + CorrelationId = correlationId, + // Central dispatch — no authenticated actor (the originating + // script's identity is captured on the upstream NotifySend row). + Actor = null, + SourceSiteId = notification.SourceSiteId, + SourceInstanceId = notification.SourceInstanceId, + SourceScript = notification.SourceScript, + Target = notification.ListName, + Status = status, + ErrorMessage = errorMessage, + }; } /// @@ -563,6 +755,13 @@ public class NotificationOutboxActor : ReceiveActor, IWithTimers notification.Status = NotificationStatus.Discarded; await repository.UpdateAsync(notification); + // M4 Bundle B3: a manual discard is the OTHER code path that produces + // a terminal NotificationStatus transition (alongside the dispatcher). + // Emit a Discarded NotifyDeliver row to match the dispatcher's + // Delivered/Parked emissions; the row carries no error message because + // the discard is an operator-driven cancellation, not a delivery error. + EmitTerminalAudit(notification, DateTimeOffset.UtcNow, errorMessage: null); + return new DiscardNotificationResponse(request.CorrelationId, Success: true, ErrorMessage: null); } diff --git a/src/ScadaLink.NotificationOutbox/ScadaLink.NotificationOutbox.csproj b/src/ScadaLink.NotificationOutbox/ScadaLink.NotificationOutbox.csproj index 64b6b1b..c52791b 100644 --- a/src/ScadaLink.NotificationOutbox/ScadaLink.NotificationOutbox.csproj +++ b/src/ScadaLink.NotificationOutbox/ScadaLink.NotificationOutbox.csproj @@ -22,6 +22,13 @@ + + diff --git a/src/ScadaLink.SiteRuntime/ScadaLink.SiteRuntime.csproj b/src/ScadaLink.SiteRuntime/ScadaLink.SiteRuntime.csproj index bfa3f5b..da712a0 100644 --- a/src/ScadaLink.SiteRuntime/ScadaLink.SiteRuntime.csproj +++ b/src/ScadaLink.SiteRuntime/ScadaLink.SiteRuntime.csproj @@ -22,6 +22,14 @@ + + diff --git a/src/ScadaLink.SiteRuntime/Scripts/AuditingDbCommand.cs b/src/ScadaLink.SiteRuntime/Scripts/AuditingDbCommand.cs new file mode 100644 index 0000000..2936e55 --- /dev/null +++ b/src/ScadaLink.SiteRuntime/Scripts/AuditingDbCommand.cs @@ -0,0 +1,522 @@ +using System.Data; +using System.Data.Common; +using System.Diagnostics; +using Microsoft.Extensions.Logging; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Enums; + +namespace ScadaLink.SiteRuntime.Scripts; + +/// +/// Audit Log #23 — M4 Bundle A: decorator that emits +/// exactly one DbOutbound/DbWrite audit event per execution. +/// +/// +/// +/// Vocabulary lock (M4 plan): both writes (Execute / ExecuteScalar) and +/// reads (ExecuteReader) emit on the +/// channel. The Extra JSON column +/// distinguishes them — {"op":"write","rowsAffected":N} for writes, +/// {"op":"read","rowsReturned":N} for reads. +/// +/// +/// Best-effort emission (alog.md §7): mirrors +/// 's 3-layer fail-safe. +/// The original ADO.NET result (or original exception) flows back to the +/// script untouched; audit-build, audit-write, and audit-continuation faults +/// are all logged + swallowed. A faulted never +/// aborts the SQL call. +/// +/// +internal sealed class AuditingDbCommand : DbCommand +{ + private readonly DbCommand _inner; + private readonly IAuditWriter _auditWriter; + private readonly string _connectionName; + private readonly string _siteId; + private readonly string _instanceName; + private readonly string? _sourceScript; + private readonly ILogger _logger; + private DbConnection? _wrappingConnection; + + public AuditingDbCommand( + DbCommand inner, + IAuditWriter auditWriter, + string connectionName, + string siteId, + string instanceName, + string? sourceScript, + ILogger logger) + { + _inner = inner ?? throw new ArgumentNullException(nameof(inner)); + _auditWriter = auditWriter ?? throw new ArgumentNullException(nameof(auditWriter)); + _connectionName = connectionName ?? throw new ArgumentNullException(nameof(connectionName)); + _siteId = siteId ?? string.Empty; + _instanceName = instanceName ?? string.Empty; + _sourceScript = sourceScript; + _logger = logger ?? throw new ArgumentNullException(nameof(logger)); + } + + // -- Forwarded surface ------------------------------------------------ + +#pragma warning disable CS8765 // ADO.NET base members carry pre-NRT signatures with permissive nullability + public override string CommandText + { + get => _inner.CommandText; + set => _inner.CommandText = value; + } +#pragma warning restore CS8765 + + public override int CommandTimeout + { + get => _inner.CommandTimeout; + set => _inner.CommandTimeout = value; + } + + public override CommandType CommandType + { + get => _inner.CommandType; + set => _inner.CommandType = value; + } + + public override bool DesignTimeVisible + { + get => _inner.DesignTimeVisible; + set => _inner.DesignTimeVisible = value; + } + + public override UpdateRowSource UpdatedRowSource + { + get => _inner.UpdatedRowSource; + set => _inner.UpdatedRowSource = value; + } + + protected override DbConnection? DbConnection + { + // When the script has wrapped the connection (the normal path through + // ScriptRuntimeContext.DatabaseHelper.Connection) we keep returning + // the wrapper, but writes from the user go through to the inner + // command so the underlying provider keeps its wiring intact. + get => _wrappingConnection ?? _inner.Connection; + set + { + _wrappingConnection = value; + _inner.Connection = value switch + { + AuditingDbConnection auditing => auditing.GetType() + .GetField("_inner", System.Reflection.BindingFlags.Instance | System.Reflection.BindingFlags.NonPublic) + !.GetValue(auditing) as DbConnection, + _ => value + }; + } + } + + protected override DbParameterCollection DbParameterCollection => _inner.Parameters; + + protected override DbTransaction? DbTransaction + { + get => _inner.Transaction; + set => _inner.Transaction = value; + } + + public override void Cancel() => _inner.Cancel(); + + public override void Prepare() => _inner.Prepare(); + + protected override DbParameter CreateDbParameter() => _inner.CreateParameter(); + + // -- Audited execution surface --------------------------------------- + + public override int ExecuteNonQuery() + { + var occurredAtUtc = DateTime.UtcNow; + var startTicks = Stopwatch.GetTimestamp(); + int rows = 0; + Exception? thrown = null; + try + { + rows = _inner.ExecuteNonQuery(); + return rows; + } + catch (Exception ex) + { + thrown = ex; + throw; + } + finally + { + EmitAudit( + occurredAtUtc, + ElapsedMs(startTicks), + op: "write", + rowsAffected: thrown == null ? rows : (int?)null, + rowsReturned: null, + thrown); + } + } + + public override object? ExecuteScalar() + { + var occurredAtUtc = DateTime.UtcNow; + var startTicks = Stopwatch.GetTimestamp(); + object? scalar = null; + Exception? thrown = null; + try + { + scalar = _inner.ExecuteScalar(); + return scalar; + } + catch (Exception ex) + { + thrown = ex; + throw; + } + finally + { + // ExecuteScalar is classified as "write" per the M4 vocabulary + // lock — it's a single-value execution; rowsAffected mirrors the + // inner command's value if exposed (DbCommand has no RecordsAffected + // property, so we report -1 when the provider didn't surface it). + EmitAudit( + occurredAtUtc, + ElapsedMs(startTicks), + op: "write", + rowsAffected: thrown == null ? -1 : (int?)null, + rowsReturned: null, + thrown); + } + } + + public override async Task ExecuteNonQueryAsync(CancellationToken cancellationToken) + { + var occurredAtUtc = DateTime.UtcNow; + var startTicks = Stopwatch.GetTimestamp(); + int rows = 0; + Exception? thrown = null; + try + { + rows = await _inner.ExecuteNonQueryAsync(cancellationToken).ConfigureAwait(false); + return rows; + } + catch (Exception ex) + { + thrown = ex; + throw; + } + finally + { + EmitAudit( + occurredAtUtc, + ElapsedMs(startTicks), + op: "write", + rowsAffected: thrown == null ? rows : (int?)null, + rowsReturned: null, + thrown); + } + } + + public override async Task ExecuteScalarAsync(CancellationToken cancellationToken) + { + var occurredAtUtc = DateTime.UtcNow; + var startTicks = Stopwatch.GetTimestamp(); + object? scalar = null; + Exception? thrown = null; + try + { + scalar = await _inner.ExecuteScalarAsync(cancellationToken).ConfigureAwait(false); + return scalar; + } + catch (Exception ex) + { + thrown = ex; + throw; + } + finally + { + EmitAudit( + occurredAtUtc, + ElapsedMs(startTicks), + op: "write", + rowsAffected: thrown == null ? -1 : (int?)null, + rowsReturned: null, + thrown); + } + } + + protected override DbDataReader ExecuteDbDataReader(CommandBehavior behavior) + { + var occurredAtUtc = DateTime.UtcNow; + var startTicks = Stopwatch.GetTimestamp(); + DbDataReader? reader = null; + Exception? thrown = null; + try + { + reader = _inner.ExecuteReader(behavior); + return new AuditingDbDataReader( + reader, + onClose: rows => EmitAudit( + occurredAtUtc, + ElapsedMs(startTicks), + op: "read", + rowsAffected: null, + rowsReturned: rows, + thrown: null)); + } + catch (Exception ex) + { + thrown = ex; + // Emit the failure row immediately — no reader to wait on. + EmitAudit( + occurredAtUtc, + ElapsedMs(startTicks), + op: "read", + rowsAffected: null, + rowsReturned: null, + thrown); + throw; + } + } + + protected override async Task ExecuteDbDataReaderAsync( + CommandBehavior behavior, CancellationToken cancellationToken) + { + var occurredAtUtc = DateTime.UtcNow; + var startTicks = Stopwatch.GetTimestamp(); + DbDataReader? reader = null; + Exception? thrown = null; + try + { + reader = await _inner.ExecuteReaderAsync(behavior, cancellationToken).ConfigureAwait(false); + return new AuditingDbDataReader( + reader, + onClose: rows => EmitAudit( + occurredAtUtc, + ElapsedMs(startTicks), + op: "read", + rowsAffected: null, + rowsReturned: rows, + thrown: null)); + } + catch (Exception ex) + { + thrown = ex; + EmitAudit( + occurredAtUtc, + ElapsedMs(startTicks), + op: "read", + rowsAffected: null, + rowsReturned: null, + thrown); + throw; + } + } + + protected override void Dispose(bool disposing) + { + if (disposing) + { + _inner.Dispose(); + } + base.Dispose(disposing); + } + + // -- Emission --------------------------------------------------------- + + private static int ElapsedMs(long startTicks) => + (int)((Stopwatch.GetTimestamp() - startTicks) * 1000d / Stopwatch.Frequency); + + /// + /// Best-effort emission of one DbOutbound/DbWrite audit row. + /// Mirrors the M2 Bundle F EmitCallAudit 3-layer fail-safe pattern. + /// + private void EmitAudit( + DateTime occurredAtUtc, + int durationMs, + string op, + int? rowsAffected, + int? rowsReturned, + Exception? thrown) + { + AuditEvent evt; + try + { + evt = BuildAuditEvent(occurredAtUtc, durationMs, op, rowsAffected, rowsReturned, thrown); + } + catch (Exception buildEx) + { + // Defensive: building the event from already-validated fields + // shouldn't throw, but the alog.md §7 contract requires we never + // propagate to the user-facing action regardless. + _logger.LogWarning(buildEx, + "Failed to build Audit Log #23 event for {Connection} (op={Op}) — skipping emission", + _connectionName, op); + return; + } + + try + { + var writeTask = _auditWriter.WriteAsync(evt, CancellationToken.None); + if (!writeTask.IsCompleted) + { + writeTask.ContinueWith( + t => _logger.LogWarning(t.Exception, + "Audit Log #23 write failed for EventId {EventId} ({Connection} op={Op})", + evt.EventId, _connectionName, op), + CancellationToken.None, + TaskContinuationOptions.OnlyOnFaulted | TaskContinuationOptions.ExecuteSynchronously, + TaskScheduler.Default); + } + else if (writeTask.IsFaulted) + { + _logger.LogWarning(writeTask.Exception, + "Audit Log #23 write failed for EventId {EventId} ({Connection} op={Op})", + evt.EventId, _connectionName, op); + } + } + catch (Exception writeEx) + { + // Synchronous throw from WriteAsync before its own try/catch. + // Swallow + log per alog.md §7. + _logger.LogWarning(writeEx, + "Audit Log #23 write threw synchronously for EventId {EventId} ({Connection} op={Op})", + evt.EventId, _connectionName, op); + } + } + + private AuditEvent BuildAuditEvent( + DateTime occurredAtUtc, + int durationMs, + string op, + int? rowsAffected, + int? rowsReturned, + Exception? thrown) + { + var status = thrown == null ? AuditStatus.Delivered : AuditStatus.Failed; + + // Target = "." so the audit + // row carries a human-recognisable handle without dragging the full + // (potentially huge) statement into the index column. The full + // statement + parameter values live in RequestSummary. + string target = _connectionName; + var sqlSnippet = _inner.CommandText ?? string.Empty; + if (sqlSnippet.Length > 0) + { + var snippet = sqlSnippet.Length > 60 + ? sqlSnippet[..60] + : sqlSnippet; + target = $"{_connectionName}.{snippet}"; + } + + // RequestSummary captures the SQL statement + parameter values by + // default per the alog.md M4 acceptance criteria (M5 will add + // per-connection redaction opt-in). + string? requestSummary = BuildRequestSummary(); + + // Extra carries the op discriminator + row count per the vocabulary + // lock. Build as a small hand-rolled JSON object to avoid pulling + // in System.Text.Json on the hot path. + string extra = op == "write" + ? $"{{\"op\":\"write\",\"rowsAffected\":{(rowsAffected ?? 0)}}}" + : $"{{\"op\":\"read\",\"rowsReturned\":{(rowsReturned ?? 0)}}}"; + + return new AuditEvent + { + EventId = Guid.NewGuid(), + OccurredAtUtc = DateTime.SpecifyKind(occurredAtUtc, DateTimeKind.Utc), + Channel = AuditChannel.DbOutbound, + Kind = AuditKind.DbWrite, + CorrelationId = null, + SourceSiteId = string.IsNullOrEmpty(_siteId) ? null : _siteId, + SourceInstanceId = _instanceName, + SourceScript = _sourceScript, + Actor = null, + Target = target, + Status = status, + HttpStatus = null, + DurationMs = durationMs, + ErrorMessage = thrown?.Message, + ErrorDetail = thrown?.ToString(), + RequestSummary = requestSummary, + ResponseSummary = null, + PayloadTruncated = false, + Extra = extra, + ForwardState = AuditForwardState.Pending, + }; + } + + /// + /// Compose a JSON request summary capturing the SQL statement and + /// parameter values. Parameter values are captured by default per the + /// M4 acceptance criteria — redaction is opt-in and deferred to M5. + /// + private string? BuildRequestSummary() + { + var sql = _inner.CommandText; + if (string.IsNullOrEmpty(sql)) + { + return null; + } + + // Hand-roll the JSON so we don't pull in System.Text.Json for a + // shape this small. Values are stringified with ToString() — fully + // structured serialisation arrives with the redaction work in M5. + var sb = new System.Text.StringBuilder(sql.Length + 64); + sb.Append("{\"sql\":"); + AppendJsonString(sb, sql); + + if (_inner.Parameters.Count > 0) + { + sb.Append(",\"parameters\":{"); + var first = true; + foreach (DbParameter p in _inner.Parameters) + { + if (!first) sb.Append(','); + first = false; + AppendJsonString(sb, p.ParameterName); + sb.Append(':'); + if (p.Value is null || p.Value is DBNull) + { + sb.Append("null"); + } + else + { + AppendJsonString(sb, p.Value.ToString() ?? string.Empty); + } + } + sb.Append('}'); + } + + sb.Append('}'); + return sb.ToString(); + } + + private static void AppendJsonString(System.Text.StringBuilder sb, string value) + { + sb.Append('"'); + foreach (var ch in value) + { + switch (ch) + { + case '"': sb.Append("\\\""); break; + case '\\': sb.Append("\\\\"); break; + case '\b': sb.Append("\\b"); break; + case '\f': sb.Append("\\f"); break; + case '\n': sb.Append("\\n"); break; + case '\r': sb.Append("\\r"); break; + case '\t': sb.Append("\\t"); break; + default: + if (ch < 0x20) + { + sb.Append("\\u").Append(((int)ch).ToString("x4")); + } + else + { + sb.Append(ch); + } + break; + } + } + sb.Append('"'); + } +} diff --git a/src/ScadaLink.SiteRuntime/Scripts/AuditingDbConnection.cs b/src/ScadaLink.SiteRuntime/Scripts/AuditingDbConnection.cs new file mode 100644 index 0000000..a1e6121 --- /dev/null +++ b/src/ScadaLink.SiteRuntime/Scripts/AuditingDbConnection.cs @@ -0,0 +1,116 @@ +using System.Data; +using System.Data.Common; +using Microsoft.Extensions.Logging; +using ScadaLink.Commons.Interfaces.Services; + +namespace ScadaLink.SiteRuntime.Scripts; + +/// +/// Audit Log #23 — M4 Bundle A: thin decorator over the +/// returned by +/// . The decorator +/// itself does no audit work — it simply intercepts +/// so the handed back to +/// the script is wrapped in an that emits one +/// DbOutbound/DbWrite audit row per execution. +/// +/// +/// +/// All other members forward to the inner connection +/// unchanged so the script keeps full ADO.NET semantics (transactions, state +/// transitions, server-version queries, etc.). Disposing the wrapper disposes +/// the inner connection — the caller is still responsible for disposal per +/// the contract. +/// +/// +/// The audit-write failure contract (alog.md §7) is honoured at the +/// layer — see that class for the 3-layer +/// fail-safe pattern (build, write, observe). +/// +/// +internal sealed class AuditingDbConnection : DbConnection +{ + private readonly DbConnection _inner; + private readonly IAuditWriter _auditWriter; + private readonly string _connectionName; + private readonly string _siteId; + private readonly string _instanceName; + private readonly string? _sourceScript; + private readonly ILogger _logger; + + public AuditingDbConnection( + DbConnection inner, + IAuditWriter auditWriter, + string connectionName, + string siteId, + string instanceName, + string? sourceScript, + ILogger logger) + { + _inner = inner ?? throw new ArgumentNullException(nameof(inner)); + _auditWriter = auditWriter ?? throw new ArgumentNullException(nameof(auditWriter)); + _connectionName = connectionName ?? throw new ArgumentNullException(nameof(connectionName)); + _siteId = siteId ?? string.Empty; + _instanceName = instanceName ?? string.Empty; + _sourceScript = sourceScript; + _logger = logger ?? throw new ArgumentNullException(nameof(logger)); + } + + // ConnectionString is settable on DbConnection — forward both halves. + public override string ConnectionString + { + // Some providers throw on get when the connection hasn't been opened + // with a string set explicitly. The wrapper has no opinion — forward. +#pragma warning disable CS8765 // nullability of overridden member parameter — base setter accepts null in practice + get => _inner.ConnectionString; + set => _inner.ConnectionString = value; +#pragma warning restore CS8765 + } + + public override string Database => _inner.Database; + public override string DataSource => _inner.DataSource; + public override string ServerVersion => _inner.ServerVersion; + public override ConnectionState State => _inner.State; + + public override void ChangeDatabase(string databaseName) => _inner.ChangeDatabase(databaseName); + public override void Close() => _inner.Close(); + public override void Open() => _inner.Open(); + public override Task OpenAsync(CancellationToken cancellationToken) => _inner.OpenAsync(cancellationToken); + + protected override DbTransaction BeginDbTransaction(IsolationLevel isolationLevel) + => _inner.BeginTransaction(isolationLevel); + + protected override DbCommand CreateDbCommand() + { + var innerCmd = _inner.CreateCommand(); + // Hand the script an auditing wrapper. The wrapper preserves the + // inner command's identity for parameters / type maps via delegation. + return new AuditingDbCommand( + innerCmd, + _auditWriter, + _connectionName, + _siteId, + _instanceName, + _sourceScript, + _logger); + } + + protected override void Dispose(bool disposing) + { + if (disposing) + { + _inner.Dispose(); + } + base.Dispose(disposing); + } + + public override ValueTask DisposeAsync() + { + // DbConnection.DisposeAsync is virtual; calling base would run the + // synchronous Dispose path. Forward to the inner connection + // asynchronously and short-circuit the base. + var task = _inner.DisposeAsync(); + GC.SuppressFinalize(this); + return task; + } +} diff --git a/src/ScadaLink.SiteRuntime/Scripts/AuditingDbDataReader.cs b/src/ScadaLink.SiteRuntime/Scripts/AuditingDbDataReader.cs new file mode 100644 index 0000000..3b1eae1 --- /dev/null +++ b/src/ScadaLink.SiteRuntime/Scripts/AuditingDbDataReader.cs @@ -0,0 +1,157 @@ +using System.Collections; +using System.Data.Common; + +namespace ScadaLink.SiteRuntime.Scripts; + +/// +/// Audit Log #23 — M4 Bundle A: decorator that +/// counts the number of rows read by the script and fires a single audit +/// emission callback when the reader closes. +/// +/// +/// +/// The wrapping reader counts each successful / +/// and invokes onClose +/// exactly once — on , , or +/// disposal — with the running tally. This lets +/// emit one +/// DbOutbound/DbWrite row per ExecuteReader with +/// Extra.rowsReturned populated, matching the M4 vocabulary lock. +/// +/// +/// Multiple result sets via are folded into a single +/// rowsReturned tally — the script sees one audit row per +/// ExecuteReader call, not per result set. +/// +/// +internal sealed class AuditingDbDataReader : DbDataReader +{ + private readonly DbDataReader _inner; + private readonly Action _onClose; + private int _rowsReturned; + private bool _closed; + + public AuditingDbDataReader(DbDataReader inner, Action onClose) + { + _inner = inner ?? throw new ArgumentNullException(nameof(inner)); + _onClose = onClose ?? throw new ArgumentNullException(nameof(onClose)); + } + + // -- Row-count interception ------------------------------------------ + + public override bool Read() + { + var more = _inner.Read(); + if (more) _rowsReturned++; + return more; + } + + public override async Task ReadAsync(CancellationToken cancellationToken) + { + var more = await _inner.ReadAsync(cancellationToken).ConfigureAwait(false); + if (more) _rowsReturned++; + return more; + } + + public override void Close() + { + if (!_closed) + { + _closed = true; + try { _inner.Close(); } + finally { SafeFireOnClose(); } + } + } + + public override async Task CloseAsync() + { + if (!_closed) + { + _closed = true; + try { await _inner.CloseAsync().ConfigureAwait(false); } + finally { SafeFireOnClose(); } + } + } + + protected override void Dispose(bool disposing) + { + if (disposing) + { + // DbDataReader.Dispose calls Close on most providers, but we + // guard with _closed to ensure onClose fires exactly once. + if (!_closed) + { + _closed = true; + try { _inner.Dispose(); } + finally { SafeFireOnClose(); } + } + else + { + _inner.Dispose(); + } + } + base.Dispose(disposing); + } + + public override async ValueTask DisposeAsync() + { + if (!_closed) + { + _closed = true; + try { await _inner.DisposeAsync().ConfigureAwait(false); } + finally { SafeFireOnClose(); } + } + else + { + await _inner.DisposeAsync().ConfigureAwait(false); + } + GC.SuppressFinalize(this); + } + + private void SafeFireOnClose() + { + // The onClose callback runs the audit emission, which is itself + // best-effort and swallows internally — but defend the reader's own + // close path anyway so an audit fault never propagates out of + // Close/Dispose. + try { _onClose(_rowsReturned); } + catch { /* audit emission is best-effort by contract */ } + } + + // -- Forwarded surface ------------------------------------------------ + + public override object this[int ordinal] => _inner[ordinal]; + public override object this[string name] => _inner[name]; + public override int Depth => _inner.Depth; + public override int FieldCount => _inner.FieldCount; + public override bool HasRows => _inner.HasRows; + public override bool IsClosed => _inner.IsClosed; + public override int RecordsAffected => _inner.RecordsAffected; + public override int VisibleFieldCount => _inner.VisibleFieldCount; + public override bool GetBoolean(int ordinal) => _inner.GetBoolean(ordinal); + public override byte GetByte(int ordinal) => _inner.GetByte(ordinal); + public override long GetBytes(int ordinal, long dataOffset, byte[]? buffer, int bufferOffset, int length) + => _inner.GetBytes(ordinal, dataOffset, buffer, bufferOffset, length); + public override char GetChar(int ordinal) => _inner.GetChar(ordinal); + public override long GetChars(int ordinal, long dataOffset, char[]? buffer, int bufferOffset, int length) + => _inner.GetChars(ordinal, dataOffset, buffer, bufferOffset, length); + public override string GetDataTypeName(int ordinal) => _inner.GetDataTypeName(ordinal); + public override DateTime GetDateTime(int ordinal) => _inner.GetDateTime(ordinal); + public override decimal GetDecimal(int ordinal) => _inner.GetDecimal(ordinal); + public override double GetDouble(int ordinal) => _inner.GetDouble(ordinal); + public override IEnumerator GetEnumerator() => ((IEnumerable)_inner).GetEnumerator(); + public override Type GetFieldType(int ordinal) => _inner.GetFieldType(ordinal); + public override float GetFloat(int ordinal) => _inner.GetFloat(ordinal); + public override Guid GetGuid(int ordinal) => _inner.GetGuid(ordinal); + public override short GetInt16(int ordinal) => _inner.GetInt16(ordinal); + public override int GetInt32(int ordinal) => _inner.GetInt32(ordinal); + public override long GetInt64(int ordinal) => _inner.GetInt64(ordinal); + public override string GetName(int ordinal) => _inner.GetName(ordinal); + public override int GetOrdinal(string name) => _inner.GetOrdinal(name); + public override string GetString(int ordinal) => _inner.GetString(ordinal); + public override object GetValue(int ordinal) => _inner.GetValue(ordinal); + public override int GetValues(object[] values) => _inner.GetValues(values); + public override bool IsDBNull(int ordinal) => _inner.IsDBNull(ordinal); + public override bool NextResult() => _inner.NextResult(); + public override Task NextResultAsync(CancellationToken cancellationToken) => _inner.NextResultAsync(cancellationToken); +} diff --git a/src/ScadaLink.SiteRuntime/Scripts/ScriptRuntimeContext.cs b/src/ScadaLink.SiteRuntime/Scripts/ScriptRuntimeContext.cs index b5eceaa..f7d838f 100644 --- a/src/ScadaLink.SiteRuntime/Scripts/ScriptRuntimeContext.cs +++ b/src/ScadaLink.SiteRuntime/Scripts/ScriptRuntimeContext.cs @@ -252,7 +252,16 @@ public class ScriptRuntimeContext /// Database.CachedWrite("name", "sql", params) /// public DatabaseHelper Database => new( - _databaseGateway, _instanceName, _logger, _siteId, _sourceScript, + _databaseGateway, + _instanceName, + _logger, + // Audit Log #23 (M4 Bundle A): wire the IAuditWriter so + // Database.Connection(name) returns an auditing decorator that + // emits one DbOutbound/DbWrite row per script-initiated + // Execute / ExecuteScalar / ExecuteReader. + _auditWriter, + _siteId, + _sourceScript, // Audit Log #23 (M3 Bundle E — Task E6): emit CachedSubmit telemetry on // every Database.CachedWrite enqueue. _cachedForwarder); @@ -263,8 +272,16 @@ public class ScriptRuntimeContext /// for central delivery and returns its NotificationId; /// Notify.Status(id) queries the delivery status of that notification. /// + /// + /// Audit Log #23 (M4 Bundle C): the is threaded + /// through so Notify.To(list).Send(...) emits one + /// Notification/NotifySend audit row per accepted submission. + /// Best-effort per alog.md §7 — a thrown writer never aborts the script's + /// Send. + /// public NotifyHelper Notify => new( - _storeAndForward, _siteCommunicationActor, _siteId, _instanceName, _sourceScript, _askTimeout, _logger); + _storeAndForward, _siteCommunicationActor, _siteId, _instanceName, _sourceScript, _askTimeout, _logger, + _auditWriter); /// /// Audit Log #23 (M3): site-local tracking-status API for cached operations. @@ -894,10 +911,23 @@ public class ScriptRuntimeContext private readonly string? _sourceScript; private readonly ICachedCallTelemetryForwarder? _cachedForwarder; + /// + /// Audit Log #23 (M4 Bundle A): best-effort emitter for synchronous + /// Database.Connection-routed Execute / ExecuteScalar / + /// ExecuteReader calls. When wired, returns + /// an that intercepts each command + /// execution and writes one DbOutbound/DbWrite audit + /// row. Optional — when null the helper falls back to the raw + /// inner the gateway + /// returns (tests / minimal hosts that don't wire audit). + /// + private readonly IAuditWriter? _auditWriter; + internal DatabaseHelper( IDatabaseGateway? gateway, string instanceName, ILogger logger, + IAuditWriter? auditWriter = null, string siteId = "", string? sourceScript = null, ICachedCallTelemetryForwarder? cachedForwarder = null) @@ -905,6 +935,7 @@ public class ScriptRuntimeContext _gateway = gateway; _instanceName = instanceName; _logger = logger; + _auditWriter = auditWriter; _siteId = siteId; _sourceScript = sourceScript; _cachedForwarder = cachedForwarder; @@ -917,7 +948,28 @@ public class ScriptRuntimeContext if (_gateway == null) throw new InvalidOperationException("Database gateway not available"); - return await _gateway.GetConnectionAsync(name, cancellationToken); + var inner = await _gateway.GetConnectionAsync(name, cancellationToken); + + // Audit Log #23 (M4 Bundle A): wrap in an auditing decorator so + // every script-initiated Execute* / ExecuteReader on the returned + // connection emits one DbOutbound/DbWrite audit row. The wrapper + // delegates all other ADO.NET behaviour to the inner connection + // unchanged — including disposal, so the caller's existing + // dispose pattern (await using var conn = ...) still releases + // the underlying connection to the pool. + if (_auditWriter == null) + { + return inner; + } + + return new AuditingDbConnection( + inner, + _auditWriter, + connectionName: name, + siteId: _siteId, + instanceName: _instanceName, + sourceScript: _sourceScript, + logger: _logger); } /// @@ -1046,6 +1098,16 @@ public class ScriptRuntimeContext private readonly TimeSpan _askTimeout; private readonly ILogger _logger; + /// + /// Audit Log #23 (M4 Bundle C): best-effort emitter for the + /// Notification/NotifySend row produced when the script + /// calls Notify.To(list).Send(...). Optional — when null the + /// degrades to a no-op audit path so tests + /// / minimal hosts that don't wire AddAuditLog still work (mirrors the + /// M2 Bundle F IExternalSystemClient wrapper). + /// + private readonly IAuditWriter? _auditWriter; + internal NotifyHelper( StoreAndForwardService? storeAndForward, ICanTell? siteCommunicationActor, @@ -1053,7 +1115,8 @@ public class ScriptRuntimeContext string instanceName, string? sourceScript, TimeSpan askTimeout, - ILogger logger) + ILogger logger, + IAuditWriter? auditWriter = null) { _storeAndForward = storeAndForward; _siteCommunicationActor = siteCommunicationActor; @@ -1062,6 +1125,7 @@ public class ScriptRuntimeContext _sourceScript = sourceScript; _askTimeout = askTimeout; _logger = logger; + _auditWriter = auditWriter; } /// @@ -1070,7 +1134,10 @@ public class ScriptRuntimeContext public NotifyTarget To(string listName) { return new NotifyTarget( - listName, _storeAndForward, _siteId, _instanceName, _sourceScript, _logger); + listName, _storeAndForward, _siteId, _instanceName, _sourceScript, _logger, + // Audit Log #23 (M4 Bundle C): forward the writer so Send() + // can emit one NotifySend(Submitted) row per accepted submission. + _auditWriter); } /// @@ -1145,13 +1212,22 @@ public class ScriptRuntimeContext private readonly string? _sourceScript; private readonly ILogger _logger; + /// + /// Audit Log #23 (M4 Bundle C): best-effort emitter for the + /// Notification/NotifySend row written immediately after + /// the underlying S&F enqueue accepts the submission. Optional — + /// when null no audit row is emitted (no-op path). + /// + private readonly IAuditWriter? _auditWriter; + internal NotifyTarget( string listName, StoreAndForwardService? storeAndForward, string siteId, string instanceName, string? sourceScript, - ILogger logger) + ILogger logger, + IAuditWriter? auditWriter = null) { _listName = listName; _storeAndForward = storeAndForward; @@ -1159,6 +1235,7 @@ public class ScriptRuntimeContext _instanceName = instanceName; _sourceScript = sourceScript; _logger = logger; + _auditWriter = auditWriter; } /// @@ -1207,6 +1284,7 @@ public class ScriptRuntimeContext // The S&F engine assigns its own GUID to the message; pin the message id to // the NotificationId so the buffer can be queried by it (Notify.Status) and // the forwarder's idempotency key matches the buffered row. + var occurredAtUtc = DateTime.UtcNow; await _storeAndForward.EnqueueAsync( StoreAndForwardCategory.Notification, target: _listName, @@ -1218,8 +1296,125 @@ public class ScriptRuntimeContext "Notify enqueued notification {NotificationId} to list '{List}' for central delivery", notificationId, _listName); + // Audit Log #23 (M4 Bundle C): emit one Notification/NotifySend + // (Submitted) row per accepted submission. The emission is wired + // AFTER the EnqueueAsync returns so we only audit submissions the + // S&F engine accepted — a failed enqueue throws, never produces an + // audit row (mirrors ESG: audit fires after the boundary call + // returned a result, never speculatively). Best-effort per alog.md + // §7 — the audit write is wrapped in try/catch and any failure is + // logged + swallowed so the script's Send call still returns the + // NotificationId. + EmitNotifySendAudit(notificationId, subject, message, occurredAtUtc); + return notificationId; } + + /// + /// Best-effort emission of one Notification/NotifySend + /// (Status Submitted) audit row. Any exception thrown by the + /// writer is logged and swallowed — audit-write failures must never + /// abort the user-facing Notify.Send call (alog.md §7). + /// + private void EmitNotifySendAudit( + string notificationId, + string subject, + string body, + DateTime occurredAtUtc) + { + if (_auditWriter == null) + { + return; + } + + AuditEvent evt; + try + { + // CorrelationId is the NotificationId parsed as a Guid. Notify + // mints the id via Guid.NewGuid().ToString("N") so the parse + // is expected to succeed; on the off-chance the format + // changes / a caller injects an unparseable value, leave it + // null per Bundle B's pattern rather than fail the emission. + Guid? correlationId = Guid.TryParse(notificationId, out var parsed) ? parsed : (Guid?)null; + + // M4 captures the request summary verbatim — {"subject": "...", "body": "..."}. + // M5 will layer redaction / payload-cap enforcement on top. + var requestSummary = JsonSerializer.Serialize(new + { + subject = subject, + body = body, + }); + + evt = new AuditEvent + { + EventId = Guid.NewGuid(), + OccurredAtUtc = DateTime.SpecifyKind(occurredAtUtc, DateTimeKind.Utc), + Channel = AuditChannel.Notification, + Kind = AuditKind.NotifySend, + CorrelationId = correlationId, + SourceSiteId = string.IsNullOrEmpty(_siteId) ? null : _siteId, + SourceInstanceId = _instanceName, + SourceScript = _sourceScript, + Actor = null, + Target = _listName, + Status = AuditStatus.Submitted, + HttpStatus = null, + // Send is fire-and-forget from the script's perspective — + // the dispatcher (NotificationOutboxActor) times each + // delivery attempt and stamps DurationMs on its + // NotifyDeliver(Attempted) rows. + DurationMs = null, + ErrorMessage = null, + ErrorDetail = null, + RequestSummary = requestSummary, + ResponseSummary = null, + PayloadTruncated = false, + Extra = null, + ForwardState = AuditForwardState.Pending, + }; + } + catch (Exception buildEx) + { + // Defensive: building the event itself must never propagate. + _logger.LogWarning(buildEx, + "Failed to build Audit Log #23 NotifySend event for NotificationId {NotificationId} list '{List}' — skipping emission", + notificationId, _listName); + return; + } + + try + { + // Fire-and-forget (mirrors ExternalSystemHelper.EmitCallAudit) + // so the script is never blocked on the audit writer; we observe + // failures via ContinueWith so a thrown writer is logged rather + // than going to the unobserved-task firehose. + var writeTask = _auditWriter.WriteAsync(evt, CancellationToken.None); + if (!writeTask.IsCompleted) + { + writeTask.ContinueWith( + t => _logger.LogWarning(t.Exception, + "Audit Log #23 write failed for EventId {EventId} (NotifySend NotificationId {NotificationId})", + evt.EventId, notificationId), + CancellationToken.None, + TaskContinuationOptions.OnlyOnFaulted | TaskContinuationOptions.ExecuteSynchronously, + TaskScheduler.Default); + } + else if (writeTask.IsFaulted) + { + _logger.LogWarning(writeTask.Exception, + "Audit Log #23 write failed for EventId {EventId} (NotifySend NotificationId {NotificationId})", + evt.EventId, notificationId); + } + } + catch (Exception writeEx) + { + // Synchronous throw from WriteAsync (e.g. ArgumentNullException + // before the writer's own try/catch). Swallow + log per alog.md §7. + _logger.LogWarning(writeEx, + "Audit Log #23 write threw synchronously for EventId {EventId} (NotifySend NotificationId {NotificationId})", + evt.EventId, notificationId); + } + } } /// diff --git a/tests/ScadaLink.AuditLog.Tests/AddAuditLogTests.cs b/tests/ScadaLink.AuditLog.Tests/AddAuditLogTests.cs index 03d337a..61d0031 100644 --- a/tests/ScadaLink.AuditLog.Tests/AddAuditLogTests.cs +++ b/tests/ScadaLink.AuditLog.Tests/AddAuditLogTests.cs @@ -3,6 +3,7 @@ using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Options; +using ScadaLink.AuditLog.Central; using ScadaLink.AuditLog.Configuration; using ScadaLink.AuditLog.Site; using ScadaLink.AuditLog.Site.Telemetry; @@ -155,6 +156,34 @@ public class AddAuditLogTests Assert.IsType(client); } + // -- M4 Bundle B (B1) central direct-write audit writer ----------------- + + [Fact] + public void AddAuditLog_Registers_ICentralAuditWriter_AsCentralAuditWriter() + { + using var provider = BuildProvider(new Dictionary + { + ["AuditLog:SiteWriter:DatabasePath"] = ":memory:", + }); + + var writer = provider.GetService(); + Assert.NotNull(writer); + Assert.IsType(writer); + } + + [Fact] + public void AddAuditLog_ICentralAuditWriter_IsSingleton() + { + using var provider = BuildProvider(new Dictionary + { + ["AuditLog:SiteWriter:DatabasePath"] = ":memory:", + }); + + var w1 = provider.GetService(); + var w2 = provider.GetService(); + Assert.Same(w1, w2); + } + [Fact] public void AddAuditLog_Options_Bind_RoundTrip_SqliteWriter() { diff --git a/tests/ScadaLink.AuditLog.Tests/Central/CentralAuditWriterTests.cs b/tests/ScadaLink.AuditLog.Tests/Central/CentralAuditWriterTests.cs new file mode 100644 index 0000000..1a9ca3b --- /dev/null +++ b/tests/ScadaLink.AuditLog.Tests/Central/CentralAuditWriterTests.cs @@ -0,0 +1,127 @@ +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Abstractions; +using NSubstitute; +using NSubstitute.ExceptionExtensions; +using ScadaLink.AuditLog.Central; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Enums; + +namespace ScadaLink.AuditLog.Tests.Central; + +/// +/// M4 Bundle B1 — unit tests for , the +/// central-only direct-write implementation of . +/// The writer is a thin wrapper around +/// : it stamps +/// , resolves the (scoped) repository +/// from a fresh DI scope per call, and swallows any thrown exception — +/// audit-write failures NEVER abort the user-facing action (alog.md §13). +/// +public class CentralAuditWriterTests +{ + private static AuditEvent NewEvent(Guid? eventId = null) => new() + { + EventId = eventId ?? Guid.NewGuid(), + OccurredAtUtc = new DateTime(2026, 5, 20, 10, 0, 0, DateTimeKind.Utc), + Channel = AuditChannel.Notification, + Kind = AuditKind.NotifyDeliver, + Status = AuditStatus.Attempted, + CorrelationId = Guid.NewGuid(), + Target = "ops-team", + }; + + private static (CentralAuditWriter writer, IAuditLogRepository repo) BuildWriter() + { + var repo = Substitute.For(); + var services = new ServiceCollection(); + services.AddScoped(_ => repo); + var provider = services.BuildServiceProvider(); + return (new CentralAuditWriter(provider, NullLogger.Instance), repo); + } + + [Fact] + public async Task WriteAsync_PassesEvent_To_InsertIfNotExistsAsync() + { + var (writer, repo) = BuildWriter(); + var evt = NewEvent(); + + await writer.WriteAsync(evt); + + await repo.Received(1).InsertIfNotExistsAsync( + Arg.Is(e => e.EventId == evt.EventId), + Arg.Any()); + } + + [Fact] + public async Task WriteAsync_Stamps_IngestedAtUtc_Before_Insert() + { + var (writer, repo) = BuildWriter(); + var before = DateTime.UtcNow; + + await writer.WriteAsync(NewEvent()); + + var after = DateTime.UtcNow; + await repo.Received(1).InsertIfNotExistsAsync( + Arg.Is(e => + e.IngestedAtUtc != null && + e.IngestedAtUtc >= before && + e.IngestedAtUtc <= after), + Arg.Any()); + } + + [Fact] + public async Task WriteAsync_Repository_Throws_DoesNotPropagate() + { + var repo = Substitute.For(); + repo.InsertIfNotExistsAsync(Arg.Any(), Arg.Any()) + .ThrowsAsync(new InvalidOperationException("db down")); + var services = new ServiceCollection(); + services.AddScoped(_ => repo); + var provider = services.BuildServiceProvider(); + var writer = new CentralAuditWriter(provider, NullLogger.Instance); + + // Must not throw — audit failure NEVER aborts the user-facing action. + await writer.WriteAsync(NewEvent()); + } + + [Fact] + public async Task WriteAsync_Resolves_Repository_PerCall_From_Fresh_Scope() + { + // Counting factory: every scope opening should resolve a new repo + // (scoped lifetime). We assert at least two distinct instances + // across two WriteAsync calls. + var instances = new List(); + var services = new ServiceCollection(); + services.AddScoped(_ => + { + var r = Substitute.For(); + instances.Add(r); + return r; + }); + var provider = services.BuildServiceProvider(); + var writer = new CentralAuditWriter(provider, NullLogger.Instance); + + await writer.WriteAsync(NewEvent()); + await writer.WriteAsync(NewEvent()); + + Assert.Equal(2, instances.Count); + Assert.NotSame(instances[0], instances[1]); + } + + [Fact] + public void Constructor_NullServices_Throws() + { + Assert.Throws( + () => new CentralAuditWriter(null!, NullLogger.Instance)); + } + + [Fact] + public void Constructor_NullLogger_Throws() + { + var services = new ServiceCollection().BuildServiceProvider(); + Assert.Throws( + () => new CentralAuditWriter(services, null!)); + } +} diff --git a/tests/ScadaLink.AuditLog.Tests/Integration/AuditWriteFailureSafetyTests.cs b/tests/ScadaLink.AuditLog.Tests/Integration/AuditWriteFailureSafetyTests.cs new file mode 100644 index 0000000..7c505a8 --- /dev/null +++ b/tests/ScadaLink.AuditLog.Tests/Integration/AuditWriteFailureSafetyTests.cs @@ -0,0 +1,472 @@ +using Akka.Actor; +using Akka.TestKit.Xunit2; +using Microsoft.AspNetCore.Builder; +using Microsoft.AspNetCore.Hosting; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.TestHost; +using Microsoft.Data.Sqlite; +using Microsoft.EntityFrameworkCore; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Options; +using NSubstitute; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Entities.Notifications; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Messages.Integration; +using ScadaLink.Commons.Types; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.ConfigurationDatabase; +using ScadaLink.ConfigurationDatabase.Repositories; +using ScadaLink.ConfigurationDatabase.Tests.Migrations; +using ScadaLink.InboundAPI.Middleware; +using ScadaLink.NotificationOutbox; +using ScadaLink.NotificationOutbox.Delivery; +using ScadaLink.NotificationOutbox.Messages; +using ScadaLink.SiteRuntime.Scripts; +using System.Net; +using System.Security.Claims; +using System.Text; +using System.Text.Encodings.Web; + +namespace ScadaLink.AuditLog.Tests.Integration; + +/// +/// Audit Log #23 — M4 Bundle E (Task E4) cross-boundary safety suite verifying +/// the alog.md §13 contract: an always-throwing audit writer NEVER aborts the +/// user-facing action. Exercises every boundary that emits audit rows in M2, +/// M3, and M4: +/// +/// +/// External system sync call (M2 Bundle F). +/// External system cached call (M3 Bundle E). +/// Database sync write (M4 Bundle A). +/// Inbound API request (M4 Bundle D). +/// Notification dispatcher (M4 Bundle B). +/// +/// +/// +/// The site-local boundaries (ESG sync/cached, DB sync) take the always-throw +/// in place of the production +/// ; the central boundaries (Inbound API, +/// Notification dispatcher) take the always-throw +/// in place of +/// . In each case the wrapped action's +/// original return value (or original exception) must still flow back to the +/// caller untouched. +/// +/// +public class AuditWriteFailureSafetyTests : TestKit, IClassFixture +{ + private readonly MsSqlMigrationFixture _fixture; + + public AuditWriteFailureSafetyTests(MsSqlMigrationFixture fixture) + { + _fixture = fixture; + } + + // --------------------------------------------------------------------- + // Always-throwing writer test doubles + // --------------------------------------------------------------------- + + /// + /// Site-side that ALWAYS throws on + /// . Used to verify that ESG / DB script-side + /// helpers swallow the throw and return their normal result to the script. + /// + private sealed class ThrowingAuditWriter : IAuditWriter + { + private int _attempts; + public int Attempts => Volatile.Read(ref _attempts); + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + Interlocked.Increment(ref _attempts); + return Task.FromException(new InvalidOperationException( + "test-only ThrowingAuditWriter — audit pipeline unavailable")); + } + } + + /// + /// Central-side that ALWAYS throws on + /// . Used to verify Inbound API + Notification + /// dispatcher absorb audit-write failures rather than propagating them + /// into the response / state transition. + /// + private sealed class ThrowingCentralAuditWriter : ICentralAuditWriter + { + private int _attempts; + public int Attempts => Volatile.Read(ref _attempts); + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + Interlocked.Increment(ref _attempts); + throw new InvalidOperationException( + "test-only ThrowingCentralAuditWriter — audit subsystem unavailable"); + } + } + + /// + /// Site-side that ALWAYS + /// throws on . The cached-call helpers absorb + /// the throw and still return a valid . + /// + private sealed class ThrowingCachedForwarder : ICachedCallTelemetryForwarder + { + private int _attempts; + public int Attempts => Volatile.Read(ref _attempts); + + public Task ForwardAsync(CachedCallTelemetry telemetry, CancellationToken ct = default) + { + Interlocked.Increment(ref _attempts); + return Task.FromException(new InvalidOperationException( + "test-only ThrowingCachedForwarder — telemetry pipeline unavailable")); + } + } + + // --------------------------------------------------------------------- + // Test 1 — ESG sync call still returns the original ExternalCallResult. + // --------------------------------------------------------------------- + + [Fact] + public async Task EsgSyncCall_BrokenAuditWriter_StillReturnsResult() + { + var client = Substitute.For(); + var expected = new ExternalCallResult( + Success: true, + ResponseJson: "{\"orderId\":42}", + ErrorMessage: null, + WasBuffered: false); + client.CallAsync( + "ERP", "GetOrder", + Arg.Any?>(), + Arg.Any()) + .Returns(expected); + + var writer = new ThrowingAuditWriter(); + var helper = new ScriptRuntimeContext.ExternalSystemHelper( + client, + instanceName: "Plant.Pump42", + NullLogger.Instance, + auditWriter: writer, + siteId: "site-77", + sourceScript: "ScriptActor:Sync", + cachedForwarder: null); + + var result = await helper.Call("ERP", "GetOrder"); + + Assert.Same(expected, result); + // Proof the audit writer was attempted — otherwise the test wouldn't + // actually exercise the safety contract. + Assert.True(writer.Attempts >= 1, + $"Expected audit writer to be invoked at least once; saw {writer.Attempts}."); + } + + // --------------------------------------------------------------------- + // Test 2 — ESG cached call still returns a TrackedOperationId. + // --------------------------------------------------------------------- + + [Fact] + public async Task EsgCachedCall_BrokenAuditWriter_StillReturnsTrackedOperationId() + { + var client = Substitute.For(); + // CachedCallAsync returns WasBuffered=true so the helper takes the + // S&F-deferred path — no immediate-terminal telemetry, which keeps the + // forwarder attempt count at exactly one (the CachedSubmit emission). + client.CachedCallAsync( + "ERP", "GetOrder", + Arg.Any?>(), + Arg.Any(), + Arg.Any(), + Arg.Any()) + .Returns(new ExternalCallResult(true, null, null, WasBuffered: true)); + + // BOTH the audit writer AND the cached forwarder throw — the + // CachedSubmit emission goes through the forwarder in production, so + // breaking only the writer wouldn't actually exercise the cached + // path's safety contract. + var writer = new ThrowingAuditWriter(); + var forwarder = new ThrowingCachedForwarder(); + var helper = new ScriptRuntimeContext.ExternalSystemHelper( + client, + instanceName: "Plant.Pump42", + NullLogger.Instance, + auditWriter: writer, + siteId: "site-77", + sourceScript: "ScriptActor:Cached", + cachedForwarder: forwarder); + + var trackedId = await helper.CachedCall("ERP", "GetOrder"); + + // Non-default id materialised despite the forwarder failing. + Assert.NotEqual(default, trackedId); + Assert.True(forwarder.Attempts >= 1, + $"Expected cached forwarder to be invoked at least once; saw {forwarder.Attempts}."); + } + + // --------------------------------------------------------------------- + // Test 3 — DB sync write still returns the rows-affected count. + // --------------------------------------------------------------------- + + [Fact] + public async Task DbSyncWrite_BrokenAuditWriter_StillReturnsRowsAffected() + { + const string connectionName = "machineData"; + const string instanceName = "Plant.Pump42"; + + using var keepAlive = new SqliteConnection( + "Data Source=k-safety-db;Mode=Memory;Cache=Shared"); + keepAlive.Open(); + + // Schema + seed inside a unique in-memory DB. + var dbName = $"db-{Guid.NewGuid():N}"; + var connStr = $"Data Source={dbName};Mode=Memory;Cache=Shared"; + using var dbKeepAlive = new SqliteConnection(connStr); + dbKeepAlive.Open(); + using (var seed = dbKeepAlive.CreateCommand()) + { + seed.CommandText = + "CREATE TABLE t (id INTEGER PRIMARY KEY, name TEXT NOT NULL);"; + seed.ExecuteNonQuery(); + } + var inner = new SqliteConnection(connStr); + inner.Open(); + + var gateway = Substitute.For(); + gateway.GetConnectionAsync(connectionName, Arg.Any()) + .Returns(inner); + + var writer = new ThrowingAuditWriter(); + var helper = new ScriptRuntimeContext.DatabaseHelper( + gateway, + instanceName, + NullLogger.Instance, + auditWriter: writer, + siteId: "site-77", + sourceScript: "ScriptActor:Db", + cachedForwarder: null); + + await using (var conn = await helper.Connection(connectionName)) + await using (var cmd = conn.CreateCommand()) + { + cmd.CommandText = "INSERT INTO t (id, name) VALUES (1, 'safety')"; + var rows = await cmd.ExecuteNonQueryAsync(); + Assert.Equal(1, rows); + } + + Assert.True(writer.Attempts >= 1, + $"Expected audit writer to be invoked at least once; saw {writer.Attempts}."); + } + + // --------------------------------------------------------------------- + // Test 4 — Inbound API request still returns HTTP 200. + // --------------------------------------------------------------------- + + [Fact] + public async Task InboundApi_BrokenAuditWriter_StillReturns200() + { + var writer = new ThrowingCentralAuditWriter(); + + using var host = await BuildInboundApiHostAsync(writer, endpointStatus: 200); + var client = host.GetTestClient(); + + var resp = await client.PostAsync( + "/api/echo", + new StringContent("{\"x\":1}", Encoding.UTF8, "application/json")); + + Assert.Equal(HttpStatusCode.OK, resp.StatusCode); + Assert.True(writer.Attempts >= 1, + $"Expected central audit writer to be invoked at least once; saw {writer.Attempts}."); + } + + // --------------------------------------------------------------------- + // Test 5 — Notification dispatcher still transitions to Delivered. + // --------------------------------------------------------------------- + + [SkippableFact] + public async Task NotificationDispatch_BrokenAuditWriter_StillTransitionsToDelivered() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + + var siteId = "test-e4-safety-" + Guid.NewGuid().ToString("N").Substring(0, 8); + var notificationId = Guid.NewGuid(); + + await SeedSmtpConfigAsync(); + await SeedNotificationAsync(notificationId, siteId); + + var adapter = new SingleOutcomeAdapter(DeliveryOutcome.Success("ops@example.com")); + var serviceProvider = BuildNotificationDispatcherProvider(adapter); + var throwingWriter = new ThrowingCentralAuditWriter(); + + var actor = Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( + serviceProvider, + new NotificationOutboxOptions + { + DispatchInterval = TimeSpan.FromHours(1), + PurgeInterval = TimeSpan.FromDays(1), + }, + (ICentralAuditWriter)throwingWriter, + NullLogger.Instance))); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + // Notifications table reflects the successful delivery even though + // every audit write threw — the central direct-write writer + // catches/logs internally and the dispatcher catches defensively too + // (alog.md §13). + await AwaitAssertAsync(async () => + { + await using var ctx = CreateContext(); + var row = await ctx.Notifications.SingleAsync( + n => n.NotificationId == notificationId.ToString("D")); + Assert.Equal(NotificationStatus.Delivered, row.Status); + Assert.NotNull(row.DeliveredAt); + }, TimeSpan.FromSeconds(15)); + + Assert.True(throwingWriter.Attempts >= 1, + $"Expected dispatcher to attempt audit write at least once; saw {throwingWriter.Attempts}."); + } + + // --------------------------------------------------------------------- + // Test infrastructure + // --------------------------------------------------------------------- + + private ScadaLinkDbContext CreateContext() + { + var options = new DbContextOptionsBuilder() + .UseSqlServer(_fixture.ConnectionString) + .ConfigureWarnings(w => w.Ignore( + Microsoft.EntityFrameworkCore.Diagnostics.RelationalEventId.PendingModelChangesWarning)) + .Options; + return new ScadaLinkDbContext(options); + } + + private IServiceProvider BuildNotificationDispatcherProvider( + INotificationDeliveryAdapter adapter) + { + var services = new ServiceCollection(); + services.AddDbContext(opts => + opts.UseSqlServer(_fixture.ConnectionString) + .ConfigureWarnings(w => w.Ignore( + Microsoft.EntityFrameworkCore.Diagnostics.RelationalEventId.PendingModelChangesWarning))); + services.AddScoped(sp => + new NotificationOutboxRepository(sp.GetRequiredService())); + services.AddScoped(sp => + new NotificationRepository(sp.GetRequiredService())); + services.AddScoped(_ => adapter); + return services.BuildServiceProvider(); + } + + private async Task SeedSmtpConfigAsync() + { + await using var ctx = CreateContext(); + ctx.SmtpConfigurations.Add(new SmtpConfiguration( + "smtp.example.com", "Basic", "noreply@example.com") + { + MaxRetries = 5, + RetryDelay = TimeSpan.Zero, + }); + await ctx.SaveChangesAsync(); + } + + private async Task SeedNotificationAsync(Guid notificationId, string siteId) + { + await using var ctx = CreateContext(); + ctx.Notifications.Add(new Notification( + notificationId.ToString("D"), + NotificationType.Email, + "ops-team", + "Safety subject", + "Safety body", + siteId) + { + SourceInstanceId = "Plant.Pump42", + SourceScript = "AlarmScript", + CreatedAt = DateTimeOffset.UtcNow.AddMinutes(-1), + }); + await ctx.SaveChangesAsync(); + } + + /// + /// Single-outcome adapter — returns the same + /// for every call. Used by the dispatcher safety test where we only need + /// one happy-path delivery. + /// + private sealed class SingleOutcomeAdapter : INotificationDeliveryAdapter + { + private readonly DeliveryOutcome _outcome; + public SingleOutcomeAdapter(DeliveryOutcome outcome) { _outcome = outcome; } + public NotificationType Type => NotificationType.Email; + public Task DeliverAsync( + Notification notification, CancellationToken cancellationToken = default) + => Task.FromResult(_outcome); + } + + /// + /// Builds an in-memory TestHost mirroring the production inbound-API + /// pipeline order. The supplied stands in for + /// the production so the safety test can + /// install the always-throwing variant without standing up any DB. + /// + private static async Task BuildInboundApiHostAsync( + ICentralAuditWriter writer, int endpointStatus) + { + var hostBuilder = new HostBuilder() + .ConfigureWebHost(webBuilder => + { + webBuilder + .UseTestServer() + .ConfigureServices(services => + { + services.AddSingleton(writer); + services.AddRouting(); + services.AddAuthorization(); + services.AddAuthentication("TestScheme") + .AddScheme("TestScheme", _ => { }); + }) + .Configure(app => + { + app.UseRouting(); + app.UseAuthentication(); + app.UseAuthorization(); + app.UseAuditWriteMiddleware(); + app.UseEndpoints(endpoints => + { + endpoints.MapPost("/api/{methodName}", async ctx => + { + ctx.Items[AuditWriteMiddleware.AuditActorItemKey] = "safety-actor"; + ctx.Response.StatusCode = endpointStatus; + await ctx.Response.WriteAsync("ok"); + }); + }); + }); + }); + return await hostBuilder.StartAsync(); + } + + private sealed class AlwaysAuthenticatedHandler + : Microsoft.AspNetCore.Authentication.AuthenticationHandler< + Microsoft.AspNetCore.Authentication.AuthenticationSchemeOptions> + { + public AlwaysAuthenticatedHandler( + IOptionsMonitor options, + Microsoft.Extensions.Logging.ILoggerFactory logger, + UrlEncoder encoder) + : base(options, logger, encoder) { } + + protected override Task + HandleAuthenticateAsync() + { + var identity = new ClaimsIdentity( + new[] { new Claim(ClaimTypes.Name, "framework-user") }, "TestScheme"); + var principal = new ClaimsPrincipal(identity); + var ticket = new Microsoft.AspNetCore.Authentication.AuthenticationTicket( + principal, "TestScheme"); + return Task.FromResult( + Microsoft.AspNetCore.Authentication.AuthenticateResult.Success(ticket)); + } + } +} diff --git a/tests/ScadaLink.AuditLog.Tests/Integration/DatabaseSyncEmissionEndToEndTests.cs b/tests/ScadaLink.AuditLog.Tests/Integration/DatabaseSyncEmissionEndToEndTests.cs new file mode 100644 index 0000000..5a73256 --- /dev/null +++ b/tests/ScadaLink.AuditLog.Tests/Integration/DatabaseSyncEmissionEndToEndTests.cs @@ -0,0 +1,297 @@ +using Akka.Actor; +using Akka.TestKit.Xunit2; +using Microsoft.Data.Sqlite; +using Microsoft.EntityFrameworkCore; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Options; +using NSubstitute; +using ScadaLink.AuditLog.Central; +using ScadaLink.AuditLog.Site; +using ScadaLink.AuditLog.Site.Telemetry; +using ScadaLink.AuditLog.Tests.Integration.Infrastructure; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Audit; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.ConfigurationDatabase; +using ScadaLink.ConfigurationDatabase.Repositories; +using ScadaLink.ConfigurationDatabase.Tests.Migrations; +using ScadaLink.SiteRuntime.Scripts; + +namespace ScadaLink.AuditLog.Tests.Integration; + +/// +/// Audit Log #23 — M4 Bundle E (Task E1) end-to-end suite verifying every +/// synchronous Database.Connection(name).Execute* / +/// ExecuteReader call made via the Bundle A +/// emits exactly one +/// / row +/// that materialises in the central MSSQL AuditLog via the production +/// site-SQLite + telemetry-actor + central ingest-actor pipeline. +/// +/// +/// +/// Composes the same pipeline as the M2 : +/// in-memory + + +/// on the site, drained by a real +/// through a +/// stub that short-circuits the +/// gRPC wire and Asks the central backed by +/// the real on the per-class +/// MSSQL database. +/// +/// +/// Drives the AuditingDbConnection wrapper directly via +/// 's internal ctor (the +/// AuditLog tests project has InternalsVisibleTo on SiteRuntime). No +/// script runtime, no Akka Instance Actor — the test wires the helper, opens +/// an in-memory SQLite connection through a stub , +/// runs one SQL statement, and waits for the central row to land. Each test +/// uses a unique SourceSiteId (Guid suffix) so concurrent tests +/// sharing the MSSQL fixture don't interfere with each other. +/// +/// +public class DatabaseSyncEmissionEndToEndTests : TestKit, IClassFixture +{ + private readonly MsSqlMigrationFixture _fixture; + + public DatabaseSyncEmissionEndToEndTests(MsSqlMigrationFixture fixture) + { + _fixture = fixture; + } + + private const string ConnectionName = "machineData"; + private const string InstanceName = "Plant.Pump42"; + private const string SourceScript = "ScriptActor:doDbWork"; + + private static string NewSiteId() => + "test-e1-db-" + Guid.NewGuid().ToString("N").Substring(0, 8); + + private ScadaLinkDbContext CreateContext() + { + var options = new DbContextOptionsBuilder() + .UseSqlServer(_fixture.ConnectionString) + .Options; + return new ScadaLinkDbContext(options); + } + + /// + /// Per-test in-memory SQLite database with a tiny 2-row schema we can both + /// write to and select from. Mirrors the pattern from + /// DatabaseSyncEmissionTests — the keep-alive root keeps the + /// in-memory database file pinned for the duration of the test, while the + /// returned live connection is what the stub gateway hands back to + /// the auditing wrapper. + /// + private static SqliteConnection NewInMemoryDb(out SqliteConnection keepAlive) + { + var dbName = $"db-{Guid.NewGuid():N}"; + var connStr = $"Data Source={dbName};Mode=Memory;Cache=Shared"; + + keepAlive = new SqliteConnection(connStr); + keepAlive.Open(); + using (var seed = keepAlive.CreateCommand()) + { + seed.CommandText = + "CREATE TABLE t (id INTEGER PRIMARY KEY, name TEXT NOT NULL);" + + "INSERT INTO t (id, name) VALUES (1, 'alpha');" + + "INSERT INTO t (id, name) VALUES (2, 'beta');"; + seed.ExecuteNonQuery(); + } + + var live = new SqliteConnection(connStr); + live.Open(); + return live; + } + + private static SqliteAuditWriter CreateInMemorySqliteWriter() => + new( + Options.Create(new SqliteAuditWriterOptions + { + DatabasePath = "ignored", + BatchSize = 64, + ChannelCapacity = 1024, + }), + NullLogger.Instance, + connectionStringOverride: + $"Data Source=file:auditlog-e1-{Guid.NewGuid():N}?mode=memory&cache=shared"); + + private static IOptions FastTelemetryOptions() => + Options.Create(new SiteAuditTelemetryOptions + { + BatchSize = 256, + // 1s on both intervals so the initial scheduled tick fires quickly + // — drains the SQLite Pending row and pushes it through the stub + // gRPC client into the central ingest actor. + BusyIntervalSeconds = 1, + IdleIntervalSeconds = 1, + }); + + private IActorRef CreateIngestActor(IAuditLogRepository repo) => + Sys.ActorOf(Props.Create(() => new AuditLogIngestActor( + repo, + NullLogger.Instance))); + + private IActorRef CreateTelemetryActor( + ISiteAuditQueue queue, + ISiteStreamAuditClient client) => + Sys.ActorOf(Props.Create(() => new SiteAuditTelemetryActor( + queue, + client, + FastTelemetryOptions(), + NullLogger.Instance))); + + /// + /// Wires the production + /// (internal ctor) onto + /// the supplied + + /// with the test's site id and source script. The returned helper's + /// Connection(...) hands back a real AuditingDbConnection. + /// + private static ScriptRuntimeContext.DatabaseHelper CreateHelper( + IDatabaseGateway gateway, + IAuditWriter writer, + string siteId) => + new( + gateway, + InstanceName, + NullLogger.Instance, + auditWriter: writer, + siteId: siteId, + sourceScript: SourceScript, + cachedForwarder: null); + + [SkippableFact] + public async Task DbWrite_Insert_Emits_OneCentralRow_WithExtraOpWrite_AndRowsAffected() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + + var siteId = NewSiteId(); + + // Central — repository + ingest actor backed by the MSSQL fixture. + await using var ingestContext = CreateContext(); + var ingestRepo = new AuditLogRepository(ingestContext); + var ingestActor = CreateIngestActor(ingestRepo); + + // Site — SQLite audit writer + ring + fallback + telemetry actor that + // drains into the stub gRPC client which forwards to the ingest actor. + await using var sqliteWriter = CreateInMemorySqliteWriter(); + var ring = new RingBufferFallback(); + var fallback = new FallbackAuditWriter( + sqliteWriter, + ring, + new NoOpAuditWriteFailureCounter(), + NullLogger.Instance); + var stubClient = new DirectActorSiteStreamAuditClient(ingestActor); + CreateTelemetryActor(sqliteWriter, stubClient); + + // SQLite-backed inner connection — the stub gateway hands it to the + // auditing wrapper as the DbConnection the script would have got. + using var keepAlive = new SqliteConnection("Data Source=k1;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out _); + var gateway = Substitute.For(); + gateway.GetConnectionAsync(ConnectionName, Arg.Any()) + .Returns(inner); + + // Act — one INSERT through the auditing wrapper. The wrapper emits a + // single DbOutbound/DbWrite event to the fallback writer; the + // telemetry actor's next tick drains it to central. + var helper = CreateHelper(gateway, fallback, siteId); + await using (var conn = await helper.Connection(ConnectionName)) + await using (var cmd = conn.CreateCommand()) + { + cmd.CommandText = "INSERT INTO t (id, name) VALUES (3, 'gamma')"; + var rows = await cmd.ExecuteNonQueryAsync(); + Assert.Equal(1, rows); + } + + // Assert — one central row, Kind=DbWrite, Status=Delivered, + // Extra.op="write", Extra.rowsAffected=1. 15s upper bound covers the + // initial 1s tick + SQLite drain + actor round-trip + EF/MSSQL latency. + await AwaitAssertAsync(async () => + { + await using var readContext = CreateContext(); + var readRepo = new AuditLogRepository(readContext); + var rows = await readRepo.QueryAsync( + new AuditLogQueryFilter(SourceSiteId: siteId), + new AuditLogPaging(PageSize: 10)); + var evt = Assert.Single(rows); + Assert.Equal(AuditChannel.DbOutbound, evt.Channel); + Assert.Equal(AuditKind.DbWrite, evt.Kind); + Assert.Equal(AuditStatus.Delivered, evt.Status); + Assert.Equal(siteId, evt.SourceSiteId); + Assert.Equal(InstanceName, evt.SourceInstanceId); + Assert.Equal(SourceScript, evt.SourceScript); + Assert.NotNull(evt.Extra); + Assert.Contains("\"op\":\"write\"", evt.Extra); + Assert.Contains("\"rowsAffected\":1", evt.Extra); + // Central stamps IngestedAtUtc; the site never sets it. + Assert.NotNull(evt.IngestedAtUtc); + Assert.StartsWith(ConnectionName, evt.Target); + }, TimeSpan.FromSeconds(15)); + } + + [SkippableFact] + public async Task DbWrite_Select_Emits_OneCentralRow_WithExtraOpRead_AndRowsReturned() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + + var siteId = NewSiteId(); + + await using var ingestContext = CreateContext(); + var ingestRepo = new AuditLogRepository(ingestContext); + var ingestActor = CreateIngestActor(ingestRepo); + + await using var sqliteWriter = CreateInMemorySqliteWriter(); + var ring = new RingBufferFallback(); + var fallback = new FallbackAuditWriter( + sqliteWriter, + ring, + new NoOpAuditWriteFailureCounter(), + NullLogger.Instance); + var stubClient = new DirectActorSiteStreamAuditClient(ingestActor); + CreateTelemetryActor(sqliteWriter, stubClient); + + using var keepAlive = new SqliteConnection("Data Source=k2;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out _); + var gateway = Substitute.For(); + gateway.GetConnectionAsync(ConnectionName, Arg.Any()) + .Returns(inner); + + var helper = CreateHelper(gateway, fallback, siteId); + await using (var conn = await helper.Connection(ConnectionName)) + await using (var cmd = conn.CreateCommand()) + { + cmd.CommandText = "SELECT id, name FROM t ORDER BY id"; + await using var reader = await cmd.ExecuteReaderAsync(); + var seen = 0; + while (await reader.ReadAsync()) + { + seen++; + } + // Explicit close so the AuditingDbDataReader callback fires before + // the helper is disposed (Bundle A defers the audit emission to + // reader-close so rowsReturned is observable). + await reader.CloseAsync(); + Assert.Equal(2, seen); + } + + await AwaitAssertAsync(async () => + { + await using var readContext = CreateContext(); + var readRepo = new AuditLogRepository(readContext); + var rows = await readRepo.QueryAsync( + new AuditLogQueryFilter(SourceSiteId: siteId), + new AuditLogPaging(PageSize: 10)); + var evt = Assert.Single(rows); + Assert.Equal(AuditChannel.DbOutbound, evt.Channel); + Assert.Equal(AuditKind.DbWrite, evt.Kind); + Assert.Equal(AuditStatus.Delivered, evt.Status); + Assert.NotNull(evt.Extra); + Assert.Contains("\"op\":\"read\"", evt.Extra); + Assert.Contains("\"rowsReturned\":2", evt.Extra); + Assert.NotNull(evt.IngestedAtUtc); + }, TimeSpan.FromSeconds(15)); + } +} diff --git a/tests/ScadaLink.AuditLog.Tests/Integration/InboundApiAuditTests.cs b/tests/ScadaLink.AuditLog.Tests/Integration/InboundApiAuditTests.cs new file mode 100644 index 0000000..a881e56 --- /dev/null +++ b/tests/ScadaLink.AuditLog.Tests/Integration/InboundApiAuditTests.cs @@ -0,0 +1,298 @@ +using Microsoft.AspNetCore.Authentication; +using Microsoft.AspNetCore.Builder; +using Microsoft.AspNetCore.Hosting; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.TestHost; +using Microsoft.EntityFrameworkCore; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging.Abstractions; +using ScadaLink.AuditLog.Central; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Audit; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.ConfigurationDatabase; +using ScadaLink.ConfigurationDatabase.Repositories; +using ScadaLink.ConfigurationDatabase.Tests.Migrations; +using ScadaLink.InboundAPI.Middleware; +using System.Security.Claims; +using System.Text; +using System.Text.Encodings.Web; + +namespace ScadaLink.AuditLog.Tests.Integration; + +/// +/// Audit Log #23 — M4 Bundle E (Task E3) end-to-end audit trail for the +/// inbound API surface. Wires the production +/// into a Microsoft.AspNetCore.TestHost +/// pipeline that mirrors the production +/// UseAuthentication → UseAuditWriteMiddleware → POST /api/{methodName} +/// order, with the real backed by the per-class +/// MSSQL AuditLog table. +/// +/// +/// +/// Three response shapes are covered: a happy-path 200 (with the actor +/// resolved from ), a 401 unauthenticated +/// (Actor stays null, kind flips to +/// ), and a 500 internal-error +/// response. Each test uses a unique method name so concurrent tests sharing +/// the fixture don't interfere. +/// +/// +/// The middleware-level unit tests already cover the recording-writer shape +/// (AuditWriteMiddlewareTests) and the pipeline ordering +/// (MiddlewareOrderTests); these tests verify the END-TO-END +/// materialisation in the central AuditLog table — the production +/// glue from request → writer → repository → MSSQL row. +/// +/// +public class InboundApiAuditTests : IClassFixture +{ + private readonly MsSqlMigrationFixture _fixture; + + public InboundApiAuditTests(MsSqlMigrationFixture fixture) + { + _fixture = fixture; + } + + /// + /// Per-test unique method name suffix — the audit row's Target + /// captures it so each test can query by + /// without disturbing other tests using the same MSSQL fixture. + /// + private static string NewMethodName(string prefix) => + prefix + "-" + Guid.NewGuid().ToString("N").Substring(0, 8); + + private ScadaLinkDbContext CreateContext() + { + var options = new DbContextOptionsBuilder() + .UseSqlServer(_fixture.ConnectionString) + .ConfigureWarnings(w => w.Ignore( + Microsoft.EntityFrameworkCore.Diagnostics.RelationalEventId.PendingModelChangesWarning)) + .Options; + return new ScadaLinkDbContext(options); + } + + /// + /// Spins up a minimal in-memory ASP.NET host whose pipeline mirrors the + /// production arrangement. The endpoint handler delegate is supplied by + /// each test so it can shape the response (200 with an actor, 401 + /// auth-fail, 500 server error) the way the production handler would. + /// + private async Task BuildHostAsync(RequestDelegate endpointHandler) + { + var hostBuilder = new HostBuilder() + .ConfigureWebHost(webBuilder => + { + webBuilder + .UseTestServer() + .ConfigureServices(services => + { + // Real EF DbContext + AuditLogRepository wired against + // the per-class MSSQL fixture. CentralAuditWriter is a + // singleton — same pattern the production Host uses — + // opening a fresh scope per call to resolve the scoped + // repository. + services.AddDbContext(opts => + opts.UseSqlServer(_fixture.ConnectionString) + .ConfigureWarnings(w => w.Ignore( + Microsoft.EntityFrameworkCore.Diagnostics.RelationalEventId.PendingModelChangesWarning))); + services.AddScoped(sp => + new AuditLogRepository(sp.GetRequiredService())); + services.AddSingleton(sp => + new CentralAuditWriter(sp, NullLogger.Instance)); + + services.AddRouting(); + services.AddAuthorization(); + services.AddAuthentication("TestScheme") + .AddScheme( + "TestScheme", _ => { }); + }) + .Configure(app => + { + // Mirror production order: routing → auth → audit + // middleware → endpoint. The auth scheme always + // succeeds; per-request auth-failure semantics are + // produced INSIDE the endpoint handler (mirroring + // ApiKeyValidator's in-handler short-circuit). + app.UseRouting(); + app.UseAuthentication(); + app.UseAuthorization(); + app.UseAuditWriteMiddleware(); + app.UseEndpoints(endpoints => + { + endpoints.MapPost("/api/{methodName}", endpointHandler); + }); + }); + }); + + return await hostBuilder.StartAsync(); + } + + /// + /// Minimal authentication handler that always succeeds — keeps + /// populated so the middleware's + /// Items-then-User fallback path has a real principal to ignore. The + /// middleware's primary actor resolution path uses + /// so this handler's + /// claim never appears on the emitted Actor unless the endpoint stashes + /// it explicitly. + /// + private sealed class AlwaysAuthenticatedHandler : AuthenticationHandler + { + public AlwaysAuthenticatedHandler( + Microsoft.Extensions.Options.IOptionsMonitor options, + Microsoft.Extensions.Logging.ILoggerFactory logger, + UrlEncoder encoder) + : base(options, logger, encoder) { } + + protected override Task HandleAuthenticateAsync() + { + var identity = new ClaimsIdentity( + new[] { new Claim(ClaimTypes.Name, "framework-user") }, "TestScheme"); + var principal = new ClaimsPrincipal(identity); + var ticket = new AuthenticationTicket(principal, "TestScheme"); + return Task.FromResult(AuthenticateResult.Success(ticket)); + } + } + + /// + /// Queries the central AuditLog table for the row produced by the + /// test's unique method name. Wrapped in calls so the + /// query can be used inside a polling helper. + /// + private async Task> QueryByTargetAsync(string methodName) + { + await using var ctx = CreateContext(); + var repo = new AuditLogRepository(ctx); + return await repo.QueryAsync( + new AuditLogQueryFilter(Target: methodName), + new AuditLogPaging(PageSize: 10)); + } + + /// + /// Awaits the central AuditLog row materialising for + /// . The writer is fire-and-forget so we + /// poll briefly after the HTTP response returns to absorb scheduling + /// jitter between the middleware's finally block and the row hitting + /// MSSQL. + /// + private async Task AwaitOneAsync(string methodName) + { + var deadline = DateTime.UtcNow + TimeSpan.FromSeconds(10); + while (DateTime.UtcNow < deadline) + { + var rows = await QueryByTargetAsync(methodName); + if (rows.Count > 0) + { + return Assert.Single(rows); + } + await Task.Delay(100); + } + + // Fall through to a final query so the failure message carries the + // actual row count from the last attempt. + var finalRows = await QueryByTargetAsync(methodName); + return Assert.Single(finalRows); + } + + [SkippableFact] + public async Task PostToApi_WithValidActor_Emits_InboundRequest_StatusDelivered_HttpStatus200_ActorPopulated() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + var methodName = NewMethodName("echo"); + + using var host = await BuildHostAsync(async ctx => + { + // Simulate the production endpoint stashing the resolved API key + // name on HttpContext.Items AFTER successful auth — the middleware + // reads it in its finally block to populate Actor. + ctx.Items[AuditWriteMiddleware.AuditActorItemKey] = "integration-svc"; + ctx.Response.StatusCode = 200; + await ctx.Response.WriteAsync("ok"); + }); + + var client = host.GetTestClient(); + var resp = await client.PostAsync( + $"/api/{methodName}", + new StringContent("{\"x\":1}", Encoding.UTF8, "application/json")); + Assert.Equal(System.Net.HttpStatusCode.OK, resp.StatusCode); + + var evt = await AwaitOneAsync(methodName); + Assert.Equal(AuditChannel.ApiInbound, evt.Channel); + Assert.Equal(AuditKind.InboundRequest, evt.Kind); + Assert.Equal(AuditStatus.Delivered, evt.Status); + Assert.Equal(200, evt.HttpStatus); + Assert.Equal("integration-svc", evt.Actor); + // Central direct-write — no site-local forward state (alog.md §6). + Assert.Null(evt.ForwardState); + // IngestedAtUtc stamped by the central writer. + Assert.NotNull(evt.IngestedAtUtc); + } + + [SkippableFact] + public async Task PostToApi_Without_Auth_Emits_InboundAuthFailure_StatusFailed_HttpStatus401_ActorNull() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + var methodName = NewMethodName("auth-fail"); + + using var host = await BuildHostAsync(async ctx => + { + // The production ApiKeyValidator returns 401 from inside the + // handler when the X-API-Key header is missing or invalid; the + // handler must NOT stash an actor name in that case so the + // middleware emits Actor=null on the resulting audit row. + ctx.Response.StatusCode = 401; + await ctx.Response.WriteAsync("unauthorized"); + }); + + var client = host.GetTestClient(); + var resp = await client.PostAsync( + $"/api/{methodName}", + new StringContent("{}", Encoding.UTF8, "application/json")); + Assert.Equal(System.Net.HttpStatusCode.Unauthorized, resp.StatusCode); + + var evt = await AwaitOneAsync(methodName); + Assert.Equal(AuditChannel.ApiInbound, evt.Channel); + Assert.Equal(AuditKind.InboundAuthFailure, evt.Kind); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.Equal(401, evt.HttpStatus); + // Never echo back an unauthenticated principal — middleware suppresses + // the framework user resolution on 401/403 paths. + Assert.Null(evt.Actor); + } + + [SkippableFact] + public async Task PostToApi_Returning500_Emits_InboundRequest_StatusFailed_HttpStatus500() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + var methodName = NewMethodName("server-error"); + + using var host = await BuildHostAsync(async ctx => + { + // A handler-returned 500 (not a throw) — auth succeeded so Actor + // resolution is still allowed; the audit row's Kind stays + // InboundRequest (not InboundAuthFailure) and Status flips to + // Failed because the response is not a 2xx. + ctx.Items[AuditWriteMiddleware.AuditActorItemKey] = "integration-svc"; + ctx.Response.StatusCode = 500; + await ctx.Response.WriteAsync("kaboom"); + }); + + var client = host.GetTestClient(); + var resp = await client.PostAsync( + $"/api/{methodName}", + new StringContent("{}", Encoding.UTF8, "application/json")); + Assert.Equal(System.Net.HttpStatusCode.InternalServerError, resp.StatusCode); + + var evt = await AwaitOneAsync(methodName); + Assert.Equal(AuditChannel.ApiInbound, evt.Channel); + Assert.Equal(AuditKind.InboundRequest, evt.Kind); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.Equal(500, evt.HttpStatus); + Assert.Equal("integration-svc", evt.Actor); + } +} diff --git a/tests/ScadaLink.AuditLog.Tests/Integration/NotifyDispatcherAuditTrailTests.cs b/tests/ScadaLink.AuditLog.Tests/Integration/NotifyDispatcherAuditTrailTests.cs new file mode 100644 index 0000000..cfc5bcf --- /dev/null +++ b/tests/ScadaLink.AuditLog.Tests/Integration/NotifyDispatcherAuditTrailTests.cs @@ -0,0 +1,349 @@ +using Akka.Actor; +using Akka.TestKit.Xunit2; +using Microsoft.EntityFrameworkCore; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Abstractions; +using ScadaLink.AuditLog.Central; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Entities.Notifications; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Audit; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.ConfigurationDatabase; +using ScadaLink.ConfigurationDatabase.Repositories; +using ScadaLink.ConfigurationDatabase.Tests.Migrations; +using ScadaLink.NotificationOutbox; +using ScadaLink.NotificationOutbox.Delivery; +using ScadaLink.NotificationOutbox.Messages; + +namespace ScadaLink.AuditLog.Tests.Integration; + +/// +/// Audit Log #23 — M4 Bundle E (Task E2): end-to-end audit trail produced by +/// the central dispatcher loop. Wires +/// the production onto the real +/// against the per-class +/// MSSQL database, drives the dispatcher +/// with a stub that yields a +/// transient-then-success sequence, and asserts the resulting +/// / +/// rows materialise with the expected Attempted/Delivered shape. +/// +/// +/// +/// The Submit row is normally produced by the site-side Notify.Send +/// wrapper (Bundle C); for this E2E we pre-insert a single AuditLog Submit row +/// via alongside the seeded +/// row so the assertions can confirm the dispatcher +/// emissions slot in alongside it. This keeps the test focused on the +/// dispatcher's emission shape without depending on the upstream site path. +/// +/// +/// Each test uses a unique notification id + source-site id so concurrent +/// tests sharing the MSSQL fixture don't interfere. The dispatcher is driven +/// deterministically via the internal +/// InternalMessages.DispatchTick.Instance sentinel (same pattern the +/// existing NotificationOutbox.Tests use). +/// +/// +public class NotifyDispatcherAuditTrailTests : TestKit, IClassFixture +{ + private readonly MsSqlMigrationFixture _fixture; + + public NotifyDispatcherAuditTrailTests(MsSqlMigrationFixture fixture) + { + _fixture = fixture; + } + + private static string NewSiteId() => + "test-e2-notify-" + Guid.NewGuid().ToString("N").Substring(0, 8); + + private ScadaLinkDbContext CreateContext() + { + var options = new DbContextOptionsBuilder() + .UseSqlServer(_fixture.ConnectionString) + .ConfigureWarnings(w => w.Ignore( + Microsoft.EntityFrameworkCore.Diagnostics.RelationalEventId.PendingModelChangesWarning)) + .Options; + return new ScadaLinkDbContext(options); + } + + /// + /// Builds a DI provider that mirrors the production wiring expected by + /// : scoped EF-backed + /// + + /// + the supplied . The + /// registration powers the + /// the actor will emit through. + /// + private IServiceProvider BuildServiceProvider(INotificationDeliveryAdapter adapter) + { + var services = new ServiceCollection(); + services.AddDbContext(opts => + opts.UseSqlServer(_fixture.ConnectionString) + .ConfigureWarnings(w => w.Ignore( + Microsoft.EntityFrameworkCore.Diagnostics.RelationalEventId.PendingModelChangesWarning))); + services.AddScoped(sp => + new NotificationOutboxRepository(sp.GetRequiredService())); + services.AddScoped(sp => + new NotificationRepository(sp.GetRequiredService())); + services.AddScoped(sp => + new AuditLogRepository(sp.GetRequiredService())); + services.AddScoped(_ => adapter); + return services.BuildServiceProvider(); + } + + /// + /// Stub adapter that yields the next outcome from a configurable queue per + /// call. Lets a single dispatch sweep exercise the transient-then-success + /// transition by alternating + /// and . + /// + private sealed class QueuedOutcomeAdapter : INotificationDeliveryAdapter + { + private readonly Queue _outcomes; + public int CallCount; + + public QueuedOutcomeAdapter(params DeliveryOutcome[] outcomes) + { + _outcomes = new Queue(outcomes); + } + + public NotificationType Type => NotificationType.Email; + + public Task DeliverAsync( + Notification notification, CancellationToken cancellationToken = default) + { + Interlocked.Increment(ref CallCount); + // Defensive — if a test under-supplies outcomes we surface the + // problem as an explicit transient failure rather than throwing + // (the dispatcher would log + skip the notification but the audit + // assertions would be misleading). + var outcome = _outcomes.Count > 0 + ? _outcomes.Dequeue() + : DeliveryOutcome.Transient("test stub out of outcomes"); + return Task.FromResult(outcome); + } + } + + /// + /// Inserts a single SMTP configuration row so the dispatcher's + /// ResolveRetryPolicyAsync sees a real (maxRetries, retryDelay) + /// pair rather than the conservative fallback. RetryDelay of 0 means a + /// transient outcome's NextAttemptAt is immediately due — useful so + /// the SECOND DispatchTick re-claims the row without waiting. + /// + private async Task SeedSmtpConfigAsync(int maxRetries = 5) + { + await using var ctx = CreateContext(); + ctx.SmtpConfigurations.Add(new SmtpConfiguration( + "smtp.example.com", "Basic", "noreply@example.com") + { + MaxRetries = maxRetries, + RetryDelay = TimeSpan.Zero, + }); + await ctx.SaveChangesAsync(); + } + + /// + /// Seeds the Pending outbox row the dispatcher will claim. Using a fixed + /// caller-supplied notificationId so the test can later query the + /// AuditLog by = notificationId. + /// + private async Task SeedNotificationAsync( + Guid notificationId, string siteId, string listName = "ops-team") + { + await using var ctx = CreateContext(); + var n = new Notification( + notificationId.ToString("D"), + NotificationType.Email, + listName, + "Tank overflow", + "Tank 3 level critical", + siteId) + { + SourceInstanceId = "Plant.Pump42", + SourceScript = "AlarmScript", + CreatedAt = DateTimeOffset.UtcNow.AddMinutes(-1), + }; + ctx.Notifications.Add(n); + await ctx.SaveChangesAsync(); + return n; + } + + /// + /// Pre-inserts the Submit AuditLog row that the site-side Notify.Send + /// wrapper would have emitted (Bundle C). Keeps the assertions on the + /// dispatcher emissions intact without depending on the upstream site + /// path. + /// + private async Task SeedSubmitAuditRowAsync(Guid notificationId, string siteId) + { + await using var ctx = CreateContext(); + var repo = new AuditLogRepository(ctx); + var submitEvt = new AuditEvent + { + EventId = Guid.NewGuid(), + OccurredAtUtc = DateTime.UtcNow.AddMinutes(-1), + Channel = AuditChannel.Notification, + Kind = AuditKind.NotifySend, + CorrelationId = notificationId, + SourceSiteId = siteId, + SourceInstanceId = "Plant.Pump42", + SourceScript = "AlarmScript", + Target = "ops-team", + Status = AuditStatus.Submitted, + ForwardState = AuditForwardState.Forwarded, + IngestedAtUtc = DateTime.UtcNow.AddMinutes(-1), + }; + await repo.InsertIfNotExistsAsync(submitEvt); + } + + private static NotificationOutboxOptions LongDispatchOptions() => + // 1h dispatch + 24h purge so PreStart's timers never fire during the + // test; the test drives the dispatcher with explicit DispatchTick. + new() + { + DispatchInterval = TimeSpan.FromHours(1), + PurgeInterval = TimeSpan.FromDays(1), + }; + + [SkippableFact] + public async Task NotifyDispatcher_FailThenSuccess_Emits_TwoAttempts_OneDelivered_Terminal() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + + var siteId = NewSiteId(); + var notificationId = Guid.NewGuid(); + await SeedSmtpConfigAsync(maxRetries: 5); + await SeedNotificationAsync(notificationId, siteId); + await SeedSubmitAuditRowAsync(notificationId, siteId); + + var adapter = new QueuedOutcomeAdapter( + DeliveryOutcome.Transient("smtp 421 try again"), + DeliveryOutcome.Success("ops@example.com")); + var serviceProvider = BuildServiceProvider(adapter); + var auditWriter = new CentralAuditWriter( + serviceProvider, + NullLogger.Instance); + + var actor = Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( + serviceProvider, + LongDispatchOptions(), + (ICentralAuditWriter)auditWriter, + NullLogger.Instance))); + + // First tick: transient failure → one Attempted row, no terminal row. + actor.Tell(InternalMessages.DispatchTick.Instance); + await AwaitAssertAsync(async () => + { + await using var ctx = CreateContext(); + var repo = new AuditLogRepository(ctx); + var rows = await repo.QueryAsync( + new AuditLogQueryFilter(SourceSiteId: siteId), + new AuditLogPaging(PageSize: 50)); + // 1 Submit + 1 Attempted = 2 rows so far. + Assert.Equal(2, rows.Count); + Assert.Single(rows, r => r.Kind == AuditKind.NotifyDeliver + && r.Status == AuditStatus.Attempted); + Assert.Single(rows, r => r.Kind == AuditKind.NotifySend); + }, TimeSpan.FromSeconds(15)); + + // Second tick: success → second Attempted + one Delivered terminal. + actor.Tell(InternalMessages.DispatchTick.Instance); + await AwaitAssertAsync(async () => + { + await using var ctx = CreateContext(); + var repo = new AuditLogRepository(ctx); + var rows = await repo.QueryAsync( + new AuditLogQueryFilter(SourceSiteId: siteId), + new AuditLogPaging(PageSize: 50)); + // 1 Submit + 2 Attempted + 1 Delivered terminal = 4 rows. + Assert.InRange(rows.Count, 3, 4); + var notifyDeliverRows = rows + .Where(r => r.Kind == AuditKind.NotifyDeliver) + .ToList(); + Assert.Equal(2, notifyDeliverRows.Count(r => r.Status == AuditStatus.Attempted)); + var terminal = Assert.Single(notifyDeliverRows, r => r.Status == AuditStatus.Delivered); + // All NotifyDeliver rows correlate to the original notification id. + Assert.All(notifyDeliverRows, r => Assert.Equal(notificationId, r.CorrelationId)); + Assert.Equal("ops-team", terminal.Target); + }, TimeSpan.FromSeconds(15)); + + // Operational Notifications table mirrors the audit outcome. + await AwaitAssertAsync(async () => + { + await using var ctx = CreateContext(); + var n = await ctx.Notifications.SingleAsync( + row => row.NotificationId == notificationId.ToString("D")); + Assert.Equal(NotificationStatus.Delivered, n.Status); + Assert.NotNull(n.DeliveredAt); + }, TimeSpan.FromSeconds(15)); + } + + [SkippableFact] + public async Task NotifyDispatcher_AuditWriter_Throws_DeliveryStillSucceeds() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + + var siteId = NewSiteId(); + var notificationId = Guid.NewGuid(); + await SeedSmtpConfigAsync(maxRetries: 5); + await SeedNotificationAsync(notificationId, siteId); + + var adapter = new QueuedOutcomeAdapter( + DeliveryOutcome.Success("ops@example.com")); + var serviceProvider = BuildServiceProvider(adapter); + + // ALWAYS-throw writer wired in place of the production + // CentralAuditWriter. The dispatcher MUST still deliver the + // notification and persist the terminal Delivered transition + // regardless of the audit subsystem being down (alog.md §13). + var throwingWriter = new ThrowingCentralAuditWriter(); + + var actor = Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( + serviceProvider, + LongDispatchOptions(), + (ICentralAuditWriter)throwingWriter, + NullLogger.Instance))); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + // The Notifications table is the operational source of truth — assert + // it transitions to Delivered even though every audit write threw. + await AwaitAssertAsync(async () => + { + await using var ctx = CreateContext(); + var n = await ctx.Notifications.SingleAsync( + row => row.NotificationId == notificationId.ToString("D")); + Assert.Equal(NotificationStatus.Delivered, n.Status); + Assert.NotNull(n.DeliveredAt); + }, TimeSpan.FromSeconds(15)); + + // The writer was attempted (at least once for the Attempted row, plus + // once for the Delivered terminal) — proves the dispatcher tried to + // emit and absorbed the throws rather than aborting the action. + Assert.True(throwingWriter.AttemptCount >= 2, + $"Expected the dispatcher to attempt audit writes; saw {throwingWriter.AttemptCount}"); + } + + /// + /// Test-only that ALWAYS throws on + /// . Used to verify the dispatcher's defensive + /// try/catch contract (alog.md §13) — audit failures must NEVER abort + /// the user-facing notification delivery. + /// + private sealed class ThrowingCentralAuditWriter : ICentralAuditWriter + { + private int _attemptCount; + public int AttemptCount => Volatile.Read(ref _attemptCount); + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + Interlocked.Increment(ref _attemptCount); + throw new InvalidOperationException( + "test-only ThrowingCentralAuditWriter — audit subsystem unavailable"); + } + } +} diff --git a/tests/ScadaLink.AuditLog.Tests/ScadaLink.AuditLog.Tests.csproj b/tests/ScadaLink.AuditLog.Tests/ScadaLink.AuditLog.Tests.csproj index bd99f49..b85f00a 100644 --- a/tests/ScadaLink.AuditLog.Tests/ScadaLink.AuditLog.Tests.csproj +++ b/tests/ScadaLink.AuditLog.Tests/ScadaLink.AuditLog.Tests.csproj @@ -20,9 +20,13 @@ - - - + @@ -55,6 +59,26 @@ needs a project reference to SiteRuntime where the store lives. --> + + + + + + + + + + diff --git a/tests/ScadaLink.InboundAPI.Tests/Middleware/AuditWriteMiddlewareTests.cs b/tests/ScadaLink.InboundAPI.Tests/Middleware/AuditWriteMiddlewareTests.cs new file mode 100644 index 0000000..fab1521 --- /dev/null +++ b/tests/ScadaLink.InboundAPI.Tests/Middleware/AuditWriteMiddlewareTests.cs @@ -0,0 +1,373 @@ +using System.Net; +using System.Text; +using System.Text.Json; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.Routing; +using Microsoft.Extensions.Logging.Abstractions; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.InboundAPI.Middleware; + +namespace ScadaLink.InboundAPI.Tests.Middleware; + +/// +/// M4 Bundle D (D1) — verifies emits exactly one +/// row per request via +/// covering all outcome shapes: +/// success (InboundRequest/Delivered), client/server error (InboundRequest/Failed), +/// and unauthenticated (InboundAuthFailure/Failed). Audit-write failures must NEVER +/// alter the HTTP response (alog.md §13). +/// +public class AuditWriteMiddlewareTests +{ + /// + /// Test-only recording . Captures every + /// the middleware emits so each test can assert on + /// the shape of the row produced for one request. + /// + private sealed class RecordingAuditWriter : ICentralAuditWriter + { + public List Events { get; } = new(); + public Func? OnWrite { get; set; } + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + lock (Events) + { + Events.Add(evt); + } + + return OnWrite?.Invoke(evt) ?? Task.CompletedTask; + } + } + + /// + /// Builds an primed for the inbound API route shape: + /// POST /api/{methodName}, optional JSON body, RemoteIpAddress + User-Agent. + /// The route value resolver mirrors the production endpoint mapping so the + /// middleware can pull the method name without owning routing itself. + /// + private static DefaultHttpContext BuildContext( + string methodName = "echo", + string? body = null, + string? userAgent = "test-agent/1.0", + IPAddress? remoteIp = null) + { + var ctx = new DefaultHttpContext(); + ctx.Request.Method = "POST"; + ctx.Request.Path = $"/api/{methodName}"; + ctx.Request.RouteValues["methodName"] = methodName; + + if (body is not null) + { + var bytes = Encoding.UTF8.GetBytes(body); + ctx.Request.Body = new MemoryStream(bytes); + ctx.Request.ContentLength = bytes.Length; + ctx.Request.ContentType = "application/json"; + } + + if (userAgent is not null) + { + ctx.Request.Headers["User-Agent"] = userAgent; + } + + ctx.Connection.RemoteIpAddress = remoteIp ?? IPAddress.Parse("10.0.0.5"); + + return ctx; + } + + private static AuditWriteMiddleware CreateMiddleware( + RequestDelegate next, + ICentralAuditWriter writer) => + new(next, writer, NullLogger.Instance); + + // --------------------------------------------------------------------- + // 1. Happy path — InboundRequest/Delivered/HttpStatus 200 + // --------------------------------------------------------------------- + + [Fact] + public async Task Pipeline_Success_EmitsOneEvent_KindInboundRequest_StatusDelivered_HttpStatus200() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext(); + var mw = CreateMiddleware(_ => + { + ctx.Response.StatusCode = 200; + return Task.CompletedTask; + }, writer); + + await mw.InvokeAsync(ctx); + + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditChannel.ApiInbound, evt.Channel); + Assert.Equal(AuditKind.InboundRequest, evt.Kind); + Assert.Equal(AuditStatus.Delivered, evt.Status); + Assert.Equal(200, evt.HttpStatus); + // Central direct-write — no ForwardState (alog.md §6). + Assert.Null(evt.ForwardState); + Assert.NotEqual(Guid.Empty, evt.EventId); + Assert.Equal("echo", evt.Target); + } + + // --------------------------------------------------------------------- + // 2. 400 — script/validation failure path + // --------------------------------------------------------------------- + + [Fact] + public async Task Pipeline_400_EmitsEvent_Status_Failed_HttpStatus400() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext(); + var mw = CreateMiddleware(_ => + { + ctx.Response.StatusCode = 400; + return Task.CompletedTask; + }, writer); + + await mw.InvokeAsync(ctx); + + var evt = Assert.Single(writer.Events); + // A 400 is a request the auth succeeded for — still InboundRequest, not + // InboundAuthFailure. Only 401/403 maps to the auth-failure kind. + Assert.Equal(AuditKind.InboundRequest, evt.Kind); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.Equal(400, evt.HttpStatus); + } + + // --------------------------------------------------------------------- + // 3. 401 — auth failure path + // --------------------------------------------------------------------- + + [Fact] + public async Task Pipeline_401_EmitsEvent_KindInboundAuthFailure_StatusFailed() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext(); + var mw = CreateMiddleware(_ => + { + ctx.Response.StatusCode = 401; + return Task.CompletedTask; + }, writer); + + await mw.InvokeAsync(ctx); + + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditKind.InboundAuthFailure, evt.Kind); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.Equal(401, evt.HttpStatus); + // The candidate API key never resolved to a name, so Actor stays null — + // never echo back an unauthenticated principal. + Assert.Null(evt.Actor); + } + + [Fact] + public async Task Pipeline_403_EmitsEvent_KindInboundAuthFailure_StatusFailed() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext(); + var mw = CreateMiddleware(_ => + { + ctx.Response.StatusCode = 403; + return Task.CompletedTask; + }, writer); + + await mw.InvokeAsync(ctx); + + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditKind.InboundAuthFailure, evt.Kind); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.Equal(403, evt.HttpStatus); + } + + // --------------------------------------------------------------------- + // 4. 500 — handler threw OR returned 500 + // --------------------------------------------------------------------- + + [Fact] + public async Task Pipeline_500_EmitsEvent_Status_Failed() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext(); + var mw = CreateMiddleware(_ => + { + ctx.Response.StatusCode = 500; + return Task.CompletedTask; + }, writer); + + await mw.InvokeAsync(ctx); + + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditKind.InboundRequest, evt.Kind); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.Equal(500, evt.HttpStatus); + } + + [Fact] + public async Task Pipeline_Throws_EmitsEvent_Status_Failed_And_Rethrows() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext(); + var boom = new InvalidOperationException("kaboom"); + var mw = CreateMiddleware(_ => throw boom, writer); + + // The middleware MUST re-throw so the request's own error path is + // authoritative — audit emission is best-effort only. + var thrown = await Assert.ThrowsAsync( + () => mw.InvokeAsync(ctx)); + Assert.Same(boom, thrown); + + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.Equal("kaboom", evt.ErrorMessage); + } + + // --------------------------------------------------------------------- + // 5. Actor resolution — the endpoint handler stashes the API key name + // AFTER successful auth so the middleware can pick it up from + // HttpContext.Items. + // --------------------------------------------------------------------- + + [Fact] + public async Task ApiKeyName_Resolved_From_HttpContext_AsActor() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext(); + var mw = CreateMiddleware(_ => + { + // The endpoint handler is expected to stash the resolved API key + // name here once ApiKeyValidator.ValidateAsync has succeeded. + ctx.Items[AuditWriteMiddleware.AuditActorItemKey] = "integration-svc"; + ctx.Response.StatusCode = 200; + return Task.CompletedTask; + }, writer); + + await mw.InvokeAsync(ctx); + + var evt = Assert.Single(writer.Events); + Assert.Equal("integration-svc", evt.Actor); + } + + // --------------------------------------------------------------------- + // 6. Writer failure must NEVER alter the HTTP response + // --------------------------------------------------------------------- + + [Fact] + public async Task AuditWriter_Throws_HttpResponse_Unchanged_Success_Stays_Success() + { + var writer = new RecordingAuditWriter + { + OnWrite = _ => throw new InvalidOperationException("writer offline"), + }; + var ctx = BuildContext(); + var mw = CreateMiddleware(_ => + { + ctx.Response.StatusCode = 200; + return Task.CompletedTask; + }, writer); + + // Audit emission is best-effort; even a thrown writer must NOT bubble + // up and contaminate the user-facing response status. + await mw.InvokeAsync(ctx); + + Assert.Equal(200, ctx.Response.StatusCode); + } + + [Fact] + public async Task AuditWriter_Throws_OnFailedRequest_HttpResponse_Unchanged() + { + var writer = new RecordingAuditWriter + { + OnWrite = _ => throw new InvalidOperationException("writer offline"), + }; + var ctx = BuildContext(); + var mw = CreateMiddleware(_ => + { + ctx.Response.StatusCode = 500; + return Task.CompletedTask; + }, writer); + + await mw.InvokeAsync(ctx); + + Assert.Equal(500, ctx.Response.StatusCode); + } + + // --------------------------------------------------------------------- + // 7. Provenance — RemoteIp + User-Agent surface in Extra JSON + // --------------------------------------------------------------------- + + [Fact] + public async Task RemoteIp_And_UserAgent_AppearInExtra() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext( + userAgent: "curl/8.4.0", + remoteIp: IPAddress.Parse("192.168.50.50")); + var mw = CreateMiddleware(_ => + { + ctx.Response.StatusCode = 200; + return Task.CompletedTask; + }, writer); + + await mw.InvokeAsync(ctx); + + var evt = Assert.Single(writer.Events); + Assert.NotNull(evt.Extra); + using var doc = JsonDocument.Parse(evt.Extra!); + var root = doc.RootElement; + Assert.Equal("192.168.50.50", root.GetProperty("remoteIp").GetString()); + Assert.Equal("curl/8.4.0", root.GetProperty("userAgent").GetString()); + } + + // --------------------------------------------------------------------- + // Body capture — the small JSON body is buffered and stashed on + // RequestSummary so subsequent reads (the endpoint handler's + // JsonDocument.Parse) still see the full payload. + // --------------------------------------------------------------------- + + [Fact] + public async Task RequestBody_IsBuffered_AndStashed_OnRequestSummary() + { + var writer = new RecordingAuditWriter(); + var requestJson = "{\"x\":1}"; + var ctx = BuildContext(body: requestJson); + + string? observedAfterMiddleware = null; + var mw = CreateMiddleware(async hc => + { + // Downstream code must still be able to read the body — the + // middleware enables buffering and rewinds so the handler sees the + // unconsumed stream. + using var reader = new StreamReader(hc.Request.Body); + observedAfterMiddleware = await reader.ReadToEndAsync(); + hc.Response.StatusCode = 200; + }, writer); + + await mw.InvokeAsync(ctx); + + Assert.Equal(requestJson, observedAfterMiddleware); + var evt = Assert.Single(writer.Events); + Assert.Equal(requestJson, evt.RequestSummary); + } + + [Fact] + public async Task DurationMs_IsRecorded() + { + var writer = new RecordingAuditWriter(); + var ctx = BuildContext(); + var mw = CreateMiddleware(async _ => + { + // The middleware records elapsed milliseconds — a small delay + // ensures DurationMs is non-negative and roughly tracks reality + // without being flake-sensitive in CI. + await Task.Delay(5); + ctx.Response.StatusCode = 200; + }, writer); + + await mw.InvokeAsync(ctx); + + var evt = Assert.Single(writer.Events); + Assert.NotNull(evt.DurationMs); + Assert.True(evt.DurationMs >= 0); + } +} diff --git a/tests/ScadaLink.InboundAPI.Tests/Middleware/MiddlewareOrderTests.cs b/tests/ScadaLink.InboundAPI.Tests/Middleware/MiddlewareOrderTests.cs new file mode 100644 index 0000000..b74356f --- /dev/null +++ b/tests/ScadaLink.InboundAPI.Tests/Middleware/MiddlewareOrderTests.cs @@ -0,0 +1,236 @@ +using Microsoft.AspNetCore.Authentication; +using Microsoft.AspNetCore.Builder; +using Microsoft.AspNetCore.Hosting; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.TestHost; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging.Abstractions; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.InboundAPI.Middleware; +using System.Security.Claims; + +namespace ScadaLink.InboundAPI.Tests.Middleware; + +/// +/// M4 Bundle D (D2) — verifies the production pipeline order from +/// ScadaLink.Host.Program.cs for the inbound API: +/// UseAuthentication → UseAuthorization → UseAuditWriteMiddleware → endpoint. +/// +/// +/// The order is load-bearing: the audit middleware must run AFTER auth (so any +/// framework-resolved principal on is in place) +/// and BEFORE the inbound-API endpoint handler (so the handler's stashed actor +/// name from is observable in the +/// finally block when the handler returns). The order is also what +/// guarantees auth-failure responses (401/403 produced by a future auth scheme) +/// are seen by the middleware so it can emit +/// . +/// +/// +public class MiddlewareOrderTests +{ + /// + /// Captures the order of pipeline stages by appending a token to a shared + /// list as each stage runs. The assertion compares the resulting sequence + /// directly so a regression that re-orders the pipeline fails loudly. + /// + private sealed class OrderingRecorder + { + public List Stages { get; } = new(); + public void Record(string stage) + { + lock (Stages) { Stages.Add(stage); } + } + } + + private sealed class RecordingAuditWriter : ICentralAuditWriter + { + public List Events { get; } = new(); + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + lock (Events) { Events.Add(evt); } + return Task.CompletedTask; + } + } + + [Fact] + public async Task Middleware_Pipeline_PlacesAuditWriteAfterAuth_BeforeScriptExecution() + { + var recorder = new OrderingRecorder(); + var writer = new RecordingAuditWriter(); + + using var host = await BuildHostAsync(recorder, writer); + var client = host.GetTestClient(); + + var response = await client.PostAsync("/api/echo", new StringContent("{}")); + + Assert.Equal(System.Net.HttpStatusCode.OK, response.StatusCode); + + // The recorder MUST observe these stages in exactly this order: + // 1. Authentication (UseAuthentication marker) + // 2. Authorization (UseAuthorization marker) + // 3. AuditMiddleware-Before-Next (audit middleware entered) + // 4. Endpoint handler (the route handler ran) + // 5. AuditMiddleware-After-Next (audit middleware completed) + Assert.Equal( + new[] + { + "auth", + "authz", + "audit-before", + "endpoint", + "audit-after", + }, + recorder.Stages); + + // And exactly one InboundRequest/Delivered audit row was emitted — + // proving the audit middleware actually wrapped the endpoint. + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditKind.InboundRequest, evt.Kind); + Assert.Equal(AuditStatus.Delivered, evt.Status); + Assert.Equal("test-actor", evt.Actor); + } + + [Fact] + public async Task Middleware_Pipeline_Records_AuthFailure_Beyond_Endpoint() + { + // A 401 short-circuit happens *inside the endpoint handler* in the real + // InboundAPI (the X-API-Key validator runs there), so the audit + // middleware still wraps it and observes the 401 response status. This + // confirms ordering supports the InboundAuthFailure emission path. + var recorder = new OrderingRecorder(); + var writer = new RecordingAuditWriter(); + + using var host = await BuildHostAsync(recorder, writer, endpointStatus: 401); + var client = host.GetTestClient(); + + var response = await client.PostAsync("/api/echo", new StringContent("{}")); + + Assert.Equal(System.Net.HttpStatusCode.Unauthorized, response.StatusCode); + + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditKind.InboundAuthFailure, evt.Kind); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.Equal(401, evt.HttpStatus); + } + + /// + /// Builds a minimal in-memory host whose pipeline mirrors the production + /// arrangement in ScadaLink.Host.Program.cs: + /// UseRouting → UseAuthentication → UseAuthorization → UseAuditWriteMiddleware → endpoints. + /// Marker middlewares record their entry into so + /// the test can assert on the resulting ordering. + /// + private static async Task BuildHostAsync( + OrderingRecorder recorder, + ICentralAuditWriter writer, + int endpointStatus = 200) + { + var hostBuilder = new HostBuilder() + .ConfigureWebHost(webBuilder => + { + webBuilder + .UseTestServer() + .ConfigureServices(services => + { + services.AddSingleton(writer); + services.AddSingleton(sp => + new AuditWriteMiddleware( + // The middleware factory pattern is bypassed + // here so the inner delegate is closed over the + // recorder — UseMiddleware below still + // instantiates the type correctly. + _ => Task.CompletedTask, + writer, + NullLogger.Instance)); + services.AddRouting(); + services.AddAuthorization(); + services.AddAuthentication("TestScheme") + .AddScheme( + "TestScheme", _ => { }); + }) + .Configure(app => + { + app.UseRouting(); + app.Use(async (ctx, next) => + { + recorder.Record("auth"); + await next(); + }); + app.UseAuthentication(); + app.Use(async (ctx, next) => + { + recorder.Record("authz"); + await next(); + }); + app.UseAuthorization(); + + // The order-under-test: AuditWriteMiddleware sits + // AFTER auth/authz markers and BEFORE the endpoint + // marker. We wrap with a sentinel marker that fires + // *before* the audit middleware enters so the test can + // pin where the audit middleware lands in the chain. + app.Use(async (ctx, next) => + { + recorder.Record("audit-before"); + await next(); + recorder.Record("audit-after"); + }); + app.UseAuditWriteMiddleware(); + + app.UseEndpoints(endpoints => + { + endpoints.MapPost("/api/{methodName}", async ctx => + { + recorder.Record("endpoint"); + + if (endpointStatus is 401 or 403) + { + // Simulate an auth-failure short-circuit + // produced by the in-handler API key + // validator — Actor must stay null. + ctx.Response.StatusCode = endpointStatus; + return; + } + + // Simulate the production handler stashing + // the resolved API key name AFTER auth. + ctx.Items[AuditWriteMiddleware.AuditActorItemKey] = "test-actor"; + ctx.Response.StatusCode = endpointStatus; + await ctx.Response.WriteAsync("ok"); + }); + }); + }); + }); + + var host = await hostBuilder.StartAsync(); + return host; + } + + /// + /// Minimal authentication handler that always succeeds — keeps + /// populated so the test's audit middleware + /// path that prefers Items but falls back to User.Identity has a real + /// principal to ignore. The middleware's primary path uses Items so this + /// handler's claim never appears on the emitted Actor. + /// + private sealed class AlwaysAuthenticatedHandler : AuthenticationHandler + { + public AlwaysAuthenticatedHandler( + Microsoft.Extensions.Options.IOptionsMonitor options, + Microsoft.Extensions.Logging.ILoggerFactory logger, + System.Text.Encodings.Web.UrlEncoder encoder) + : base(options, logger, encoder) { } + + protected override Task HandleAuthenticateAsync() + { + var identity = new ClaimsIdentity(new[] { new Claim(ClaimTypes.Name, "framework-user") }, "TestScheme"); + var principal = new ClaimsPrincipal(identity); + var ticket = new AuthenticationTicket(principal, "TestScheme"); + return Task.FromResult(AuthenticateResult.Success(ticket)); + } + } +} diff --git a/tests/ScadaLink.InboundAPI.Tests/ScadaLink.InboundAPI.Tests.csproj b/tests/ScadaLink.InboundAPI.Tests/ScadaLink.InboundAPI.Tests.csproj index a29815f..1ec503e 100644 --- a/tests/ScadaLink.InboundAPI.Tests/ScadaLink.InboundAPI.Tests.csproj +++ b/tests/ScadaLink.InboundAPI.Tests/ScadaLink.InboundAPI.Tests.csproj @@ -14,6 +14,7 @@ + diff --git a/tests/ScadaLink.IntegrationTests/NotificationOutboxFlowTests.cs b/tests/ScadaLink.IntegrationTests/NotificationOutboxFlowTests.cs index a4ed61b..b639a9a 100644 --- a/tests/ScadaLink.IntegrationTests/NotificationOutboxFlowTests.cs +++ b/tests/ScadaLink.IntegrationTests/NotificationOutboxFlowTests.cs @@ -8,8 +8,10 @@ using Microsoft.EntityFrameworkCore.Storage.ValueConversion; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Logging.Abstractions; using NSubstitute; +using ScadaLink.Commons.Entities.Audit; using ScadaLink.Commons.Entities.Notifications; using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; using ScadaLink.Commons.Messages.Notification; using ScadaLink.Commons.Types.Enums; using ScadaLink.ConfigurationDatabase; @@ -172,7 +174,20 @@ public class NotificationOutboxFlowTests : TestKit }; return Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( - services, options, NullLogger.Instance))); + services, + options, + (ICentralAuditWriter)new NoOpCentralAuditWriter(), + NullLogger.Instance))); + } + + /// + /// Test-only no-op . The integration tests + /// in this file pre-date M4 Bundle B's audit-writer injection; they do not + /// assert on emission, just need a non-null collaborator. + /// + private sealed class NoOpCentralAuditWriter : ICentralAuditWriter + { + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) => Task.CompletedTask; } private static NotificationSubmit MakeSubmit(string notificationId) diff --git a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorAttemptEmissionTests.cs b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorAttemptEmissionTests.cs new file mode 100644 index 0000000..728ddc1 --- /dev/null +++ b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorAttemptEmissionTests.cs @@ -0,0 +1,252 @@ +using Akka.Actor; +using Akka.TestKit.Xunit2; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Abstractions; +using NSubstitute; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Entities.Notifications; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.NotificationOutbox.Delivery; +using ScadaLink.NotificationOutbox.Messages; + +namespace ScadaLink.NotificationOutbox.Tests; + +/// +/// M4 Bundle B (B2) — verifies the +/// dispatcher loop emits exactly ONE +/// / +/// audit row with per attempt regardless of +/// the delivery outcome (success, transient, permanent). Terminal-state +/// emission is covered separately in +/// . +/// +public class NotificationOutboxActorAttemptEmissionTests : TestKit +{ + private readonly INotificationOutboxRepository _outboxRepository = + Substitute.For(); + + private readonly INotificationRepository _notificationRepository = + Substitute.For(); + + private readonly RecordingCentralAuditWriter _auditWriter = new(); + + /// + /// Recording writer so each test can assert on the events captured during + /// one dispatch tick without depending on a concrete implementation. + /// + private sealed class RecordingCentralAuditWriter : ICentralAuditWriter + { + public List Events { get; } = new(); + public Func? OnWrite { get; set; } + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + lock (Events) + { + Events.Add(evt); + } + + return OnWrite?.Invoke(evt) ?? Task.CompletedTask; + } + } + + private IServiceProvider BuildServiceProvider(IEnumerable adapters) + { + var services = new ServiceCollection(); + services.AddScoped(_ => _outboxRepository); + services.AddScoped(_ => _notificationRepository); + foreach (var adapter in adapters) + { + services.AddScoped(_ => adapter); + } + + return services.BuildServiceProvider(); + } + + private sealed class StubAdapter : INotificationDeliveryAdapter + { + private readonly Func _outcome; + public int CallCount; + + public StubAdapter(Func outcome) { _outcome = outcome; } + + public NotificationType Type => NotificationType.Email; + + public Task DeliverAsync( + Notification notification, CancellationToken cancellationToken = default) + { + Interlocked.Increment(ref CallCount); + return Task.FromResult(_outcome()); + } + } + + private IActorRef CreateActor(IEnumerable adapters) + { + return Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( + BuildServiceProvider(adapters), + new NotificationOutboxOptions { DispatchInterval = TimeSpan.FromHours(1) }, + (ICentralAuditWriter)_auditWriter, + NullLogger.Instance))); + } + + private static Notification MakeNotification( + Guid? notificationId = null, + string sourceSite = "site-1", + int retryCount = 0) + { + return new Notification( + (notificationId ?? Guid.NewGuid()).ToString("D"), + NotificationType.Email, + "ops-team", + "Tank overflow", + "Tank 3 level critical", + sourceSite) + { + RetryCount = retryCount, + CreatedAt = DateTimeOffset.UtcNow, + SourceInstanceId = "instance-42", + SourceScript = "AlarmScript", + }; + } + + private void SetupSmtpRetryPolicy(int maxRetries, TimeSpan retryDelay) + { + var config = new SmtpConfiguration("smtp.example.com", "Basic", "noreply@example.com") + { + MaxRetries = maxRetries, + RetryDelay = retryDelay, + }; + _notificationRepository.GetAllSmtpConfigurationsAsync(Arg.Any()) + .Returns(new[] { config }); + } + + private List EventsByStatus(AuditStatus status) + { + lock (_auditWriter.Events) + { + return _auditWriter.Events.Where(e => e.Status == status).ToList(); + } + } + + [Fact] + public void Attempt_Success_EmitsOneEvent_KindNotifyDeliver_StatusAttempted() + { + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var id = Guid.NewGuid(); + var notification = MakeNotification(notificationId: id, sourceSite: "site-alpha"); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Success("ops@example.com")); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + var attempted = EventsByStatus(AuditStatus.Attempted); + Assert.Single(attempted); + var evt = attempted[0]; + Assert.Equal(AuditChannel.Notification, evt.Channel); + Assert.Equal(AuditKind.NotifyDeliver, evt.Kind); + Assert.Equal(id, evt.CorrelationId); + Assert.Equal("ops-team", evt.Target); + Assert.Equal("site-alpha", evt.SourceSiteId); + Assert.Equal("instance-42", evt.SourceInstanceId); + Assert.Equal("AlarmScript", evt.SourceScript); + // Central dispatch: actor is null (no authenticated end-user). + Assert.Null(evt.Actor); + // Successful attempt: no error message. + Assert.Null(evt.ErrorMessage); + }); + } + + [Fact] + public void Attempt_TransientFailure_EmitsEvent_StatusAttempted_ErrorMessageSet() + { + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(retryCount: 1); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Transient("smtp timeout")); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + var attempted = EventsByStatus(AuditStatus.Attempted); + Assert.Single(attempted); + Assert.Equal(AuditKind.NotifyDeliver, attempted[0].Kind); + Assert.Equal("smtp timeout", attempted[0].ErrorMessage); + }); + } + + [Fact] + public void Attempt_PermanentFailure_EmitsEvent_StatusAttempted_ErrorMessageSet() + { + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Permanent("invalid recipient address")); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + var attempted = EventsByStatus(AuditStatus.Attempted); + Assert.Single(attempted); + Assert.Equal(AuditKind.NotifyDeliver, attempted[0].Kind); + Assert.Equal("invalid recipient address", attempted[0].ErrorMessage); + }); + } + + [Fact] + public void AuditWriter_Throws_DeliveryStateUpdate_StillSucceeds() + { + // Audit failure must NEVER abort the user-facing action: the delivery + // outcome must still be persisted via UpdateAsync. + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Success("ops@example.com")); + _auditWriter.OnWrite = _ => throw new InvalidOperationException("audit dead"); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + // Update of the notification row must still happen. + AwaitAssert(() => + { + _outboxRepository.Received(1).UpdateAsync( + Arg.Is(n => n.Status == NotificationStatus.Delivered), + Arg.Any()); + }); + } + + [Fact] + public void Attempt_RecordsOccurredAtUtc_AsUtc() + { + // The OccurredAtUtc on the emitted event must be UTC (all timestamps + // are UTC throughout the system). + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Success("ops@example.com")); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + var attempted = EventsByStatus(AuditStatus.Attempted); + Assert.Single(attempted); + Assert.Equal(DateTimeKind.Utc, attempted[0].OccurredAtUtc.Kind); + }); + } +} diff --git a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorAuditInjectionTests.cs b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorAuditInjectionTests.cs new file mode 100644 index 0000000..0b6a302 --- /dev/null +++ b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorAuditInjectionTests.cs @@ -0,0 +1,79 @@ +using Akka.Actor; +using Akka.TestKit.Xunit2; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Abstractions; +using NSubstitute; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Entities.Notifications; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; + +namespace ScadaLink.NotificationOutbox.Tests; + +/// +/// M4 Bundle B (B1) — verifies accepts an +/// at construction so subsequent bundle tasks +/// (B2/B3) can route attempt + terminal lifecycle events through the central +/// direct-write audit path. +/// +public class NotificationOutboxActorAuditInjectionTests : TestKit +{ + private static IServiceProvider BuildEmptyProvider() + { + var services = new ServiceCollection(); + services.AddScoped(_ => Substitute.For()); + services.AddScoped(_ => Substitute.For()); + return services.BuildServiceProvider(); + } + + /// + /// Inline NoOp writer that records calls — used to assert later tasks emit + /// events without depending on a concrete CentralAuditWriter. + /// + private sealed class RecordingCentralAuditWriter : ICentralAuditWriter + { + public List Events { get; } = new(); + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + lock (Events) + { + Events.Add(evt); + } + return Task.CompletedTask; + } + } + + [Fact] + public void Actor_ConstructedWith_ICentralAuditWriter_NoException() + { + var writer = new RecordingCentralAuditWriter(); + // Long dispatch interval so PreStart's timer never fires during the test. + var options = new NotificationOutboxOptions { DispatchInterval = TimeSpan.FromHours(1) }; + + var actor = Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( + BuildEmptyProvider(), + options, + writer, + NullLogger.Instance))); + + Assert.NotNull(actor); + // No event has been emitted yet — the writer is purely injected at this stage. + lock (writer.Events) + { + Assert.Empty(writer.Events); + } + } + + [Fact] + public void Actor_NullAuditWriter_Throws() + { + var options = new NotificationOutboxOptions { DispatchInterval = TimeSpan.FromHours(1) }; + + Assert.Throws(() => new NotificationOutboxActor( + BuildEmptyProvider(), + options, + auditWriter: null!, + NullLogger.Instance)); + } +} diff --git a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorDispatchTests.cs b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorDispatchTests.cs index fafdf3d..ea91625 100644 --- a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorDispatchTests.cs +++ b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorDispatchTests.cs @@ -8,6 +8,7 @@ using ScadaLink.Commons.Interfaces.Repositories; using ScadaLink.Commons.Types.Enums; using ScadaLink.NotificationOutbox.Delivery; using ScadaLink.NotificationOutbox.Messages; +using ScadaLink.NotificationOutbox.Tests.TestSupport; namespace ScadaLink.NotificationOutbox.Tests; @@ -81,6 +82,7 @@ public class NotificationOutboxActorDispatchTests : TestKit return Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( BuildServiceProvider(adapters), options ?? new NotificationOutboxOptions { DispatchInterval = TimeSpan.FromHours(1) }, + new NoOpCentralAuditWriter(), NullLogger.Instance))); } diff --git a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorIngestTests.cs b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorIngestTests.cs index 4c62943..123711d 100644 --- a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorIngestTests.cs +++ b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorIngestTests.cs @@ -9,6 +9,7 @@ using ScadaLink.Commons.Interfaces.Repositories; using ScadaLink.Commons.Messages.Notification; using ScadaLink.Commons.Types.Enums; using ScadaLink.NotificationOutbox.Delivery; +using ScadaLink.NotificationOutbox.Tests.TestSupport; namespace ScadaLink.NotificationOutbox.Tests; @@ -34,6 +35,7 @@ public class NotificationOutboxActorIngestTests : TestKit return Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( BuildServiceProvider(), new NotificationOutboxOptions(), + new NoOpCentralAuditWriter(), NullLogger.Instance))); } diff --git a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorPurgeTests.cs b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorPurgeTests.cs index bcd749e..b291f76 100644 --- a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorPurgeTests.cs +++ b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorPurgeTests.cs @@ -8,6 +8,7 @@ using ScadaLink.Commons.Interfaces.Repositories; using ScadaLink.Commons.Types.Enums; using ScadaLink.NotificationOutbox.Delivery; using ScadaLink.NotificationOutbox.Messages; +using ScadaLink.NotificationOutbox.Tests.TestSupport; namespace ScadaLink.NotificationOutbox.Tests; @@ -46,6 +47,7 @@ public class NotificationOutboxActorPurgeTests : TestKit DispatchInterval = TimeSpan.FromHours(1), PurgeInterval = TimeSpan.FromHours(1), }, + new NoOpCentralAuditWriter(), NullLogger.Instance))); } diff --git a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorQueryTests.cs b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorQueryTests.cs index 3f2a5d6..5bc9052 100644 --- a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorQueryTests.cs +++ b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorQueryTests.cs @@ -10,6 +10,7 @@ using ScadaLink.Commons.Messages.Notification; using ScadaLink.Commons.Types.Enums; using ScadaLink.Commons.Types.Notifications; using ScadaLink.NotificationOutbox.Delivery; +using ScadaLink.NotificationOutbox.Tests.TestSupport; namespace ScadaLink.NotificationOutbox.Tests; @@ -36,6 +37,7 @@ public class NotificationOutboxActorQueryTests : TestKit BuildServiceProvider(), // A long dispatch interval keeps the dispatch loop from interfering with these tests. options ?? new NotificationOutboxOptions { DispatchInterval = TimeSpan.FromHours(1) }, + new NoOpCentralAuditWriter(), NullLogger.Instance))); } diff --git a/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorTerminalEmissionTests.cs b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorTerminalEmissionTests.cs new file mode 100644 index 0000000..eab39ac --- /dev/null +++ b/tests/ScadaLink.NotificationOutbox.Tests/NotificationOutboxActorTerminalEmissionTests.cs @@ -0,0 +1,283 @@ +using Akka.Actor; +using Akka.TestKit.Xunit2; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Abstractions; +using NSubstitute; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Entities.Notifications; +using ScadaLink.Commons.Interfaces.Repositories; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Messages.Notification; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.NotificationOutbox.Delivery; +using ScadaLink.NotificationOutbox.Messages; + +namespace ScadaLink.NotificationOutbox.Tests; + +/// +/// M4 Bundle B (B3) — verifies the +/// emits a second +/// / +/// audit row carrying the terminal status (Delivered, Parked, Discarded) on +/// every terminal-state transition. The B2 Attempted row is still emitted +/// alongside the terminal one — these tests assert ONLY the terminal row +/// presence and status. +/// +public class NotificationOutboxActorTerminalEmissionTests : TestKit +{ + private readonly INotificationOutboxRepository _outboxRepository = + Substitute.For(); + + private readonly INotificationRepository _notificationRepository = + Substitute.For(); + + private readonly RecordingCentralAuditWriter _auditWriter = new(); + + private sealed class RecordingCentralAuditWriter : ICentralAuditWriter + { + public List Events { get; } = new(); + public Func? OnWrite { get; set; } + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + lock (Events) + { + Events.Add(evt); + } + + return OnWrite?.Invoke(evt) ?? Task.CompletedTask; + } + } + + private IServiceProvider BuildServiceProvider(IEnumerable adapters) + { + var services = new ServiceCollection(); + services.AddScoped(_ => _outboxRepository); + services.AddScoped(_ => _notificationRepository); + foreach (var adapter in adapters) + { + services.AddScoped(_ => adapter); + } + + return services.BuildServiceProvider(); + } + + private sealed class StubAdapter : INotificationDeliveryAdapter + { + private readonly Func _outcome; + + public StubAdapter(Func outcome) { _outcome = outcome; } + + public NotificationType Type => NotificationType.Email; + + public Task DeliverAsync( + Notification notification, CancellationToken cancellationToken = default) + => Task.FromResult(_outcome()); + } + + private IActorRef CreateActor(IEnumerable adapters) + { + return Sys.ActorOf(Props.Create(() => new NotificationOutboxActor( + BuildServiceProvider(adapters), + new NotificationOutboxOptions { DispatchInterval = TimeSpan.FromHours(1) }, + (ICentralAuditWriter)_auditWriter, + NullLogger.Instance))); + } + + private static Notification MakeNotification( + NotificationStatus status = NotificationStatus.Pending, + int retryCount = 0, + Guid? notificationId = null) + { + return new Notification( + (notificationId ?? Guid.NewGuid()).ToString("D"), + NotificationType.Email, + "ops-team", + "Tank overflow", + "Tank 3 level critical", + "site-1") + { + Status = status, + RetryCount = retryCount, + CreatedAt = DateTimeOffset.UtcNow, + }; + } + + private void SetupSmtpRetryPolicy(int maxRetries, TimeSpan retryDelay) + { + var config = new SmtpConfiguration("smtp.example.com", "Basic", "noreply@example.com") + { + MaxRetries = maxRetries, + RetryDelay = retryDelay, + }; + _notificationRepository.GetAllSmtpConfigurationsAsync(Arg.Any()) + .Returns(new[] { config }); + } + + private List EventsByStatus(AuditStatus status) + { + lock (_auditWriter.Events) + { + return _auditWriter.Events.Where(e => e.Status == status).ToList(); + } + } + + [Fact] + public void Terminal_Delivered_EmitsEvent_StatusDelivered() + { + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Success("ops@example.com")); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + var delivered = EventsByStatus(AuditStatus.Delivered); + Assert.Single(delivered); + var evt = delivered[0]; + Assert.Equal(AuditChannel.Notification, evt.Channel); + Assert.Equal(AuditKind.NotifyDeliver, evt.Kind); + Assert.Equal("ops-team", evt.Target); + }); + } + + [Fact] + public void Terminal_Parked_OnPermanentFailure_EmitsEvent_StatusParked() + { + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Permanent("invalid recipient address")); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + var parked = EventsByStatus(AuditStatus.Parked); + Assert.Single(parked); + Assert.Equal(AuditKind.NotifyDeliver, parked[0].Kind); + Assert.Equal("invalid recipient address", parked[0].ErrorMessage); + }); + } + + [Fact] + public void Terminal_Parked_OnTransientReachingMaxRetries_EmitsEvent_StatusParked() + { + SetupSmtpRetryPolicy(maxRetries: 3, retryDelay: TimeSpan.FromMinutes(1)); + // RetryCount starts at max-1; the failed attempt increments it to max + // which triggers the Parked terminal transition. + var notification = MakeNotification(retryCount: 2); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Transient("smtp timeout")); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + var parked = EventsByStatus(AuditStatus.Parked); + Assert.Single(parked); + Assert.Equal(AuditKind.NotifyDeliver, parked[0].Kind); + }); + } + + [Fact] + public void Terminal_Parked_OnMissingAdapter_EmitsEvent_StatusParked() + { + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + // No adapters registered: the missing-adapter park path runs. + var actor = CreateActor([]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + var parked = EventsByStatus(AuditStatus.Parked); + Assert.Single(parked); + Assert.Equal(AuditKind.NotifyDeliver, parked[0].Kind); + Assert.Contains("no delivery adapter", parked[0].ErrorMessage!); + }); + } + + [Fact] + public void Transient_BelowMaxRetries_DoesNotEmitTerminalRow() + { + // A transient failure that does not reach max-retries leaves the row + // in Retrying — non-terminal, so no terminal audit row should be + // emitted (only the Attempted row from B2). + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(retryCount: 0); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Transient("smtp timeout")); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + // Wait for the Attempted row to land so we know dispatch has run. + AwaitAssert(() => Assert.Single(EventsByStatus(AuditStatus.Attempted))); + + // No terminal rows of any kind. + Assert.Empty(EventsByStatus(AuditStatus.Delivered)); + Assert.Empty(EventsByStatus(AuditStatus.Parked)); + Assert.Empty(EventsByStatus(AuditStatus.Discarded)); + } + + [Fact] + public void Terminal_Discarded_OnManualDiscard_EmitsEvent_StatusDiscarded() + { + // Wire the actor with a parked row that GetByIdAsync returns; the + // discard handler must emit a terminal Discarded audit row. + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(status: NotificationStatus.Parked); + _outboxRepository.GetByIdAsync(notification.NotificationId, Arg.Any()) + .Returns(notification); + var actor = CreateActor([]); + + actor.Tell(new DiscardNotificationRequest( + CorrelationId: "test-corr", NotificationId: notification.NotificationId)); + + // First wait for the discard handler to reply (handshake), then assert + // the audit row landed. + ExpectMsg(r => r.Success); + AwaitAssert(() => + { + var discarded = EventsByStatus(AuditStatus.Discarded); + Assert.Single(discarded); + Assert.Equal(AuditKind.NotifyDeliver, discarded[0].Kind); + }); + } + + [Fact] + public void AuditWriter_Throws_TerminalUpdate_StillSucceeds() + { + // Audit failure NEVER aborts the user-facing action: the dispatcher + // must still persist the Delivered status via UpdateAsync. + SetupSmtpRetryPolicy(maxRetries: 5, retryDelay: TimeSpan.FromMinutes(1)); + var notification = MakeNotification(); + _outboxRepository.GetDueAsync(Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(new[] { notification }); + var adapter = new StubAdapter(() => DeliveryOutcome.Success("ops@example.com")); + _auditWriter.OnWrite = _ => throw new InvalidOperationException("audit dead"); + var actor = CreateActor([adapter]); + + actor.Tell(InternalMessages.DispatchTick.Instance); + + AwaitAssert(() => + { + _outboxRepository.Received(1).UpdateAsync( + Arg.Is(n => n.Status == NotificationStatus.Delivered), + Arg.Any()); + }); + } +} diff --git a/tests/ScadaLink.NotificationOutbox.Tests/TestSupport/NoOpCentralAuditWriter.cs b/tests/ScadaLink.NotificationOutbox.Tests/TestSupport/NoOpCentralAuditWriter.cs new file mode 100644 index 0000000..ae82341 --- /dev/null +++ b/tests/ScadaLink.NotificationOutbox.Tests/TestSupport/NoOpCentralAuditWriter.cs @@ -0,0 +1,15 @@ +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Services; + +namespace ScadaLink.NotificationOutbox.Tests.TestSupport; + +/// +/// Test-only no-op . Used by existing +/// NotificationOutboxActor TestKit fixtures whose tests pre-date the M4 Bundle B +/// audit-writer injection — they don't care about audit emission, they just +/// need a non-null collaborator so the actor's constructor succeeds. +/// +internal sealed class NoOpCentralAuditWriter : ICentralAuditWriter +{ + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) => Task.CompletedTask; +} diff --git a/tests/ScadaLink.SiteRuntime.Tests/Scripts/DatabaseSyncEmissionTests.cs b/tests/ScadaLink.SiteRuntime.Tests/Scripts/DatabaseSyncEmissionTests.cs new file mode 100644 index 0000000..f2ca536 --- /dev/null +++ b/tests/ScadaLink.SiteRuntime.Tests/Scripts/DatabaseSyncEmissionTests.cs @@ -0,0 +1,296 @@ +using Microsoft.Data.Sqlite; +using Microsoft.Extensions.Logging.Abstractions; +using Moq; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.SiteRuntime.Scripts; + +namespace ScadaLink.SiteRuntime.Tests.Scripts; + +/// +/// Audit Log #23 — M4 Bundle A (Tasks A1+A2): every synchronous DB call made +/// through Database.Connection("name") emits exactly one +/// DbOutbound/DbWrite audit event with an Extra envelope +/// distinguishing writes (op="write", rowsAffected=N) from reads +/// (op="read", rowsReturned=N). The audit emission is +/// best-effort — a thrown must never +/// abort the script's call, and the original ADO.NET result (or original +/// exception) must surface to the caller unchanged. +/// +public class DatabaseSyncEmissionTests +{ + /// + /// In-memory mirroring the M2 Bundle F stub — + /// captures every event and may be configured to throw to verify the + /// 3-layer fail-safe (mirrors CapturingAuditWriter in + /// ExternalSystemCallAuditEmissionTests). + /// + private sealed class CapturingAuditWriter : IAuditWriter + { + public List Events { get; } = new(); + public Exception? ThrowOnWrite { get; set; } + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + if (ThrowOnWrite != null) + { + return Task.FromException(ThrowOnWrite); + } + + Events.Add(evt); + return Task.CompletedTask; + } + } + + private const string SiteId = "site-77"; + private const string InstanceName = "Plant.Pump42"; + private const string SourceScript = "ScriptActor:Sync"; + private const string ConnectionName = "machineData"; + + private static ScriptRuntimeContext.DatabaseHelper CreateHelper( + IDatabaseGateway gateway, + IAuditWriter? auditWriter) + { + return new ScriptRuntimeContext.DatabaseHelper( + gateway, + InstanceName, + NullLogger.Instance, + auditWriter: auditWriter, + siteId: SiteId, + sourceScript: SourceScript, + cachedForwarder: null); + } + + /// + /// Spin up a fresh in-memory SQLite database with a tiny single-table + /// schema we can write to and read from. The connection is returned in + /// the open state so the test only has to call Connection() via + /// the helper. SQLite in-memory databases live as long as the connection + /// holding them, so the keep-alive root must outlive any auditing + /// wrapper the test exercises. + /// + private static SqliteConnection NewInMemoryDb(out SqliteConnection keepAlive) + { + // The shared-cache name is per-test (Guid) so concurrent tests don't + // collide. mode=memory keeps it RAM-only; cache=shared lets the + // keep-alive root and the gateway-returned connection see the same + // in-memory DB. The keepAlive connection must remain open for the + // duration of the test or the in-memory DB is discarded. + var dbName = $"db-{Guid.NewGuid():N}"; + var connStr = $"Data Source={dbName};Mode=Memory;Cache=Shared"; + + keepAlive = new SqliteConnection(connStr); + keepAlive.Open(); + using (var seed = keepAlive.CreateCommand()) + { + seed.CommandText = + "CREATE TABLE t (id INTEGER PRIMARY KEY, name TEXT NOT NULL);" + + "INSERT INTO t (id, name) VALUES (1, 'alpha');" + + "INSERT INTO t (id, name) VALUES (2, 'beta');"; + seed.ExecuteNonQuery(); + } + + var live = new SqliteConnection(connStr); + live.Open(); + return live; + } + + [Fact] + public async Task Execute_InsertSuccess_EmitsOneEvent_KindDbWrite_StatusDelivered_OpWrite_RowsAffected() + { + using var keepAlive = new SqliteConnection("Data Source=k;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out var _); + var gateway = new Mock(); + gateway + .Setup(g => g.GetConnectionAsync(ConnectionName, It.IsAny())) + .ReturnsAsync(inner); + var writer = new CapturingAuditWriter(); + + var helper = CreateHelper(gateway.Object, writer); + await using var conn = await helper.Connection(ConnectionName); + await using var cmd = conn.CreateCommand(); + cmd.CommandText = "INSERT INTO t (id, name) VALUES (3, 'gamma')"; + var rows = await cmd.ExecuteNonQueryAsync(); + + Assert.Equal(1, rows); + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditChannel.DbOutbound, evt.Channel); + Assert.Equal(AuditKind.DbWrite, evt.Kind); + Assert.Equal(AuditStatus.Delivered, evt.Status); + Assert.Equal(AuditForwardState.Pending, evt.ForwardState); + Assert.NotNull(evt.Extra); + Assert.Contains("\"op\":\"write\"", evt.Extra); + Assert.Contains("\"rowsAffected\":1", evt.Extra); + Assert.Equal(DateTimeKind.Utc, evt.OccurredAtUtc.Kind); + Assert.NotEqual(Guid.Empty, evt.EventId); + Assert.StartsWith(ConnectionName, evt.Target); + } + + [Fact] + public async Task ExecuteScalar_Success_EmitsKindDbWrite_OpWrite() + { + using var keepAlive = new SqliteConnection("Data Source=k2;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out var _); + var gateway = new Mock(); + gateway + .Setup(g => g.GetConnectionAsync(ConnectionName, It.IsAny())) + .ReturnsAsync(inner); + var writer = new CapturingAuditWriter(); + + var helper = CreateHelper(gateway.Object, writer); + await using var conn = await helper.Connection(ConnectionName); + await using var cmd = conn.CreateCommand(); + cmd.CommandText = "SELECT COUNT(*) FROM t"; + var scalar = await cmd.ExecuteScalarAsync(); + + Assert.NotNull(scalar); + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditChannel.DbOutbound, evt.Channel); + Assert.Equal(AuditKind.DbWrite, evt.Kind); + Assert.Equal(AuditStatus.Delivered, evt.Status); + Assert.NotNull(evt.Extra); + // ExecuteScalar is classified as "write" per the M4 vocabulary lock + // (Channel=DbOutbound, Kind=DbWrite, Extra.op="write") — the + // rowsAffected for a SELECT-on-SqlCommand is -1 in ADO.NET; the audit + // wrapper records whatever DbCommand.ExecuteScalar returned via the + // built-in path, plus the rowsAffected counter the wrapper observed. + Assert.Contains("\"op\":\"write\"", evt.Extra); + Assert.Contains("rowsAffected", evt.Extra); + } + + [Fact] + public async Task Execute_Throws_EmitsEvent_StatusFailed_ErrorMessageSet() + { + using var keepAlive = new SqliteConnection("Data Source=k3;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out var _); + var gateway = new Mock(); + gateway + .Setup(g => g.GetConnectionAsync(ConnectionName, It.IsAny())) + .ReturnsAsync(inner); + var writer = new CapturingAuditWriter(); + + var helper = CreateHelper(gateway.Object, writer); + await using var conn = await helper.Connection(ConnectionName); + await using var cmd = conn.CreateCommand(); + // Reference an undefined column — SQLite throws SqliteException synchronously. + cmd.CommandText = "INSERT INTO t (does_not_exist) VALUES (1)"; + await Assert.ThrowsAsync(() => cmd.ExecuteNonQueryAsync()); + + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditStatus.Failed, evt.Status); + Assert.False(string.IsNullOrEmpty(evt.ErrorMessage)); + Assert.NotNull(evt.ErrorDetail); + Assert.Contains("does_not_exist", evt.ErrorDetail); + } + + [Fact] + public async Task ExecuteReader_Success_EmitsKindDbWrite_OpRead_RowsReturned() + { + using var keepAlive = new SqliteConnection("Data Source=k4;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out var _); + var gateway = new Mock(); + gateway + .Setup(g => g.GetConnectionAsync(ConnectionName, It.IsAny())) + .ReturnsAsync(inner); + var writer = new CapturingAuditWriter(); + + var helper = CreateHelper(gateway.Object, writer); + await using var conn = await helper.Connection(ConnectionName); + await using var cmd = conn.CreateCommand(); + cmd.CommandText = "SELECT id, name FROM t ORDER BY id"; + await using var reader = await cmd.ExecuteReaderAsync(); + var rows = 0; + while (await reader.ReadAsync()) + { + rows++; + } + // Close the reader explicitly so the audit emission (deferred to + // reader-close per the wrapper contract) fires before assertion. + await reader.CloseAsync(); + + Assert.Equal(2, rows); + var evt = Assert.Single(writer.Events); + Assert.Equal(AuditChannel.DbOutbound, evt.Channel); + Assert.Equal(AuditKind.DbWrite, evt.Kind); + Assert.Equal(AuditStatus.Delivered, evt.Status); + Assert.NotNull(evt.Extra); + Assert.Contains("\"op\":\"read\"", evt.Extra); + Assert.Contains("\"rowsReturned\":2", evt.Extra); + } + + [Fact] + public async Task AuditWriter_Throws_ScriptCall_ReturnsOriginalResult() + { + using var keepAlive = new SqliteConnection("Data Source=k5;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out var _); + var gateway = new Mock(); + gateway + .Setup(g => g.GetConnectionAsync(ConnectionName, It.IsAny())) + .ReturnsAsync(inner); + var writer = new CapturingAuditWriter + { + ThrowOnWrite = new InvalidOperationException("audit writer down") + }; + + var helper = CreateHelper(gateway.Object, writer); + await using var conn = await helper.Connection(ConnectionName); + await using var cmd = conn.CreateCommand(); + cmd.CommandText = "INSERT INTO t (id, name) VALUES (4, 'delta')"; + var rows = await cmd.ExecuteNonQueryAsync(); + + // Original ADO.NET result must surface unchanged despite the audit + // writer faulting — the wrapper swallows + logs the audit failure. + Assert.Equal(1, rows); + Assert.Empty(writer.Events); + } + + [Fact] + public async Task Provenance_PopulatedFromContext() + { + using var keepAlive = new SqliteConnection("Data Source=k6;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out var _); + var gateway = new Mock(); + gateway + .Setup(g => g.GetConnectionAsync(ConnectionName, It.IsAny())) + .ReturnsAsync(inner); + var writer = new CapturingAuditWriter(); + + var helper = CreateHelper(gateway.Object, writer); + await using var conn = await helper.Connection(ConnectionName); + await using var cmd = conn.CreateCommand(); + cmd.CommandText = "INSERT INTO t (id, name) VALUES (5, 'epsilon')"; + await cmd.ExecuteNonQueryAsync(); + + var evt = Assert.Single(writer.Events); + Assert.Equal(SiteId, evt.SourceSiteId); + Assert.Equal(InstanceName, evt.SourceInstanceId); + Assert.Equal(SourceScript, evt.SourceScript); + Assert.Null(evt.Actor); + Assert.Null(evt.CorrelationId); + Assert.NotEqual(Guid.Empty, evt.EventId); + } + + [Fact] + public async Task DurationMs_NonZero() + { + using var keepAlive = new SqliteConnection("Data Source=k7;Mode=Memory;Cache=Shared"); + var inner = NewInMemoryDb(out var _); + var gateway = new Mock(); + gateway + .Setup(g => g.GetConnectionAsync(ConnectionName, It.IsAny())) + .ReturnsAsync(inner); + var writer = new CapturingAuditWriter(); + + var helper = CreateHelper(gateway.Object, writer); + await using var conn = await helper.Connection(ConnectionName); + await using var cmd = conn.CreateCommand(); + cmd.CommandText = "INSERT INTO t (id, name) VALUES (6, 'zeta')"; + await cmd.ExecuteNonQueryAsync(); + + var evt = Assert.Single(writer.Events); + Assert.NotNull(evt.DurationMs); + Assert.True(evt.DurationMs >= 0, $"DurationMs={evt.DurationMs} should be >= 0"); + Assert.True(evt.DurationMs <= 5000, $"DurationMs={evt.DurationMs} should be <= 5000"); + } +} diff --git a/tests/ScadaLink.SiteRuntime.Tests/Scripts/NotifySendAuditEmissionTests.cs b/tests/ScadaLink.SiteRuntime.Tests/Scripts/NotifySendAuditEmissionTests.cs new file mode 100644 index 0000000..8a85e73 --- /dev/null +++ b/tests/ScadaLink.SiteRuntime.Tests/Scripts/NotifySendAuditEmissionTests.cs @@ -0,0 +1,237 @@ +using System.Text.Json; +using Akka.Actor; +using Akka.TestKit.Xunit2; +using Microsoft.Data.Sqlite; +using Microsoft.Extensions.Logging.Abstractions; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Interfaces.Services; +using ScadaLink.Commons.Types.Enums; +using ScadaLink.SiteRuntime.Scripts; +using ScadaLink.StoreAndForward; + +namespace ScadaLink.SiteRuntime.Tests.Scripts; + +/// +/// Audit Log #23 — M4 Bundle C (Task C1): every script-initiated +/// Notify.To("list").Send(...) emits exactly one +/// Notification/NotifySend audit event via the wrapper inside +/// . The audit emission is +/// best-effort: a thrown must never +/// abort the script's Send — the original NotificationId must +/// still flow back to the caller and the underlying S&F enqueue must still +/// have happened. +/// +public class NotifySendAuditEmissionTests : TestKit, IAsyncLifetime, IDisposable +{ + /// + /// In-memory that records every event passed to + /// . Optionally configurable to throw, simulating a + /// catastrophic audit-writer failure that the wrapper must swallow per + /// alog.md §7. + /// + private sealed class CapturingAuditWriter : IAuditWriter + { + public List Events { get; } = new(); + public Exception? ThrowOnWrite { get; set; } + + public Task WriteAsync(AuditEvent evt, CancellationToken ct = default) + { + if (ThrowOnWrite != null) + { + return Task.FromException(ThrowOnWrite); + } + + Events.Add(evt); + return Task.CompletedTask; + } + } + + private const string SiteId = "site-7"; + private const string InstanceName = "Plant.Pump3"; + private const string SourceScript = "ScriptActor:CheckPressure"; + private const string ListName = "Operators"; + private const string Subject = "Pump alarm"; + private const string Body = "Pump 3 tripped"; + + private readonly SqliteConnection _keepAlive; + private readonly StoreAndForwardStorage _storage; + private readonly StoreAndForwardService _saf; + + public NotifySendAuditEmissionTests() + { + var dbName = $"NotifySendAudit_{Guid.NewGuid():N}"; + var connStr = $"Data Source={dbName};Mode=Memory;Cache=Shared"; + _keepAlive = new SqliteConnection(connStr); + _keepAlive.Open(); + + _storage = new StoreAndForwardStorage(connStr, NullLogger.Instance); + var options = new StoreAndForwardOptions + { + DefaultRetryInterval = TimeSpan.Zero, + DefaultMaxRetries = 3, + RetryTimerInterval = TimeSpan.FromMinutes(10) + }; + _saf = new StoreAndForwardService(_storage, options, NullLogger.Instance); + } + + public async Task InitializeAsync() => await _storage.InitializeAsync(); + + public Task DisposeAsync() => Task.CompletedTask; + + protected override void Dispose(bool disposing) + { + if (disposing) + { + _keepAlive.Dispose(); + } + base.Dispose(disposing); + } + + private ScriptRuntimeContext.NotifyHelper CreateHelper( + IAuditWriter? auditWriter, + string? sourceScript = SourceScript) + { + // siteCommunicationActor is unused by Send — pass a probe so the helper + // is fully constructed. + var probe = CreateTestProbe(); + return new ScriptRuntimeContext.NotifyHelper( + _saf, + probe.Ref, + SiteId, + InstanceName, + sourceScript, + TimeSpan.FromSeconds(3), + NullLogger.Instance, + auditWriter); + } + + [Fact] + public async Task Send_Success_EmitsOneEvent_KindNotifySend_StatusSubmitted() + { + var writer = new CapturingAuditWriter(); + var notify = CreateHelper(writer); + + var notificationId = await notify.To(ListName).Send(Subject, Body); + + Assert.False(string.IsNullOrEmpty(notificationId)); + Assert.Single(writer.Events); + var evt = writer.Events[0]; + Assert.Equal(AuditChannel.Notification, evt.Channel); + Assert.Equal(AuditKind.NotifySend, evt.Kind); + Assert.Equal(AuditStatus.Submitted, evt.Status); + Assert.Equal(AuditForwardState.Pending, evt.ForwardState); + Assert.Equal(DateTimeKind.Utc, evt.OccurredAtUtc.Kind); + Assert.NotEqual(Guid.Empty, evt.EventId); + Assert.False(evt.PayloadTruncated); + Assert.Null(evt.DurationMs); + Assert.Null(evt.HttpStatus); + Assert.Null(evt.ErrorMessage); + Assert.Null(evt.ErrorDetail); + Assert.Null(evt.Actor); + } + + [Fact] + public async Task Send_PopulatesTarget_AsListName() + { + var writer = new CapturingAuditWriter(); + var notify = CreateHelper(writer); + + await notify.To(ListName).Send(Subject, Body); + + var evt = writer.Events[0]; + Assert.Equal(ListName, evt.Target); + } + + [Fact] + public async Task Send_PopulatesRequestSummary_AsSubjectBodyJson() + { + var writer = new CapturingAuditWriter(); + var notify = CreateHelper(writer); + + await notify.To(ListName).Send(Subject, Body); + + var evt = writer.Events[0]; + Assert.NotNull(evt.RequestSummary); + // Round-trip the JSON to assert the exact shape, not raw text — the + // contract is "JSON of {subject, body}", which downstream redaction + // (M5) can reshape; M4 captures verbatim. + using var doc = JsonDocument.Parse(evt.RequestSummary!); + var root = doc.RootElement; + Assert.Equal(JsonValueKind.Object, root.ValueKind); + Assert.Equal(Subject, root.GetProperty("subject").GetString()); + Assert.Equal(Body, root.GetProperty("body").GetString()); + } + + [Fact] + public async Task Send_AuditWriter_Throws_OriginalSendStillReturns() + { + var writer = new CapturingAuditWriter + { + ThrowOnWrite = new InvalidOperationException("audit writer down") + }; + var notify = CreateHelper(writer); + + // The Send call must NOT bubble the audit-writer failure: the script + // contract is that the notification is buffered and the id is returned + // even when the audit pipeline is sick. + var notificationId = await notify.To(ListName).Send(Subject, Body); + + Assert.False(string.IsNullOrEmpty(notificationId)); + + // And the underlying S&F enqueue must still have happened — audit is + // purely additive, never aborts the user-facing action. + var buffered = await _saf.GetMessageByIdAsync(notificationId); + Assert.NotNull(buffered); + Assert.Equal(notificationId, buffered!.Id); + + Assert.Empty(writer.Events); + } + + [Fact] + public async Task Send_Provenance_PopulatedFromContext() + { + var writer = new CapturingAuditWriter(); + var notify = CreateHelper(writer); + + await notify.To(ListName).Send(Subject, Body); + + var evt = writer.Events[0]; + Assert.Equal(SiteId, evt.SourceSiteId); + Assert.Equal(InstanceName, evt.SourceInstanceId); + Assert.Equal(SourceScript, evt.SourceScript); + Assert.Null(evt.Actor); + } + + [Fact] + public async Task Send_NotificationIdParsed_AsCorrelationId() + { + var writer = new CapturingAuditWriter(); + var notify = CreateHelper(writer); + + var notificationId = await notify.To(ListName).Send(Subject, Body); + + // NotificationId is minted as Guid.NewGuid().ToString("N") — the 32-char + // hex form, which Guid.TryParse accepts. The audit row's CorrelationId + // must round-trip back to the same Guid value. + Assert.True(Guid.TryParse(notificationId, out var expected), + $"NotificationId '{notificationId}' should be a parseable Guid"); + var evt = writer.Events[0]; + Assert.NotNull(evt.CorrelationId); + Assert.Equal(expected, evt.CorrelationId); + } + + [Fact] + public async Task Send_WithoutAuditWriter_StillReturnsNotificationId_AndEnqueues() + { + // Audit is opt-in (mirrors M2 Bundle F behaviour): a null writer must + // degrade to a no-op audit path so tests / minimal hosts that don't + // wire AddAuditLog still work. + var notify = CreateHelper(auditWriter: null); + + var notificationId = await notify.To(ListName).Send(Subject, Body); + + Assert.False(string.IsNullOrEmpty(notificationId)); + var buffered = await _saf.GetMessageByIdAsync(notificationId); + Assert.NotNull(buffered); + } +}