From 855df759b516d05a0b9fdc34860c39b06dd0024f Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 20 May 2026 16:18:46 -0400 Subject: [PATCH] feat(siteruntime): emit NotifySend(Submitted) on site-side Notify.To().Send (#23 M4) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Audit Log #23 M4 Bundle C — Task C1: every script-initiated Notify.To(list).Send(...) now emits exactly one Notification/NotifySend audit row via the IAuditWriter wired through ScriptRuntimeContext. The row carries Status=Submitted, Target=list name, RequestSummary={subject,body} JSON (M5 will redact), CorrelationId=NotificationId (parsed as Guid), provenance from context, ForwardState=Pending. Emission is best-effort per alog.md §7: a thrown audit writer is logged and swallowed inside the helper; the original NotificationId still flows back to the script and the underlying S&F enqueue still happened. Mirrors the M2 Bundle F ExternalSystem.Call wrapper pattern. Tests: 7 new tests in NotifySendAuditEmissionTests covering submitted- status, list-name target, request-summary JSON shape, writer-throws fail-safe, provenance, NotificationId/CorrelationId round-trip, and the null-writer degrade path. --- .../Scripts/ScriptRuntimeContext.cs | 159 +++++++++++- .../Scripts/NotifySendAuditEmissionTests.cs | 237 ++++++++++++++++++ 2 files changed, 392 insertions(+), 4 deletions(-) create mode 100644 tests/ScadaLink.SiteRuntime.Tests/Scripts/NotifySendAuditEmissionTests.cs diff --git a/src/ScadaLink.SiteRuntime/Scripts/ScriptRuntimeContext.cs b/src/ScadaLink.SiteRuntime/Scripts/ScriptRuntimeContext.cs index aed1532..f7d838f 100644 --- a/src/ScadaLink.SiteRuntime/Scripts/ScriptRuntimeContext.cs +++ b/src/ScadaLink.SiteRuntime/Scripts/ScriptRuntimeContext.cs @@ -272,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. @@ -1090,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, @@ -1097,7 +1115,8 @@ public class ScriptRuntimeContext string instanceName, string? sourceScript, TimeSpan askTimeout, - ILogger logger) + ILogger logger, + IAuditWriter? auditWriter = null) { _storeAndForward = storeAndForward; _siteCommunicationActor = siteCommunicationActor; @@ -1106,6 +1125,7 @@ public class ScriptRuntimeContext _sourceScript = sourceScript; _askTimeout = askTimeout; _logger = logger; + _auditWriter = auditWriter; } /// @@ -1114,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); } /// @@ -1189,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; @@ -1203,6 +1235,7 @@ public class ScriptRuntimeContext _instanceName = instanceName; _sourceScript = sourceScript; _logger = logger; + _auditWriter = auditWriter; } /// @@ -1251,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, @@ -1262,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.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); + } +}