diff --git a/docs/AlarmProbeFindings.md b/docs/AlarmProbeFindings.md index 15ab240..17a54f7 100644 --- a/docs/AlarmProbeFindings.md +++ b/docs/AlarmProbeFindings.md @@ -515,3 +515,32 @@ returns gRPC `InvalidArgument`. The GUID arm of the ack command was not driven live. The public alarm RPCs expose only the full reference, so clients reach the by-name arm; worker unit tests cover the GUID arm. + +## Item handle reuse + +`AlarmAckWriter` correlates an ack with its `OnWriteComplete` by the +(server handle, item handle) pair, because the callback carries no per-write id. +After an unconfirmed ack it drops the `AckMsg` item and re-adds it so the next +ack waits on a new handle that a late completion for the old one cannot match. +That only works if MXAccess does not hand the same number out again. + +`ItemHandleReuseProbeTests` (Skip-gated, worker tests) checked this on windev +(`10.100.0.48`, Galaxy `DEV`) on 2026-10-20 against +`TestMachine_001.TestAlarm001.AckMsg`, without writing: + +| Sequence on one registration (server handle 1) | Item handles returned | +|---|---| +| `AddItem` + `Advise`, then `UnAdvise` + `RemoveItem`, five times | 1, 2, 3, 4, 5 | +| `AddItem`, then `RemoveItem`, five times | 6, 7, 8, 9, 10 | +| Add and remove `AckMsg`, add `Acked`, add `AckMsg` again | 11, then 12 (`Acked`), 13 | +| Add `AckMsg` twice while both are held | 14, 15 | + +Within a registration the numbers increase and a freed number is never reused, +so the drop-and-re-add mitigation holds. Numbering is per registration: +`Unregister` + `Register` on the same COM object returned server handle 2 and +item handle 1, and a new `LMXProxyServerClass` returned server handle 1 and +item handle 1 again. The writer is not exposed to that restart because its +teardown detaches its `OnWriteComplete` handler from the old COM object and +clears that server handle's completion entries before it creates a new one. +No per-handle generation counter is needed. + diff --git a/docs/MxAccessWorkerInstanceDesign.md b/docs/MxAccessWorkerInstanceDesign.md index b648b1a..8da84e7 100644 --- a/docs/MxAccessWorkerInstanceDesign.md +++ b/docs/MxAccessWorkerInstanceDesign.md @@ -356,7 +356,10 @@ stay acceptance-only regardless of which completion (if any) was attributed. `MxAccessWriteCompletionCache` and reuses one advised `AckMsg` item per alarm (least-recently-used, capped at 256). After an ack ends unconfirmed it marks the item dirty, and the next ack to that alarm removes and re-adds the item so the -write waits on a fresh item handle the stale completion cannot match. Every +write waits on a fresh item handle the stale completion cannot match. This +relies on MXAccess never reusing an item handle number within one +registration, which a live probe confirmed (see "Item handle reuse" in +[Alarm Probe Findings](./AlarmProbeFindings.md)). Every drop of an item (dirty re-add, eviction, or a failed `AddItem`/`Advise`/`Write`) also removes that handle's completion entry, and tearing down the registration removes every entry for its server handle, so the cache does not grow by one diff --git a/src/ZB.MOM.WW.MxGateway.Worker.Tests/Probes/ItemHandleReuseProbeTests.cs b/src/ZB.MOM.WW.MxGateway.Worker.Tests/Probes/ItemHandleReuseProbeTests.cs new file mode 100644 index 0000000..9c294a7 --- /dev/null +++ b/src/ZB.MOM.WW.MxGateway.Worker.Tests/Probes/ItemHandleReuseProbeTests.cs @@ -0,0 +1,166 @@ +// ItemHandleReuseProbeTests.cs +// +// Probe for issue #166: does MXAccess hand out a new item handle number when the +// same item is removed and re-added on one LMXProxyServer registration? The +// AlarmAckWriter's Unconfirmed mitigation (drop the item, re-add it, wait on the +// fresh handle) relies on the number changing, because OnWriteComplete carries +// only the (server, item) handle pair. +// +// The probe only adds, advises and removes items. It never writes, so it does +// not acknowledge the alarm or create Historian rows. +// +// HOW TO RUN (dev rig with MXAccess installed and the DEV Galaxy running): +// 1. Remove (or set to null) the Skip parameter on the [Fact] below. +// 2. dotnet test src/ZB.MOM.WW.MxGateway.Worker.Tests/ZB.MOM.WW.MxGateway.Worker.Tests.csproj +// -p:Platform=x86 --filter FullyQualifiedName~ItemHandleReuseProbeTests +// --logger "console;verbosity=detailed" +// 3. Read the logged handles. Results are recorded in docs/AlarmProbeFindings.md. +// +// RESULT (windev, 2026-10-20): within one registration item handles increase +// monotonically and are never reused (1..15 across add/remove/re-add of the same +// item, with and without Advise, interleaved with another item, and while held +// twice). Item numbering restarts at 1 after Unregister + Register, and a fresh +// COM object is handed server handle 1 again. + +using System; +using System.Collections.Generic; +using System.Runtime.InteropServices; +using System.Threading; +using ArchestrA.MxAccess; +using ZB.MOM.WW.MxGateway.Worker.MxAccess; +using Xunit.Abstractions; + +namespace ZB.MOM.WW.MxGateway.Worker.Tests.Probes; + +/// +/// Live probe that logs the item handles MXAccess returns when the same +/// AckMsg item is removed and re-added, to decide whether a late +/// OnWriteComplete for a dropped handle could match a re-added one. +/// +public sealed class ItemHandleReuseProbeTests +{ + private const string AckItem = "TestMachine_001.TestAlarm001.AckMsg"; + private const string OtherItem = "TestMachine_001.TestAlarm001.Acked"; + private const int Rounds = 5; + + private readonly ITestOutputHelper output; + private readonly List log = new List(); + + /// Initializes a new instance of the class. + /// Test output helper for logging. + public ItemHandleReuseProbeTests(ITestOutputHelper output) + { + this.output = output; + } + + /// Adds, removes and re-adds the AckMsg item on a fresh registration and logs every handle. + [Fact(Skip = "Live dev-rig probe (issue #166) — flip Skip=null on a host with MXAccess and the DEV Galaxy running.")] + public void RemoveThenReAdd_LogsItemHandles() + { + Exception? threadException = null; + Thread thread = new Thread(() => + { + try { RunProbe(); } + catch (Exception ex) { threadException = ex; } + }); + thread.SetApartmentState(ApartmentState.STA); + thread.Start(); + thread.Join(); + + foreach (string line in log) + { + output.WriteLine(line); + } + + if (threadException is not null) + { + throw new InvalidOperationException("Probe failed: " + threadException.Message, threadException); + } + } + + private void RunProbe() + { + LMXProxyServerClass com = new LMXProxyServerClass(); + try + { + IMxAccessServer mx = new MxAccessComServer(com); + int server = mx.Register("MxGatewayProbe166"); + Log($"Register -> server handle {server}"); + + // A: the AlarmAckWriter drop path (Advise, then UnAdvise + RemoveItem). + for (int i = 0; i < Rounds; i++) + { + int h = mx.AddItem(server, AckItem); + mx.Advise(server, h); + Log($"A{i}: AddItem+Advise {AckItem} -> {h}"); + mx.UnAdvise(server, h); + mx.RemoveItem(server, h); + Log($"A{i}: UnAdvise+RemoveItem {h}"); + } + + // B: RemoveItem without Advise. + for (int i = 0; i < Rounds; i++) + { + int h = mx.AddItem(server, AckItem); + Log($"B{i}: AddItem {AckItem} -> {h}"); + mx.RemoveItem(server, h); + Log($"B{i}: RemoveItem {h}"); + } + + // C: interleave another item to see whether a freed number is handed to any item. + int c1 = mx.AddItem(server, AckItem); + Log($"C: AddItem {AckItem} -> {c1}"); + mx.RemoveItem(server, c1); + Log($"C: RemoveItem {c1}"); + int c2 = mx.AddItem(server, OtherItem); + Log($"C: AddItem {OtherItem} -> {c2}"); + int c3 = mx.AddItem(server, AckItem); + Log($"C: AddItem {AckItem} -> {c3}"); + mx.RemoveItem(server, c2); + mx.RemoveItem(server, c3); + Log($"C: RemoveItem {c2}, {c3}"); + + // D: the same item added twice while the first is still held. + int d1 = mx.AddItem(server, AckItem); + int d2 = mx.AddItem(server, AckItem); + Log($"D: AddItem {AckItem} twice while held -> {d1}, {d2}"); + mx.RemoveItem(server, d1); + mx.RemoveItem(server, d2); + + mx.Unregister(server); + Log($"Unregister {server}"); + + // E: the TearDownServer path: re-register on the same COM object and add again. + int server2 = mx.Register("MxGatewayProbe166"); + int e1 = mx.AddItem(server2, AckItem); + Log($"E: re-Register -> server handle {server2}; AddItem {AckItem} -> {e1}"); + mx.RemoveItem(server2, e1); + mx.Unregister(server2); + } + finally + { + Marshal.FinalReleaseComObject(com); + } + + // F: a fresh COM object, as AlarmAckWriter creates after a teardown. + LMXProxyServerClass com2 = new LMXProxyServerClass(); + try + { + IMxAccessServer mx2 = new MxAccessComServer(com2); + int server3 = mx2.Register("MxGatewayProbe166"); + int f1 = mx2.AddItem(server3, AckItem); + Log($"F: new COM object Register -> server handle {server3}; AddItem {AckItem} -> {f1}"); + mx2.RemoveItem(server3, f1); + mx2.Unregister(server3); + } + finally + { + Marshal.FinalReleaseComObject(com2); + } + } + + private void Log(string line) + { + log.Add(DateTime.Now.ToString("HH:mm:ss.fff") + " " + line); + } +} diff --git a/src/ZB.MOM.WW.MxGateway.Worker/MxAccess/AlarmAckWriter.cs b/src/ZB.MOM.WW.MxGateway.Worker/MxAccess/AlarmAckWriter.cs index 1538607..d6d774c 100644 --- a/src/ZB.MOM.WW.MxGateway.Worker/MxAccess/AlarmAckWriter.cs +++ b/src/ZB.MOM.WW.MxGateway.Worker/MxAccess/AlarmAckWriter.cs @@ -166,6 +166,13 @@ public sealed class AlarmAckWriter : IAlarmAckWriter // (server, item) handle with no per-write id, so a late one would // be credited to this write. Drop the item and re-add it so this // write waits on a fresh handle the stale completion cannot match. + // That holds because MXAccess never reuses an item handle number + // within one registration: the live probe (ItemHandleReuseProbeTests, + // windev 2026-10-20) saw strictly increasing handles across repeated + // remove/re-add of the same item. Numbering restarts only on a new + // registration, and TearDownServer detaches this writer's + // OnWriteComplete handler and clears the server's completion entries + // first, so the old registration's completions cannot reach it. DropItem(mx, node); cached = false; }