fix(auditlog): site audit DB onto the data volume; required path + soft flush

Closes WP1.2 of the arch-review remediation plan (finding #2, High): SqliteAuditWriterOptions.DatabasePath defaulted to CWD-relative "auditlog.db", which on the docker rig resolves onto the container's ephemeral overlayfs (not the mounted /app/data volume), silently discarding the pending audit forward-state backlog on every recreate; nothing in docker/ or docker-env2/ overrode it; FlushIntervalMs was validated but never read by the writer loop (one commit per event even at trickle rate); and no PRAGMA synchronous was set (SQLite's FULL default fsyncs every commit). - DatabasePath now has no default (mirrors ZB.MOM.WW.LocalDb's LocalDbOptions.Path) and is required pre-host for Site nodes only, via a new StartupValidator raw-config check (top-level "AuditLog:SiteWriter:DatabasePath", NOT nested under ScadaBridge: AddAuditLog binds that section off the configuration root). SqliteAuditWriterOptionsValidator deliberately does NOT check DatabasePath itself, because AddAuditLog runs its ValidateOnStart on both Central and Site composition roots but only Site nodes ever resolve the writer — checking it there would fail Central's boot too. - All 8 site-node appsettings under docker/ and docker-env2/ now set AuditLog:SiteWriter:DatabasePath to /app/data/auditlog.db (mounted volume, survives container recreate, same convention as LocalDb:Path); the local-dev base appsettings.Site.json sets ./data/auditlog.db to match. - The writer loop now honors FlushIntervalMs: after draining the immediately available burst, it keeps the transaction open (bounded by FlushIntervalMs from the first event) waiting for more trickle-rate events before committing, instead of flushing (and fsyncing) per event. - PRAGMA synchronous = NORMAL on the write connection — audit is best-effort by design (CLAUDE.md: "Audit-write failure NEVER aborts the user-facing action"), so NORMAL's narrower power-loss window is an acceptable trade for far fewer fsyncs; WAL mode still guarantees no corruption. - Tests: StartupValidator site-required/blank/central-exempt cases; writer trickle-load single-transaction coalescing + beyond-interval separate-transaction regression (new FlushCountForTests seam); options-validator doc updates reflecting the moved responsibility. Full suite runs green: AuditLog.Tests 368/368, Host.Tests 480/480. One-time migration note: the existing container-local auditlog.db (wherever it landed under CWD) is abandoned by this change, not migrated — already-forwarded rows are safe centrally (AuditLog is the durable copy), and any still-Pending rows on the abandoned path are lost once. This is the exact bug being fixed, not a new loss: those rows were already living outside the mounted volume and would not have survived the next container recreate regardless. Cross-reference docs/known-issues/2026-07-20-cached-telemetry-drain-hot-loop.md, which this placement bug caused.
2026-08-14 20:13:31 -04:00
parent ee193cd2bb
commit 2e4e41a8f7
17 changed files with 347 additions and 24 deletions
@@ -5,30 +5,30 @@ namespace ZB.MOM.WW.ScadaBridge.AuditLog.Tests.Site;
 /// <summary>
 /// Eager startup validation for <see cref="SqliteAuditWriterOptions"/>
 /// (arch-review 08 round 2 NF4). The site hot-path writer's channel/batch/flush
-/// knobs must be positive or the background writer task cannot make progress;
-/// an empty <c>DatabasePath</c> would leave the SQLite writer with nowhere to go.
+/// knobs must be positive or the background writer task cannot make progress.
 /// <c>BacklogPollIntervalSeconds</c> is deliberately NOT validated — a
 /// non-positive value has a documented fall-back-to-30s contract.
 /// </summary>
+/// <remarks>
+/// <c>DatabasePath</c> is intentionally NOT covered here (arch-review remediation
+/// WP1.2): it defaults to <c>""</c> (no CWD-relative default — mirrors
+/// <c>LocalDb:Path</c>), but this validator runs on both Central and Site
+/// composition roots via <c>ValidateOnStart</c>, and only Site nodes ever resolve
+/// the writer. The Site-only requirement is enforced pre-host by
+/// <c>StartupValidator</c> in ZB.MOM.WW.ScadaBridge.Host — see
+/// <c>StartupValidatorTests.SiteWithoutAuditLogDatabasePath_FailsValidation</c>.
+/// </remarks>
 public class SqliteAuditWriterOptionsValidatorTests
 {
    [Fact]
    public void DefaultOptions_AreValid()
    {
+        // Includes the empty DatabasePath default — this validator does not check
+        // it (see class remarks); only StartupValidator does, and only for Site nodes.
        var validator = new SqliteAuditWriterOptionsValidator();
        Assert.True(validator.Validate(null, new SqliteAuditWriterOptions()).Succeeded);
    }

-    [Fact]
-    public void EmptyDatabasePath_Fails()
-    {
-        var validator = new SqliteAuditWriterOptionsValidator();
-        var result = validator.Validate(null, new SqliteAuditWriterOptions { DatabasePath = "" });
-        Assert.False(result.Succeeded);
-        Assert.Contains(result.Failures!,
-            f => f.Contains(nameof(SqliteAuditWriterOptions.DatabasePath), StringComparison.Ordinal));
-    }
-
    [Fact]
    public void ZeroChannelCapacity_Fails()
    {
@@ -24,7 +24,8 @@ public class SqliteAuditWriterWriteTests
    private static (SqliteAuditWriter writer, string dataSource) CreateWriter(
        string testName,
        int? channelCapacity = null,
-        INodeIdentityProvider? nodeIdentity = null)
+        INodeIdentityProvider? nodeIdentity = null,
+        int? flushIntervalMs = null)
    {
        var dataSource = $"file:{testName}-{Guid.NewGuid():N}?mode=memory&cache=shared";
        var opts = new SqliteAuditWriterOptions { DatabasePath = dataSource };
@@ -32,6 +33,10 @@ public class SqliteAuditWriterWriteTests
        {
            opts.ChannelCapacity = cap;
        }
+        if (flushIntervalMs is int flush)
+        {
+            opts.FlushIntervalMs = flush;
+        }

        // Default identity provider returns null — existing tests pre-date
        // SourceNode stamping and have no expectation about it. New stamping
@@ -181,6 +186,69 @@ public class SqliteAuditWriterWriteTests
        Assert.Equal(1000, Convert.ToInt64(sidecarCmd.ExecuteScalar()));
    }

+    // ----- FlushIntervalMs soft-flush coalescing (arch-review remediation WP1.2) ----- //
+
+    /// <summary>
+    /// A trickle of events — well under <see cref="SqliteAuditWriterOptions.BatchSize"/>,
+    /// spaced closer together than <see cref="SqliteAuditWriterOptions.FlushIntervalMs"/> —
+    /// must coalesce into ONE transaction rather than fsyncing once per event. This is the
+    /// bug WP1.2 fixes: <c>FlushIntervalMs</c> was validated but never read by the writer
+    /// loop, so every trickle-rate write incurred its own commit (and, under SQLite's
+    /// default synchronous=FULL, its own fsync).
+    /// </summary>
+    [Fact]
+    public async Task WriteAsync_TrickleLoad_CoalescesIntoOneTransaction()
+    {
+        var (writer, dataSource) = CreateWriter(
+            nameof(WriteAsync_TrickleLoad_CoalescesIntoOneTransaction),
+            flushIntervalMs: 500);
+        await using var _ = writer;
+
+        const int count = 5;
+        var writeTasks = new List<Task>(count);
+        for (int i = 0; i < count; i++)
+        {
+            writeTasks.Add(writer.WriteAsync(NewEvent()));
+            await Task.Delay(15); // spaced well under the 500ms flush window
+        }
+        await Task.WhenAll(writeTasks);
+
+        using var connection = OpenVerifierConnection(dataSource);
+        using var cmd = connection.CreateCommand();
+        cmd.CommandText = "SELECT COUNT(*) FROM audit_event;";
+        Assert.Equal(count, Convert.ToInt64(cmd.ExecuteScalar()));
+
+        // The defining assertion: all 5 trickled-in writes landed in a single
+        // FlushBatch transaction, not up to 5 separate commits.
+        Assert.Equal(1, writer.FlushCountForTests);
+    }
+
+    /// <summary>
+    /// The flip side: two events spaced FURTHER apart than
+    /// <see cref="SqliteAuditWriterOptions.FlushIntervalMs"/> must NOT be held open
+    /// waiting for a partner — the deadline bounds worst-case added latency, it does
+    /// not turn into an unbounded debounce.
+    /// </summary>
+    [Fact]
+    public async Task WriteAsync_EventsSpacedBeyondFlushInterval_FlushSeparately()
+    {
+        var (writer, dataSource) = CreateWriter(
+            nameof(WriteAsync_EventsSpacedBeyondFlushInterval_FlushSeparately),
+            flushIntervalMs: 50);
+        await using var _ = writer;
+
+        await writer.WriteAsync(NewEvent());
+        await Task.Delay(300); // well beyond the 50ms flush window
+        await writer.WriteAsync(NewEvent());
+
+        using var connection = OpenVerifierConnection(dataSource);
+        using var cmd = connection.CreateCommand();
+        cmd.CommandText = "SELECT COUNT(*) FROM audit_event;";
+        Assert.Equal(2, Convert.ToInt64(cmd.ExecuteScalar()));
+
+        Assert.Equal(2, writer.FlushCountForTests);
+    }
+
    [Fact]
    public async Task WriteAsync_DuplicateEventId_FirstWriteWins_NoException()
    {
@@ -27,10 +27,12 @@ public class SiteHealthEndpointTests : IDisposable
    private readonly List<IDisposable> _disposables = new();
    private readonly Dictionary<string, string?> _previousEnv = new(StringComparer.Ordinal);
    private readonly string _tempDbPath;
+    private readonly string _tempAuditDbPath;

    public SiteHealthEndpointTests()
    {
        _tempDbPath = Path.Combine(Path.GetTempPath(), $"scadabridge_health_ep_{Guid.NewGuid()}.db");
+        _tempAuditDbPath = Path.Combine(Path.GetTempPath(), $"scadabridge_health_ep_audit_{Guid.NewGuid()}.db");

        // Whole-key env overrides, the sanctioned path: supplying GrpcPsk concretely makes the
        // pre-host secrets expander skip appsettings.Site.json's ${secret:SB-GRPC-PSK-site-1}
@@ -50,6 +52,11 @@ public class SiteHealthEndpointTests : IDisposable
        SetEnv("ScadaBridge__Cluster__SeedNodes__1", "akka.tcp://scadabridge@localhost:18085");
        SetEnv("ScadaBridge__Communication__GrpcPsk", "test-psk-0123456789");
        SetEnv("LocalDb__Path", _tempDbPath);
+        // arch-review remediation WP1.2: SqliteAuditWriterOptions.DatabasePath has no default
+        // and StartupValidator now requires it for Site nodes — same reason LocalDb__Path is
+        // overridden above (appsettings.Site.json's own default is CWD-relative and would
+        // otherwise litter the test working directory when SiteAuditBacklogReporter probes it).
+        SetEnv("AuditLog__SiteWriter__DatabasePath", _tempAuditDbPath);
    }

    private void SetEnv(string key, string? value)
@@ -71,6 +78,7 @@ public class SiteHealthEndpointTests : IDisposable
        }

        try { File.Delete(_tempDbPath); } catch { /* best effort */ }
+        try { File.Delete(_tempAuditDbPath); } catch { /* best effort */ }

        GC.SuppressFinalize(this);
    }
@@ -44,6 +44,10 @@ public class StartupValidatorTests
        // Phase 4: gRPC (CentralControlService) is the only site→central transport, so a Site
        // node must list at least one central gRPC endpoint to dial (no Akka fallback remains).
        ["ScadaBridge:Communication:CentralGrpcEndpoints:0"] = "http://central-a:8083",
+        // arch-review remediation WP1.2: the site hot-path audit writer's SQLite file has no
+        // default path (mirrors LocalDb:Path) — required so it lands on the mounted data volume,
+        // not the container's ephemeral overlayfs.
+        ["AuditLog:SiteWriter:DatabasePath"] = "/app/data/auditlog.db",
    };

    [Fact]
@@ -124,6 +128,43 @@ public class StartupValidatorTests
        Assert.Null(Record.Exception(() => StartupValidator.Validate(config)));
    }

+    [Fact]
+    public void SiteWithoutAuditLogDatabasePath_FailsValidation()
+    {
+        // arch-review remediation WP1.2: SqliteAuditWriterOptions.DatabasePath has no default
+        // (mirrors LocalDb:Path). An unset value used to fall back to a bare "auditlog.db"
+        // resolved relative to CWD — on the docker rig, the container's ephemeral overlayfs —
+        // so the node booted, looked healthy, and lost its pending audit backlog on every
+        // recreate. Fail fast at boot instead.
+        var values = ValidSiteConfig();
+        values.Remove("AuditLog:SiteWriter:DatabasePath");
+        var config = BuildConfig(values);
+
+        var ex = Assert.Throws<InvalidOperationException>(() => StartupValidator.Validate(config));
+        Assert.Contains("DatabasePath", ex.Message);
+    }
+
+    [Fact]
+    public void SiteWithBlankAuditLogDatabasePath_FailsValidation()
+    {
+        var values = ValidSiteConfig();
+        values["AuditLog:SiteWriter:DatabasePath"] = "   ";
+        var config = BuildConfig(values);
+
+        var ex = Assert.Throws<InvalidOperationException>(() => StartupValidator.Validate(config));
+        Assert.Contains("DatabasePath", ex.Message);
+    }
+
+    [Fact]
+    public void CentralWithoutAuditLogDatabasePath_PassesValidation()
+    {
+        // AddAuditLog binds SqliteAuditWriterOptions on both roles, but only Site nodes ever
+        // resolve the writer — the requirement must not fire for Central.
+        var config = BuildConfig(ValidCentralConfig());
+
+        Assert.Null(Record.Exception(() => StartupValidator.Validate(config)));
+    }
+
    [Fact]
    public void MissingRole_FailsValidation()
    {