dohertj2/lmxopcua
1
0
Fork 0
Code Issues 43 Pull Requests Actions Packages Projects Releases Wiki Activity

fix(alarms): never drop a comment-trail entry on pair divergence (E5 review r1)

Browse Source 
I-1: a node whose in-memory trail is one short of the stored trail (it missed
a command the peer applied, whose entry then replicated in) silently dropped
its own next entry — in failover, the survivor's newest ack — because the
positional "past MAX(seq)" rule treated it as already stored.

SaveAsync now reconciles the last 16 in-memory entries against the stored
rows from that position on, by content (Kind/User/Text, timestamps within a
5-minute skew window; matched rows are consumed so repeats count). The peer's
copy of the same command is recognised and not re-appended; an unmatched
entry is inserted at its own ordinal when free, otherwise appended at
MAX(seq)+1 with a Warning — kept, never silent. Bounded read, constant write.

m1: MigrateInlineComments copies only — it no longer UPDATEs the condition
row (a fresh-HLC re-stamp could beat a newer peer ack under LWW); the next
save clears comments_json. m2: it returns unparseable alarm ids and OnReady
logs a Warning per id (+ an Information tally). m3/m4: documented in the
store remarks (Remove vs lagging peer; in-memory index == durable ordinal).

Tests: store-level failover sequence (missed command -> survivor's ack and
next entry persisted once, re-save writes 0 rows, one Warning) with the
dual-write positive control (peer copy present -> 0 rows, no Warning) and a
repeated-identical-comment case; a loopback pair failover test (link down,
survivor acks, rejoin -> both entries on both peers, held); migration
no-row-rewrite, partial fill and unparseable reporting; OnReady Warning.
Both failover tests fail against the round-0 store.

Refs #748
Claude-Session: https://claude.ai/code/session_01Ub9hGmYLQvn9XETzw7CMsT
This commit is contained in:
Joseph Doherty
2026-10-22 16:58:46 -04:00
parent 13f1357ad2
commit dad28d37a2
6 changed files with 490 additions and 82 deletions
Download Patch File Download Diff File Expand all files Collapse all files
tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/LocalDb/AlarmConditionCommentConvergenceTests.cs
+59
View File
@@ -70,6 +70,65 @@ public sealed class AlarmConditionCommentConvergenceTests
(await storeA.LoadAsync("eq/alarm-1", Ct))!.Comments.ShouldBe(appended.Comments);
}
[Fact]
public async Task Failover_AfterAMissedCommand_BothTheMissedEntryAndTheSurvivorsNextEntry_ReachBothPeers()
{
// Review I-1, end to end over the real pair:
// 1. a shared trail on both nodes;
// 2. an AddComment reaches only node A (B's command delivery failed) — A's entry replicates
// into B's table, but B's engine never applied it, so B's IN-MEMORY trail is one short;
// 3. A goes away (link down) and the operator acks on the survivor B — B's in-memory Ack
// collides with A's entry at the same ordinal;
// 4. the pair rejoins.
// Both entries must survive on both peers. Before the fix B's Ack was silently dropped.
await using var pair = new LocalDbPairHarness();
await pair.StartAsync();
var shared = AlarmConditionState.Fresh("eq/alarm-fo", T0) with
{
Active = AlarmActiveState.Active,
Acked = AlarmAckedState.Unacknowledged,
};
for (var i = 0; i < 3; i++)
shared = Part9StateMachine.ApplyAddComment(shared, "jane", $"note {i}", T0.AddMinutes(i)).State;
await Store(pair.A).SaveAsync(shared, Ct);
await LocalDbPairHarness.WaitUntilAsync(
async () => await CommentCountAsync(pair.B, "eq/alarm-fo") == 3,
"node B to hold the shared trail");
var onlyOnA = Part9StateMachine.ApplyAddComment(shared, "jane", "seen on A only", T0.AddHours(1)).State;
await Store(pair.A).SaveAsync(onlyOnA, Ct);
await LocalDbPairHarness.WaitUntilAsync(
async () => await CommentCountAsync(pair.B, "eq/alarm-fo") == 4,
"node A's entry to replicate into node B's table");
await pair.StopPassiveAsync();
// B's engine still holds the 3-entry trail it applied; the operator acks there.
var ackOnB = Part9StateMachine.ApplyAcknowledge(shared, "bob", "acked on B", T0.AddHours(2)).State;
await Store(pair.B).SaveAsync(ackOnB, Ct);
await pair.RestartPairAsync();
await LocalDbPairHarness.WaitUntilAsync(
async () => await CommentCountAsync(pair.A, "eq/alarm-fo") == 5
&& await CommentCountAsync(pair.B, "eq/alarm-fo") == 5,
"both nodes to hold the shared trail + A's missed-by-B entry + B's ack");
var onA = (await Store(pair.A).LoadAsync("eq/alarm-fo", Ct))!;
var onB = (await Store(pair.B).LoadAsync("eq/alarm-fo", Ct))!;
onA.Comments.ShouldBe(onB.Comments);
onA.Comments[3].ShouldBe(onlyOnA.Comments[3]);
onA.Comments[4].ShouldBe(ackOnB.Comments[3]);
// Held, not merely reached: nothing late duplicates either entry.
(await LocalDbPairHarness.HeldWithinAsync(
async () => await CommentCountAsync(pair.A, "eq/alarm-fo") != 5
|| await CommentCountAsync(pair.B, "eq/alarm-fo") != 5,
TimeSpan.FromSeconds(2)))
.ShouldBeFalse();
}
[Fact]
public async Task BothNodesRecordingTheSameEntry_ConvergeToOneEntry_NotTwo()
{
tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/LocalDbSetupTests.cs
+44 -2
View File
@@ -250,8 +250,11 @@ public sealed class LocalDbSetupTests : IDisposable
(await ScalarAsync(db, "SELECT COUNT(*) FROM alarm_condition_comment WHERE scripted_alarm_id = 'eq/alarm-legacy'"))
.ShouldBe(2);
(await ScalarAsync(db, "SELECT COUNT(*) FROM alarm_condition_state WHERE comments_json <> '[]'"))
.ShouldBe(0);
// The condition row itself is NOT rewritten (review m1): a migration UPDATE would re-stamp it
// with a fresh HLC and could beat a newer peer state under LWW. Only the seeding INSERT is in
// the oplog for it; the alarm's next save clears the inline column.
(await ScalarAsync(db, "SELECT COUNT(*) FROM __localdb_oplog WHERE table_name = 'alarm_condition_state'"))
.ShouldBe(1);
// Captured: the migration ran after RegisterReplicated, so the moved entries reach the peer.
(await ScalarAsync(db, "SELECT COUNT(*) FROM __localdb_oplog WHERE table_name = 'alarm_condition_comment'"))
.ShouldBe(2);
@@ -397,6 +400,45 @@ public sealed class LocalDbSetupTests : IDisposable
sink.Events.Count(e => e.Level == LogEventLevel.Information).ShouldBe(1);
}
[Fact]
public async Task OnReady_WarnsOncePerAlarmWhoseInlineCommentTrailIsUnreadable()
{
// Review m2: an unmigratable history must be visible, not skipped silently on every boot.
var first = Boot();
await first.ExecuteAsync(
"""
INSERT INTO alarm_condition_state
(scripted_alarm_id, enabled_state, acked_state, confirmed_state, shelving_state,
comments_json, updated_at_utc)
VALUES (@Id, 'Enabled', 'Acknowledged', 'Confirmed', 'Unshelved', @Json, '2026-06-10T10:05:00.0000000Z')
""",
new { Id = "eq/alarm-bad", Json = "{not json" },
TestContext.Current.CancellationToken);
await first.ExecuteAsync(
"""
INSERT INTO alarm_condition_state
(scripted_alarm_id, enabled_state, acked_state, confirmed_state, shelving_state,
comments_json, updated_at_utc)
VALUES (@Id, 'Enabled', 'Acknowledged', 'Confirmed', 'Unshelved', @Json, '2026-06-10T10:05:00.0000000Z')
""",
new
{
Id = "eq/alarm-good",
Json = """[{"timestampUtc":"2026-06-10T10:00:00Z","user":"jane","kind":"AddComment","text":"a"}]""",
},
TestContext.Current.CancellationToken);
var sink = new CollectingSink();
Boot(replication: null, logger: BuildLogger(sink));
var warnings = sink.Events.Where(e => e.Level == LogEventLevel.Warning).ToList();
warnings.Count.ShouldBe(1);
warnings[0].RenderMessage().ShouldContain("eq/alarm-bad");
// Positive control: the readable row DID move, and said so.
sink.Events.Count(e => e.Level == LogEventLevel.Information && e.RenderMessage().Contains("copied"))
.ShouldBe(1);
}
[Fact]
public void DisablingReplication_SaysNothingWhenThereWasNothingToClean()
{
tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/ScriptedAlarms/LocalDbAlarmCommentAuditTests.cs
+156 -16
View File
@@ -252,7 +252,12 @@ public sealed class LocalDbAlarmCommentAuditTests : IDisposable
var rewritten = original with { Comments = original.Comments.SetItem(1, new AlarmComment(T0, "eve", "AddComment", "forged")) };
await store.SaveAsync(rewritten, Ct);
(await store.LoadAsync("alarm-ao", Ct))!.Comments.ShouldBe(original.Comments);
// The stored entry at ordinal 1 is untouched; the unrecognised local entry is kept by
// appending it (never dropped), not by overwriting history.
var loaded = (await store.LoadAsync("alarm-ao", Ct))!.Comments;
loaded.Take(3).ShouldBe(original.Comments);
loaded.Count.ShouldBe(4);
loaded[3].Text.ShouldBe("forged");
}
// ---- back-compat + migration -----------------------------------------------------------
@@ -306,19 +311,27 @@ public sealed class LocalDbAlarmCommentAuditTests : IDisposable
}
[Fact]
public async Task Migration_MovesInlineCommentsToTheAuditTable_AndClearsTheInlineColumn()
public async Task Migration_CopiesInlineCommentsToTheAuditTable_AndNeverRewritesTheConditionRow()
{
await InsertOldShapeRowAsync("alarm-m1");
await InsertOldShapeRowAsync("alarm-m2");
await InsertOldShapeRowAsync("alarm-empty", "[]");
int migrated;
var before = await OplogHighWaterAsync();
AlarmConditionStateSchema.InlineCommentMigrationResult result;
using (var connection = _db.CreateConnection())
migrated = AlarmConditionStateSchema.MigrateInlineComments(connection);
result = AlarmConditionStateSchema.MigrateInlineComments(connection);
migrated.ShouldBe(2);
result.RowsMoved.ShouldBe(2);
result.UnparseableAlarmIds.ShouldBeEmpty();
(await ScalarAsync("SELECT COUNT(*) FROM alarm_condition_comment")).ShouldBe(6);
(await ScalarAsync("SELECT COUNT(*) FROM alarm_condition_state WHERE comments_json <> '[]'")).ShouldBe(0);
// Review m1: the migration must not touch the condition row. A full-row UPDATE re-stamps it
// with a fresh HLC and can revert a newer peer state (e.g. an ack) under LWW. The next save
// (the engine's boot save) resets the column instead.
(await OplogEntriesAboveAsync(before, AlarmConditionStateSchema.StateTable)).ShouldBe(0);
(await OplogEntriesAboveAsync(before, AlarmConditionStateSchema.CommentsTable)).ShouldBe(6,
"positive control: the copied entries were captured");
ShouldBeTheOldShapeState(await NewStore().LoadAsync("alarm-m1", Ct), "alarm-m1");
ShouldBeTheOldShapeState(await NewStore().LoadAsync("alarm-m2", Ct), "alarm-m2");
@@ -330,11 +343,11 @@ public sealed class LocalDbAlarmCommentAuditTests : IDisposable
{
await InsertOldShapeRowAsync("alarm-idem");
using (var connection = _db.CreateConnection())
AlarmConditionStateSchema.MigrateInlineComments(connection).ShouldBe(1, "positive control");
AlarmConditionStateSchema.MigrateInlineComments(connection).RowsMoved.ShouldBe(1, "positive control");
var before = await OplogHighWaterAsync();
using (var connection = _db.CreateConnection())
AlarmConditionStateSchema.MigrateInlineComments(connection).ShouldBe(0);
AlarmConditionStateSchema.MigrateInlineComments(connection).RowsMoved.ShouldBe(0);
(await OplogHighWaterAsync()).ShouldBe(before, "a re-run must write nothing");
(await ScalarAsync("SELECT COUNT(*) FROM alarm_condition_comment")).ShouldBe(3);
@@ -342,24 +355,151 @@ public sealed class LocalDbAlarmCommentAuditTests : IDisposable
}
[Fact]
public async Task Migration_OverAPartiallyMigratedRow_DoesNotDuplicateOrReorder()
public async Task Migration_OverAPartiallyMigratedRow_FillsOnlyTheMissingOrdinals()
{
// An inline row reappearing after its comments were already moved (e.g. a restored backup):
// the ordinals already held are kept, nothing is duplicated.
// Only ordinal 0 made it across (e.g. a restored backup): the run fills 1 and 2, keeps 0,
// duplicates nothing.
await InsertOldShapeRowAsync("alarm-partial");
using (var connection = _db.CreateConnection())
AlarmConditionStateSchema.MigrateInlineComments(connection);
await _db.ExecuteAsync(
"UPDATE alarm_condition_state SET comments_json = @Json WHERE scripted_alarm_id = 'alarm-partial'",
new { Json = OldShapeCommentsJson }, Ct);
AlarmConditionStateSchema.InsertCommentSql,
new
{
Id = "alarm-partial", Seq = 0,
Ts = AlarmConditionStateSchema.FormatTimestamp(OldShapeComments[0].TimestampUtc),
User = OldShapeComments[0].User, Kind = OldShapeComments[0].Kind, Text = OldShapeComments[0].Text,
},
Ct);
using (var connection = _db.CreateConnection())
AlarmConditionStateSchema.MigrateInlineComments(connection).ShouldBe(1);
AlarmConditionStateSchema.MigrateInlineComments(connection).RowsMoved.ShouldBe(1);
(await ScalarAsync("SELECT COUNT(*) FROM alarm_condition_comment")).ShouldBe(3);
ShouldBeTheOldShapeState(await NewStore().LoadAsync("alarm-partial", Ct), "alarm-partial");
}
[Fact]
public async Task Migration_ReportsAnUnparseableInlineTrail_AndLeavesItAlone()
{
// Review m2: an unreadable trail must surface (OnReady logs a Warning per id), not be
// skipped silently on every boot.
await InsertOldShapeRowAsync("alarm-bad", "{not json");
await InsertOldShapeRowAsync("alarm-good");
AlarmConditionStateSchema.InlineCommentMigrationResult result;
using (var connection = _db.CreateConnection())
result = AlarmConditionStateSchema.MigrateInlineComments(connection);
result.UnparseableAlarmIds.ShouldBe(["alarm-bad"]);
result.RowsMoved.ShouldBe(1, "positive control: the good row still moved");
(await _db.QueryAsync(
"SELECT comments_json FROM alarm_condition_state WHERE scripted_alarm_id = 'alarm-bad'",
r => r.GetString(0), null, Ct))[0]
.ShouldBe("{not json");
}
// ---- divergence / failover (review I-1) -------------------------------------------------
/// <summary>Captures log entries so a divergence Warning can be asserted, not inferred.</summary>
private sealed class CapturingLogger : Microsoft.Extensions.Logging.ILogger<LocalDbAlarmConditionStateStore>
{
public List<(Microsoft.Extensions.Logging.LogLevel Level, string Message)> Entries { get; } = [];
public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
public bool IsEnabled(Microsoft.Extensions.Logging.LogLevel logLevel) => true;
public void Log<TState>(
Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId,
TState state, Exception? exception, Func<TState, Exception?, string> formatter)
{
lock (Entries) Entries.Add((logLevel, formatter(state, exception)));
}
public int Warnings => Entries.Count(e => e.Level == Microsoft.Extensions.Logging.LogLevel.Warning);
}
[Fact]
public async Task Failover_TheSurvivorsNextEntry_IsPersisted_AfterItMissedACommandThePeerApplied()
{
// The I-1 sequence on node B's database:
// 1. a shared trail of 5 entries;
// 2. an AddComment reaches only node A (B's command delivery failed once) and A's row at
// ordinal 5 replicates into B's table — B's IN-MEMORY trail still has 5 entries;
// 3. A dies and the operator acks on B: B's in-memory Ack sits at index 5, colliding with
// A's entry at ordinal 5.
// The Ack must be persisted (and say so), not silently treated as "already stored".
var shared = Unacked("alarm-fo", Comments(5));
var a = NewStore();
await a.SaveAsync(shared, Ct);
var onlyOnA = Part9StateMachine.ApplyAddComment(shared, "jane", "seen on A only", T0.AddHours(1)).State;
await a.SaveAsync(onlyOnA, Ct);
var log = new CapturingLogger();
var b = new LocalDbAlarmConditionStateStore(_db, log);
var ackOnB = Part9StateMachine.ApplyAcknowledge(shared, "bob", "acked on B", T0.AddHours(2)).State;
await b.SaveAsync(ackOnB, Ct);
var loaded = (await NewStore().LoadAsync("alarm-fo", Ct))!;
loaded.Comments.Count.ShouldBe(7);
loaded.Comments[5].ShouldBe(onlyOnA.Comments[5]);
loaded.Comments[6].ShouldBe(ackOnB.Comments[5]);
log.Warnings.ShouldBe(1, "a divergence is never silent");
// Re-saving with no new entry must not append the Ack a second time (its own earlier
// divergence-append shifted it off its in-memory index).
var before = await OplogHighWaterAsync();
await b.SaveAsync(ackOnB with { LastTransitionUtc = T0.AddHours(3) }, Ct);
(await OplogEntriesAboveAsync(before, AlarmConditionStateSchema.CommentsTable)).ShouldBe(0);
(await OplogEntriesAboveAsync(before, AlarmConditionStateSchema.StateTable)).ShouldBe(1,
"positive control: the re-save itself was captured");
// And B's following entry (still one behind in memory) is persisted too, exactly once.
var confirmOnB = Part9StateMachine.ApplyAddComment(ackOnB, "bob", "follow-up on B", T0.AddHours(4)).State;
await b.SaveAsync(confirmOnB, Ct);
await b.SaveAsync(confirmOnB, Ct);
var after = (await NewStore().LoadAsync("alarm-fo", Ct))!;
after.Comments.Count.ShouldBe(8);
after.Comments[7].ShouldBe(confirmOnB.Comments[6]);
}
[Fact]
public async Task PeersCopyOfTheSameCommand_IsNotAppendedAgain_AndLogsNothing()
{
// The positive control for the divergence path: in normal operation both nodes apply every
// command, each with its own clock. When the peer's copy is already at the ordinal, the
// local copy is the same entry and must NOT be appended — otherwise the fix would double
// every entry on a healthy pair.
var shared = Unacked("alarm-dual", Comments(5));
await NewStore().SaveAsync(shared, Ct);
var ackOnA = Part9StateMachine.ApplyAcknowledge(shared, "bob", "on it", T0.AddHours(1)).State;
await NewStore().SaveAsync(ackOnA, Ct);
var log = new CapturingLogger();
var b = new LocalDbAlarmConditionStateStore(_db, log);
var ackOnB = Part9StateMachine.ApplyAcknowledge(shared, "bob", "on it", T0.AddHours(1).AddMilliseconds(40)).State;
var before = await OplogHighWaterAsync();
await b.SaveAsync(ackOnB, Ct);
(await OplogEntriesAboveAsync(before, AlarmConditionStateSchema.CommentsTable)).ShouldBe(0);
(await NewStore().LoadAsync("alarm-dual", Ct))!.Comments.Count.ShouldBe(6);
log.Warnings.ShouldBe(0);
}
[Fact]
public async Task ARepeatedIdenticalComment_IsKept_AsItsOwnEntry()
{
// Matching ignores the timestamp only within the clock-skew window; an operator repeating the
// same text later is a new entry, not a duplicate of the earlier one.
var store = NewStore();
var s = Unacked("alarm-repeat", Comments(2));
s = Part9StateMachine.ApplyAddComment(s, "amy", "still high", T0.AddHours(1)).State;
await store.SaveAsync(s, Ct);
s = Part9StateMachine.ApplyAddComment(s, "amy", "still high", T0.AddHours(2)).State;
await store.SaveAsync(s, Ct);
(await NewStore().LoadAsync("alarm-repeat", Ct))!.Comments.ShouldBe(s.Comments);
}
[Fact]
public async Task SavingALoadedOldShapeState_MovesItsCommentsAndAppendsTheNewOne()
{