perf(audit): bounded async audit writer with batched inserts, one-time bootstrap, retention sweep

2026-08-15 12:17:22 -04:00
parent 6c5218913b
commit e2ac5d117a
9 changed files with 845 additions and 38 deletions
@@ -0,0 +1,271 @@
+using Microsoft.Extensions.Logging.Abstractions;
+using Microsoft.Extensions.Time.Testing;
+using ZB.MOM.WW.Audit;
+using ZB.MOM.WW.Auth.ApiKeys.Sqlite;
+using ZB.MOM.WW.MxGateway.Server.Configuration;
+using ZB.MOM.WW.MxGateway.Server.Security.Audit;
+using ZB.MOM.WW.MxGateway.Tests.Security.Authentication;
+
+namespace ZB.MOM.WW.MxGateway.Tests.Security.Audit;
+
+/// <summary>
+/// Tests the bounded, asynchronous audit path: <see cref="ChannelAuditWriter"/> (enqueue-only
+/// once a drain is attached, drops rather than blocks when the channel is full) and
+/// <see cref="AuditDrainService"/> (batched drain, one-time table bootstrap, retention sweep).
+/// The channel makes the already-documented best-effort audit contract explicit and bounded:
+/// a partially denied bulk RPC no longer pays a SQLite round-trip per denied tag.
+/// </summary>
+public sealed class ChannelAuditWriterTests : IDisposable
+{
+    private readonly List<TempDatabaseDirectory> _tempDirectories = [];
+
+    /// <summary>
+    /// With a drain attached, <see cref="ChannelAuditWriter.WriteAsync"/> only enqueues — the
+    /// sink is not touched until the drain runs, and the event arrives once it does.
+    /// </summary>
+    /// <returns>A task that represents the asynchronous operation.</returns>
+    [Fact]
+    public async Task WriteAsync_WithDrainAttached_EnqueuesOnlyAndReachesSinkAfterDrain()
+    {
+        CountingAuditSink sink = new();
+        (ChannelAuditWriter writer, AuditDrainService drain) = CreateWriterAndDrain(sink);
+        writer.AttachDrain();
+
+        await writer.WriteAsync(MakeEvent("constraint-denied"), CancellationToken.None);
+
+        // Enqueue-only: nothing has reached the sink yet.
+        Assert.Equal(0, sink.InsertBatchCalls);
+        Assert.Empty(sink.Events);
+
+        int drained = await drain.DrainPendingAsync(CancellationToken.None);
+
+        Assert.Equal(1, drained);
+        Assert.Equal(1, sink.InsertBatchCalls);
+        Assert.Equal("constraint-denied", Assert.Single(sink.Events).Action);
+    }
+
+    /// <summary>
+    /// A drain pass batches up to <see cref="AuditDrainService.MaxBatchSize"/> events into one
+    /// sink call, so a partially denied bulk RPC costs a handful of transactions, not one per tag.
+    /// </summary>
+    /// <returns>A task that represents the asynchronous operation.</returns>
+    [Fact]
+    public async Task DrainPendingAsync_BatchesEventsIntoBoundedInsertCalls()
+    {
+        CountingAuditSink sink = new();
+        (ChannelAuditWriter writer, AuditDrainService drain) = CreateWriterAndDrain(sink);
+        writer.AttachDrain();
+
+        const int eventCount = 150;
+        for (int index = 0; index < eventCount; index++)
+        {
+            await writer.WriteAsync(MakeEvent($"denied-{index}"), CancellationToken.None);
+        }
+
+        int drained = await drain.DrainPendingAsync(CancellationToken.None);
+
+        Assert.Equal(eventCount, drained);
+        Assert.Equal(eventCount, sink.Events.Count);
+        // 150 events at a batch size of 64 → 3 transactions (64 + 64 + 22), not 150.
+        Assert.Equal(3, sink.InsertBatchCalls);
+        Assert.All(sink.BatchSizes, size => Assert.True(size <= AuditDrainService.MaxBatchSize));
+    }
+
+    /// <summary>
+    /// When the bounded channel is full the write is dropped rather than blocking the caller,
+    /// and the drop is counted. A stalled or slow audit database must never stall an RPC.
+    /// </summary>
+    /// <returns>A task that represents the asynchronous operation.</returns>
+    [Fact]
+    public async Task WriteAsync_WhenChannelFull_DropsWriteAndCountsItWithoutBlocking()
+    {
+        CountingAuditSink sink = new();
+        (ChannelAuditWriter writer, _) = CreateWriterAndDrain(sink);
+        writer.AttachDrain();
+
+        const int overflow = 32;
+        for (int index = 0; index < ChannelAuditWriter.ChannelCapacity + overflow; index++)
+        {
+            // Every call must complete synchronously: the channel never blocks a producer.
+            Task write = writer.WriteAsync(MakeEvent($"denied-{index}"), CancellationToken.None);
+            Assert.True(write.IsCompletedSuccessfully);
+        }
+
+        Assert.Equal(overflow, writer.DroppedCount);
+        // The channel still holds exactly its capacity; nothing reached the sink (no drain ran).
+        Assert.Equal(0, sink.InsertBatchCalls);
+
+        await Task.CompletedTask;
+    }
+
+    /// <summary>
+    /// With no drain attached (the <c>apikey</c> CLI, DI-only tests, post-shutdown) the writer
+    /// writes through to the sink instead of enqueueing into a channel nobody will ever read.
+    /// </summary>
+    /// <returns>A task that represents the asynchronous operation.</returns>
+    [Fact]
+    public async Task WriteAsync_WithNoDrainAttached_WritesThroughToSink()
+    {
+        CountingAuditSink sink = new();
+        (ChannelAuditWriter writer, _) = CreateWriterAndDrain(sink);
+
+        await writer.WriteAsync(MakeEvent("dashboard-create-key"), CancellationToken.None);
+
+        Assert.Equal("dashboard-create-key", Assert.Single(sink.Events).Action);
+    }
+
+    /// <summary>
+    /// The retention sweep deletes rows older than <c>AuditRetentionDays</c>, measured from the
+    /// injected clock, and runs once at startup after the one-time table bootstrap.
+    /// </summary>
+    /// <returns>A task that represents the asynchronous operation.</returns>
+    [Fact]
+    public async Task StartAsync_BootstrapsTableThenSweepsRetentionAtConfiguredCutoff()
+    {
+        CountingAuditSink sink = new();
+        FakeTimeProvider clock = new(new DateTimeOffset(2026, 8, 15, 12, 0, 0, TimeSpan.Zero));
+        (_, AuditDrainService drain) = CreateWriterAndDrain(
+            sink,
+            new SecurityOptions { AuditRetentionDays = 30 },
+            clock);
+
+        await drain.StartAsync(CancellationToken.None);
+        await drain.StopAsync(CancellationToken.None);
+
+        Assert.Equal(1, sink.EnsureInitializedCalls);
+        Assert.Equal(new DateTimeOffset(2026, 7, 16, 12, 0, 0, TimeSpan.Zero), Assert.Single(sink.DeleteCutoffs));
+    }
+
+    /// <summary>
+    /// The real SQLite sink deletes only rows older than the cutoff, and its bootstrap latch
+    /// means the <c>CREATE TABLE</c> round-trip is not repeated on every subsequent write.
+    /// </summary>
+    /// <returns>A task that represents the asynchronous operation.</returns>
+    [Fact]
+    public async Task SqliteStore_DeleteOlderThan_RemovesOnlyRowsBeyondTheRetentionWindow()
+    {
+        SqliteCanonicalAuditStore store = CreateStore();
+        DateTimeOffset now = new(2026, 8, 15, 12, 0, 0, TimeSpan.Zero);
+
+        await store.InsertBatchAsync(
+            [
+                MakeEvent("stale", now.AddDays(-120)),
+                // A non-UTC offset must still compare correctly against the cutoff.
+                MakeEvent("stale-offset", now.AddDays(-100).ToOffset(TimeSpan.FromHours(-5))),
+                MakeEvent("fresh", now.AddDays(-1)),
+            ],
+            CancellationToken.None);
+
+        int deleted = await store.DeleteOlderThanAsync(now.AddDays(-90), CancellationToken.None);
+
+        Assert.Equal(2, deleted);
+        Assert.Equal("fresh", Assert.Single(await store.ListRecentAsync(10, CancellationToken.None)).Action);
+    }
+
+    private static (ChannelAuditWriter Writer, AuditDrainService Drain) CreateWriterAndDrain(
+        IAuditEventSink sink,
+        SecurityOptions? security = null,
+        TimeProvider? timeProvider = null)
+    {
+        ChannelAuditWriter writer = new(
+            new CanonicalAuditWriter(sink, NullLogger<CanonicalAuditWriter>.Instance),
+            NullLogger<ChannelAuditWriter>.Instance);
+        AuditDrainService drain = new(
+            writer,
+            sink,
+            security ?? new SecurityOptions(),
+            timeProvider ?? TimeProvider.System,
+            NullLogger<AuditDrainService>.Instance);
+        return (writer, drain);
+    }
+
+    private SqliteCanonicalAuditStore CreateStore()
+    {
+        TempDatabaseDirectory directory = TempDatabaseDirectory.Create("mxgateway-channel-audit");
+        _tempDirectories.Add(directory);
+        return new SqliteCanonicalAuditStore(new AuthSqliteConnectionFactory(directory.DatabasePath()));
+    }
+
+    private static AuditEvent MakeEvent(string action, DateTimeOffset? occurredAtUtc = null) => new()
+    {
+        EventId = Guid.NewGuid(),
+        OccurredAtUtc = occurredAtUtc ?? DateTimeOffset.UtcNow,
+        Actor = "operator01",
+        Action = action,
+        Outcome = AuditOutcome.Denied,
+        Category = "ApiKey",
+    };
+
+    /// <summary>Clears SQLite pools and deletes every temporary directory created by this test.</summary>
+    public void Dispose()
+    {
+        foreach (TempDatabaseDirectory directory in _tempDirectories)
+        {
+            directory.Dispose();
+        }
+
+        _tempDirectories.Clear();
+    }
+
+    /// <summary>
+    /// In-memory <see cref="IAuditEventSink"/> that records every call, so a test can prove the
+    /// write path did NOT touch the sink and that the drain batched what it did write.
+    /// </summary>
+    private sealed class CountingAuditSink : IAuditEventSink
+    {
+        private readonly Lock _gate = new();
+
+        /// <summary>Gets the events handed to the sink, in the order they were written.</summary>
+        public List<AuditEvent> Events { get; } = [];
+
+        /// <summary>Gets the size of each batch the sink was asked to insert.</summary>
+        public List<int> BatchSizes { get; } = [];
+
+        /// <summary>Gets the cutoffs the sink was asked to delete below.</summary>
+        public List<DateTimeOffset> DeleteCutoffs { get; } = [];
+
+        /// <summary>Gets the number of <see cref="InsertBatchAsync"/> calls.</summary>
+        public int InsertBatchCalls => BatchSizes.Count;
+
+        /// <summary>Gets the number of <see cref="EnsureInitializedAsync"/> calls.</summary>
+        public int EnsureInitializedCalls { get; private set; }
+
+        /// <inheritdoc />
+        public Task EnsureInitializedAsync(CancellationToken cancellationToken)
+        {
+            lock (_gate)
+            {
+                EnsureInitializedCalls++;
+            }
+
+            return Task.CompletedTask;
+        }
+
+        /// <inheritdoc />
+        public Task InsertAsync(AuditEvent auditEvent, CancellationToken cancellationToken) =>
+            InsertBatchAsync([auditEvent], cancellationToken);
+
+        /// <inheritdoc />
+        public Task InsertBatchAsync(IReadOnlyList<AuditEvent> auditEvents, CancellationToken cancellationToken)
+        {
+            lock (_gate)
+            {
+                BatchSizes.Add(auditEvents.Count);
+                Events.AddRange(auditEvents);
+            }
+
+            return Task.CompletedTask;
+        }
+
+        /// <inheritdoc />
+        public Task<int> DeleteOlderThanAsync(DateTimeOffset cutoffUtc, CancellationToken cancellationToken)
+        {
+            lock (_gate)
+            {
+                DeleteCutoffs.Add(cutoffUtc);
+            }
+
+            return Task.FromResult(0);
+        }
+    }
+}