fix(site-call-audit): reconciliation pull serves only un-acked tracking rows (node-local ack ledger), batched page upsert, prune removed sites' cursors (review 2026-10-21 06/PERF-2 + lane H follow-up)

This commit is contained in:
Joseph Doherty
2026-10-22 09:35:30 -04:00
parent e69be1654f
commit 88273693f9
12 changed files with 789 additions and 10 deletions
@@ -416,6 +416,54 @@ public class SiteAuditTelemetryActorTests : TestKit
Assert.Equal(expectedIds, emittedEventIds);
}
/// <summary>
/// Verifies that the tracking-row versions central ACCEPTED are recorded as central acks
/// in the tracking store — and only those — so the SiteCalls reconciliation pull stops
/// re-serving them (review 2026-10-21 06/PERF-2).
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task CachedDrain_AcceptedPackets_AreRecordedAsCentralAcks()
{
var acceptedRow = NewCachedEvent(AuditKind.CachedSubmit);
var refusedRow = NewCachedEvent(AuditKind.CachedSubmit);
_queue.ReadPendingAsync(Arg.Any<int>(), Arg.Any<CancellationToken>())
.Returns(Task.FromResult<IReadOnlyList<AuditEvent>>(Array.Empty<AuditEvent>()));
_queue.ReadPendingCachedTelemetryAsync(Arg.Any<int>(), Arg.Any<CancellationToken>())
.Returns(
Task.FromResult<IReadOnlyList<AuditEvent>>(new[] { acceptedRow, refusedRow }),
Task.FromResult<IReadOnlyList<AuditEvent>>(Array.Empty<AuditEvent>()));
var acceptedTid = new TrackedOperationId(acceptedRow.CorrelationId!.Value);
var refusedTid = new TrackedOperationId(refusedRow.CorrelationId!.Value);
var acceptedSnapshot = NewSnapshot(acceptedTid) with
{
UpdatedAtUtc = new DateTime(2026, 5, 20, 10, 0, 7, DateTimeKind.Utc),
};
_trackingStore.GetStatusAsync(acceptedTid, Arg.Any<CancellationToken>())
.Returns(Task.FromResult<TrackingStatusSnapshot?>(acceptedSnapshot));
_trackingStore.GetStatusAsync(refusedTid, Arg.Any<CancellationToken>())
.Returns(Task.FromResult<TrackingStatusSnapshot?>(NewSnapshot(refusedTid)));
_client.IngestCachedTelemetryAsync(Arg.Any<CachedTelemetryBatch>(), Arg.Any<CancellationToken>())
.Returns(_ =>
{
var ack = new IngestAck();
ack.AcceptedEventIds.Add(acceptedRow.EventId.ToString());
return Task.FromResult(ack);
});
CreateActorWithCachedDrain();
await AwaitAssertAsync(async () =>
{
await _trackingStore.Received(1).RecordCentralAcksAsync(
Arg.Is<IReadOnlyDictionary<TrackedOperationId, DateTime>>(d =>
d.Count == 1 && d[acceptedTid] == acceptedSnapshot.UpdatedAtUtc),
Arg.Any<CancellationToken>());
}, TimeSpan.FromSeconds(5));
}
/// <summary>Verifies that a cached row with no tracking snapshot past the grace period is abandoned while a valid row still flows.</summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
@@ -929,6 +929,120 @@ public class SiteCallAuditRepositoryTests : IClassFixture<MsSqlMigrationFixture>
Assert.DoesNotContain(perNode, n => n.SourceNode is null);
}
// --- UpsertManyAsync (review 2026-10-21 06/PERF-2) ----------------------
/// <summary>
/// Verifies that a batched upsert applies exactly the per-row monotonic semantics: fresh
/// rows insert, a higher rank advances, a lower rank is a no-op, and a page larger than
/// one command chunk is fully applied — in a handful of round trips, not one per row.
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[SkippableFact]
public async Task UpsertManyAsync_AppliesMonotonicSemantics_InFewRoundTrips()
{
Skip.IfNot(_fixture.Available, _fixture.SkipReason);
var site = NewSiteId();
var now = DateTime.UtcNow;
var advance = TrackedOperationId.New();
var regress = TrackedOperationId.New();
await using (var seed = CreateContext())
{
var seedRepo = new SiteCallAuditRepository(seed);
await seedRepo.UpsertAsync(NewRow(advance, site, status: "Submitted", createdAtUtc: now));
await seedRepo.UpsertAsync(NewRow(regress, site, status: "Delivered", createdAtUtc: now,
terminal: true, terminalAtUtc: now));
}
var fresh = Enumerable.Range(0, 300).Select(_ => TrackedOperationId.New()).ToList();
var page = fresh.Select(id => NewRow(id, site, status: "Attempted", retryCount: 1, createdAtUtc: now))
.Append(NewRow(advance, site, status: "Delivered", createdAtUtc: now, terminal: true, terminalAtUtc: now))
.Append(NewRow(regress, site, status: "Attempted", retryCount: 9, createdAtUtc: now))
.ToList();
var counter = new NonQueryCounter();
await using (var context = CreateContext(counter))
{
await new SiteCallAuditRepository(context).UpsertManyAsync(page);
}
Assert.True(counter.Count <= 5, $"UpsertManyAsync issued {counter.Count} commands for {page.Count} rows");
await using var read = CreateContext();
var stored = await read.Set<SiteCall>().Where(s => s.SourceSite == site).ToListAsync();
Assert.Equal(302, stored.Count);
Assert.All(stored.Where(s => fresh.Contains(s.TrackedOperationId)), s => Assert.Equal("Attempted", s.Status));
Assert.Equal("Delivered", stored.Single(s => s.TrackedOperationId == advance).Status);
var kept = stored.Single(s => s.TrackedOperationId == regress);
Assert.Equal("Delivered", kept.Status);
Assert.Equal(0, kept.RetryCount);
}
/// <summary>
/// Verifies that a row another site owns still fails the batch with the ownership error,
/// while every legitimate row of the page is applied (the chunk falls back to per-row).
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[SkippableFact]
public async Task UpsertManyAsync_OwnershipViolation_StillThrows_AfterApplyingTheRestOfThePage()
{
Skip.IfNot(_fixture.Available, _fixture.SkipReason);
var owner = NewSiteId();
var attacker = NewSiteId();
var owned = TrackedOperationId.New();
await using (var seed = CreateContext())
{
await new SiteCallAuditRepository(seed).UpsertAsync(NewRow(owned, owner, status: "Submitted"));
}
var good1 = TrackedOperationId.New();
var good2 = TrackedOperationId.New();
var page = new List<SiteCall>
{
NewRow(good1, attacker, status: "Submitted"),
NewRow(owned, attacker, status: "Delivered", terminal: true),
NewRow(good2, attacker, status: "Submitted"),
};
await using (var context = CreateContext())
{
var failure = await Assert.ThrowsAsync<Microsoft.Data.SqlClient.SqlException>(
() => new SiteCallAuditRepository(context).UpsertManyAsync(page));
Assert.Equal(51001, failure.Number);
}
await using var read = CreateContext();
var repo = new SiteCallAuditRepository(read);
Assert.NotNull(await repo.GetAsync(good1));
Assert.NotNull(await repo.GetAsync(good2));
var stored = await repo.GetAsync(owned);
Assert.Equal(owner, stored!.SourceSite);
Assert.Equal("Submitted", stored.Status);
}
private ScadaBridgeDbContext CreateContext(DbCommandInterceptor interceptor)
{
var options = new DbContextOptionsBuilder<ScadaBridgeDbContext>()
.UseSqlServer(_fixture.ConnectionString)
.AddInterceptors(interceptor)
.Options;
return new ScadaBridgeDbContext(options);
}
/// <summary>Counts the non-query commands a repository call issues.</summary>
private sealed class NonQueryCounter : DbCommandInterceptor
{
/// <summary>The number of non-query commands issued.</summary>
public int Count { get; private set; }
/// <inheritdoc />
public override ValueTask<InterceptionResult<int>> NonQueryExecutingAsync(
DbCommand command, CommandEventData eventData, InterceptionResult<int> result,
CancellationToken cancellationToken = default)
{
Count++;
return base.NonQueryExecutingAsync(command, eventData, result, cancellationToken);
}
}
// --- helpers ------------------------------------------------------------
private ScadaBridgeDbContext CreateContext()
@@ -231,6 +231,9 @@ public class SiteCallAuditReconciliationTests : TestKit
/// <summary>Gets the number of upsert calls received.</summary>
public int UpsertCallCount { get; private set; }
/// <summary>Gets the row count of every batched (page) upsert received.</summary>
public List<int> UpsertManyPageSizes { get; } = new();
/// <inheritdoc />
public Task UpsertAsync(SiteCall siteCall, CancellationToken ct = default)
{
@@ -239,6 +242,23 @@ public class SiteCallAuditReconciliationTests : TestKit
return Task.CompletedTask;
}
/// <inheritdoc />
public Task UpsertManyAsync(IReadOnlyList<SiteCall> siteCalls, CancellationToken ct = default)
{
lock (UpsertManyPageSizes)
{
UpsertManyPageSizes.Add(siteCalls.Count);
}
foreach (var siteCall in siteCalls)
{
UpsertCallCount++;
Upserted[siteCall.TrackedOperationId] = siteCall;
}
return Task.CompletedTask;
}
/// <inheritdoc />
public Task<SiteCall?> GetAsync(TrackedOperationId id, CancellationToken ct = default) =>
Task.FromResult(Upserted.TryGetValue(id, out var row) ? row : null);
@@ -706,6 +726,148 @@ public class SiteCallAuditReconciliationTests : TestKit
}
}
// ---------------------------------------------------------------------
// Review 2026-10-21 06/PERF-2: a pulled page is written through ONE batched
// upsert, not one repository call per row.
// ---------------------------------------------------------------------
/// <summary>Verifies that a reconciliation page is written through a single batched upsert.</summary>
[Fact]
public void ReconciliationTick_WritesEachPageThroughOneBatchedUpsert()
{
var siteId = "siteBatch";
var rows = Enumerable.Range(0, 3)
.Select(i => NewRow(TrackedOperationId.New(), siteId, updatedAtUtc: DateTime.UtcNow.AddSeconds(i)))
.ToArray();
var sites = new StaticEnumerator(new SiteEntry(siteId, "http://siteBatch:8083"));
var client = new ScriptedPullClient().Script(siteId,
new PullSiteCallsResponse(rows, MoreAvailable: false));
var repo = new RecordingRepo();
var actor = CreateActor(sites, client, repo, FastTickOptions());
try
{
AwaitAssert(
() =>
{
Assert.Equal(3, repo.Upserted.Count);
lock (repo.UpsertManyPageSizes)
{
Assert.Contains(3, repo.UpsertManyPageSizes);
}
},
duration: TimeSpan.FromSeconds(3),
interval: TimeSpan.FromMilliseconds(50));
}
finally
{
StopTicker(actor);
}
}
/// <summary>Enumerator whose site list a test can swap between ticks.</summary>
private sealed class MutableEnumerator : ISiteEnumerator
{
private volatile IReadOnlyList<SiteEntry> _sites;
private int _calls;
/// <summary>Creates the enumerator with an initial site list.</summary>
/// <param name="sites">The initial sites.</param>
public MutableEnumerator(params SiteEntry[] sites) => _sites = sites;
/// <summary>Gets the number of enumerations performed so far.</summary>
public int Calls => Volatile.Read(ref _calls);
/// <summary>Replaces the site list returned from the next enumeration on.</summary>
/// <param name="sites">The new sites.</param>
public void Set(params SiteEntry[] sites) => _sites = sites;
/// <inheritdoc />
public Task<IReadOnlyList<SiteEntry>> EnumerateAsync(CancellationToken ct = default)
{
Interlocked.Increment(ref _calls);
return Task.FromResult(_sites);
}
}
/// <summary>
/// Verifies that a site the enumerator stops returning has its cursor and pinned latch
/// pruned: the pinned site publishes Pinned=false, and when it reappears its pull restarts
/// from <see cref="DateTime.MinValue"/> (lane H follow-up to review 2026-10-21).
/// </summary>
[Fact]
public void ReconciliationTick_RemovedSite_PrunesCursorAndPinnedLatch()
{
var siteId = "siteGone";
var ts = new DateTime(2026, 5, 20, 10, 0, 0, DateTimeKind.Utc);
var rows = new[]
{
NewRow(TrackedOperationId.New(), siteId, updatedAtUtc: ts),
NewRow(TrackedOperationId.New(), siteId, updatedAtUtc: ts),
};
var entry = new SiteEntry(siteId, "http://siteGone:8083");
var sites = new MutableEnumerator(entry);
var client = new LegacyIgnoresAfterIdPullClient(rows);
var recorder = new RecordingPullClient(client);
var repo = new RecordingRepo();
// A dedicated probe, not TestActor: the re-added legacy site pins again, and that
// event must not land in StopTicker's ExpectTerminated.
var pinnedProbe = CreateTestProbe();
Sys.EventStream.Subscribe(pinnedProbe.Ref, typeof(SiteCallReconciliationPinnedChanged));
var actor = CreateActor(sites, recorder, repo, new SiteCallAuditOptions
{
ReconciliationIntervalOverride = TimeSpan.FromMilliseconds(100),
ReconciliationBatchSize = 2,
});
try
{
Assert.True(pinnedProbe.ExpectMsg<SiteCallReconciliationPinnedChanged>(TimeSpan.FromSeconds(5)).Pinned);
sites.Set();
var unpinned = pinnedProbe.ExpectMsg<SiteCallReconciliationPinnedChanged>(TimeSpan.FromSeconds(5));
Assert.Equal(siteId, unpinned.SiteId);
Assert.False(unpinned.Pinned);
var callsBeforeReturn = recorder.Calls.Count;
sites.Set(entry);
AwaitAssert(
() =>
{
var later = recorder.Calls.Skip(callsBeforeReturn).ToList();
Assert.NotEmpty(later);
Assert.Equal(DateTime.MinValue, later[0].SinceUtc);
},
duration: TimeSpan.FromSeconds(3),
interval: TimeSpan.FromMilliseconds(50));
}
finally
{
Sys.EventStream.Unsubscribe(pinnedProbe.Ref);
StopTicker(actor);
}
}
/// <summary>Wraps a pull client and records the cursor of every pull, thread-safely.</summary>
private sealed class RecordingPullClient(IPullSiteCallsClient inner) : IPullSiteCallsClient
{
private readonly List<(DateTime SinceUtc, string? AfterId)> _calls = new();
/// <summary>Gets a snapshot of every pull cursor recorded so far.</summary>
public IReadOnlyList<(DateTime SinceUtc, string? AfterId)> Calls
{
get { lock (_calls) { return _calls.ToList(); } }
}
/// <inheritdoc />
public Task<PullSiteCallsResponse> PullAsync(
string siteId, DateTime sinceUtc, string? afterId, int batchSize, CancellationToken ct)
{
lock (_calls) { _calls.Add((sinceUtc, afterId)); }
return inner.PullAsync(siteId, sinceUtc, afterId, batchSize, ct);
}
}
// ---------------------------------------------------------------------
// 9. The reconciliation drain runs OFF the mailbox, so ingest,
// query and KPI messages are answered while a long post-outage
@@ -116,6 +116,10 @@ internal sealed class SerializingSiteCallAuditRepository : ISiteCallAuditReposit
public Task UpsertAsync(SiteCall siteCall, CancellationToken ct = default) =>
RunAsync(() => _inner.UpsertAsync(siteCall, ct));
/// <inheritdoc />
public Task UpsertManyAsync(IReadOnlyList<SiteCall> siteCalls, CancellationToken ct = default) =>
RunAsync(() => _inner.UpsertManyAsync(siteCalls, ct));
/// <inheritdoc />
public Task<SiteCall?> GetAsync(TrackedOperationId id, CancellationToken ct = default) =>
RunAsync(() => _inner.GetAsync(id, ct));
@@ -1057,4 +1057,124 @@ public class OperationTrackingStoreTests : IDisposable
Assert.Equal(System.Data.ConnectionState.Closed, connection.State);
}
// ── Central-ack filter for the reconciliation pull (review 2026-10-21 06/PERF-2) ──
/// <summary>
/// Verifies that a row whose current version central has acknowledged through the
/// cached-telemetry push is no longer served by the reconciliation read, while
/// unacknowledged rows still are.
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task ReadChangedSince_SkipsRowsCentralAckedAtTheirCurrentVersion()
{
var (store, _) = CreateStore(nameof(ReadChangedSince_SkipsRowsCentralAckedAtTheirCurrentVersion));
await using var _store = store;
var acked = TrackedOperationId.New();
var unacked = TrackedOperationId.New();
await store.RecordEnqueueAsync(acked, nameof(AuditKind.ApiCallCached), "A", null, null, "node-a");
await store.RecordEnqueueAsync(unacked, nameof(AuditKind.ApiCallCached), "B", null, null, "node-a");
var snapshot = await store.GetStatusAsync(acked);
await store.RecordCentralAcksAsync(new Dictionary<TrackedOperationId, DateTime>
{
[acked] = snapshot!.UpdatedAtUtc,
});
var rows = await store.ReadChangedSinceAsync(DateTime.MinValue, batchSize: 100);
Assert.Equal(new[] { unacked }, rows.Select(r => r.TrackedOperationId).ToArray());
}
/// <summary>
/// Verifies that a row changed AFTER central acknowledged it is served again — the ack
/// covers one version, not the operation.
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task ReadChangedSince_ServesRowChangedAfterItsAck()
{
var (store, _) = CreateStore(nameof(ReadChangedSince_ServesRowChangedAfterItsAck));
await using var _store = store;
var id = TrackedOperationId.New();
await store.RecordEnqueueAsync(id, nameof(AuditKind.ApiCallCached), "A", null, null, "node-a");
var submitted = await store.GetStatusAsync(id);
await store.RecordCentralAcksAsync(new Dictionary<TrackedOperationId, DateTime>
{
[id] = submitted!.UpdatedAtUtc,
});
await Task.Delay(5); // a strictly later UpdatedAtUtc stamp
await store.RecordTerminalAsync(id, nameof(AuditStatus.Delivered), null, 200);
var rows = await store.ReadChangedSinceAsync(DateTime.MinValue, batchSize: 100);
var row = Assert.Single(rows);
Assert.Equal(nameof(AuditStatus.Delivered), row.Status);
}
/// <summary>
/// Verifies that an older ack never rolls back a newer one (acks are monotonic per row),
/// and that the ack ledger is pruned with the tracking rows it describes.
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task CentralAcks_AreMonotonic_AndPrunedWithTheirTrackingRow()
{
var (store, dataSource) = CreateStore(nameof(CentralAcks_AreMonotonic_AndPrunedWithTheirTrackingRow));
await using var _store = store;
var id = TrackedOperationId.New();
await store.RecordEnqueueAsync(id, nameof(AuditKind.ApiCallCached), "A", null, null, "node-a");
await store.RecordTerminalAsync(id, nameof(AuditStatus.Delivered), null, 200);
var terminal = await store.GetStatusAsync(id);
await store.RecordCentralAcksAsync(new Dictionary<TrackedOperationId, DateTime> { [id] = terminal!.UpdatedAtUtc });
await store.RecordCentralAcksAsync(new Dictionary<TrackedOperationId, DateTime> { [id] = terminal.CreatedAtUtc.AddSeconds(-1) });
Assert.Empty(await store.ReadChangedSinceAsync(DateTime.MinValue, batchSize: 100));
// Age the terminal row past retention and purge: the ack row goes with it.
await store.FlushAsync();
using (var connection = OpenVerifierConnection(dataSource))
using (var cmd = connection.CreateCommand())
{
cmd.CommandText = "UPDATE OperationTracking SET TerminalAtUtc = $old;";
cmd.Parameters.AddWithValue("$old", DateTime.UtcNow.AddDays(-30).ToString("o"));
cmd.ExecuteNonQuery();
}
await store.PurgeTerminalAsync(DateTime.UtcNow.AddDays(-7));
using (var connection = OpenVerifierConnection(dataSource))
using (var cmd = connection.CreateCommand())
{
cmd.CommandText = "SELECT COUNT(*) FROM OperationTrackingCentralAck;";
Assert.Equal(0L, (long)cmd.ExecuteScalar()!);
}
}
/// <summary>
/// Verifies the ack ledger is its own table, not a column on the LocalDb-replicated
/// <c>OperationTracking</c> table (whose capture triggers are built from its column list).
/// Being node-local, a standby that takes over has no ack rows and serves every row once.
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task CentralAckLedger_IsADistinctNodeLocalTable_NotAColumnOnTheReplicatedTable()
{
var (store, dataSource) = CreateStore(nameof(CentralAckLedger_IsADistinctNodeLocalTable_NotAColumnOnTheReplicatedTable));
await using var _store = store;
await store.FlushAsync();
using var connection = OpenVerifierConnection(dataSource);
using var cmd = connection.CreateCommand();
cmd.CommandText = "PRAGMA table_info(OperationTracking);";
var columns = new List<string>();
using (var reader = cmd.ExecuteReader())
{
while (reader.Read()) columns.Add(reader.GetString(1));
}
Assert.DoesNotContain(columns, c => c.StartsWith("Acked", StringComparison.Ordinal)
|| c.Contains("CentralAck", StringComparison.Ordinal));
cmd.CommandText = "SELECT COUNT(*) FROM sqlite_master WHERE type = 'table' AND name = 'OperationTrackingCentralAck';";
Assert.Equal(1L, (long)cmd.ExecuteScalar()!);
}
}