fix(scripts): legacy WriteBatchAndWaitAsync waits for the run's own reset echo (ScadaBridge#36)

When the run reset the response flag via SetAttribute before the six-argument
handshake, wait for that reset to echo (shared timeout) before writing batch +
trigger, so the previous run's cached CompleteFlag can't satisfy it. Covers the
unported DB-owned MES/receiver scripts. Pending reset consumed per handshake.

Claude-Session: https://claude.ai/code/session_01GT67AEHd2Acv1YPwGfXEoV
This commit is contained in:
Joseph Doherty
2026-11-10 04:38:05 -05:00
parent 08fe5acfe4
commit 545d3e8ba0
3 changed files with 216 additions and 5 deletions
@@ -212,3 +212,32 @@ fast-path, and the trigger was not written until the device echoed the reset 751
response wait is dominated by the Device script's own two data writes plus the subscription response wait is dominated by the Device script's own two data writes plus the subscription
round-trip. The optional negative control (planting a stale `True` with the OPC UA tool) was round-trip. The optional negative control (planting a stale `True` with the OPC UA tool) was
skipped: `infra/tools/opcua_tool.py` needs the `asyncua` module, which is not installed here. skipped: `infra/tools/opcua_tool.py` needs the `asyncua` module, which is not installed here.
## 11. Addendum 2026-11-10 — implicit reset echo on the six-argument overload
The database-owned MES/Delmia scripts (13, 14, 36; receiver scripts 15, 16, 25, 26, 37, 38) were
never ported onto the nine-argument overload (§9 / register row 119), so every unported run still
had the §1 race. §9's "existing scripts behave identically" is therefore relaxed for **exactly
one** shape — the defect itself:
- `ScriptRuntimeContext` records each successful `SetAttribute` of the run (scope-resolved name →
encoded value, last write wins).
- The six-argument `WriteBatchAndWait`, when THIS run wrote `responseKey` to a value other than
`responseValue` (the script's own `CompleteFlag = false` reset), first waits event-driven for
that value to echo and only then writes batch + trigger — the same ordering §2 requires and the
reset-aware overload enforces. The pending write is consumed by that handshake (and by the
reset-aware overload's reset leg), so a second handshake in the same run without a new reset is
unchanged.
- The echo wait **shares** the call's `timeout` with the response wait (unlike the additive
nine-argument form), so an unported script can never run past the deadline it was sized for; a
reset that never echoes returns `false` with nothing written and logs a warning.
- A call with no prior reset write in the run, and the edge-triggered question of §2, are
unchanged. `WaitAsync` used as a handshake is NOT gated: there the trigger is written before the
wait, so a device flipping inside one sampling interval would never report the reset (§2).
Tests: `HandshakeResetEchoTests` — `LegacyOverload_AfterTheScriptsOwnReset_*` (held until the
echo / no echo ⇒ false and no batch), `LegacyOverload_ResetIsConsumedByTheHandshakeThatObservedIt`,
`ResetAwareOverload_ConsumesItsReset_SoALaterLegacyHandshakeIsNotGated`; the cached-true
legacy test still passes unchanged (no reset in that run). Porting the scripts to the nine-argument
overload is still recommended (phase-aware result, explicit reset timeout) but is no longer needed
to close the race; dropping their `Task.Delay(1000)` remains a script edit.
@@ -1,3 +1,4 @@
using System.Collections.Concurrent;
using System.Diagnostics; using System.Diagnostics;
using System.Text.Json; using System.Text.Json;
using System.Text.RegularExpressions; using System.Text.RegularExpressions;
@@ -226,6 +227,16 @@ public class ScriptRuntimeContext
/// </summary> /// </summary>
private int _logSeq; private int _logSeq;
/// <summary>
/// Gitea #36: scope-resolved attribute → codec-encoded value THIS run last wrote through
/// <see cref="SetAttribute"/> and has not yet had a handshake consume. The six-argument
/// <see cref="WriteBatchAndWait"/> reads it to recognise the script's own reset of the response
/// flag (<c>CompleteFlag = false</c> right before the call) and waits for that reset to ECHO
/// before writing the trigger, so the previous run's cached completion value can never satisfy
/// the new handshake. Concurrent because a script may run writes on parallel tasks.
/// </summary>
private readonly ConcurrentDictionary<string, string> _pendingResetWrites = new(StringComparer.Ordinal);
/// <summary> /// <summary>
/// Step logs (design 2026-09-09 D4/D5): the <c>Log</c> global site scripts call — /// Step logs (design 2026-09-09 D4/D5): the <c>Log</c> global site scripts call —
/// <c>Log.Debug/Info/Warn/Error(message, exception?)</c>. /// <c>Log.Debug/Info/Warn/Error(message, exception?)</c>.
@@ -951,6 +962,10 @@ public class ScriptRuntimeContext
throw new InvalidOperationException( throw new InvalidOperationException(
$"SetAttribute('{attributeName}') failed: {response.ErrorMessage}"); $"SetAttribute('{attributeName}') failed: {response.ErrorMessage}");
} }
// Remember the write so a following legacy handshake on this attribute can wait for its
// echo (Gitea #36). Last write wins; a handshake consumes the entry.
_pendingResetWrites[attributeName] = value;
} }
/// <summary> /// <summary>
@@ -970,11 +985,48 @@ public class ScriptRuntimeContext
/// <param name="responseEncoded">Codec-encoded target value (null ⇒ any change).</param> /// <param name="responseEncoded">Codec-encoded target value (null ⇒ any change).</param>
/// <param name="timeout">How long to wait for the response before returning false.</param> /// <param name="timeout">How long to wait for the response before returning false.</param>
/// <returns><c>true</c> on response match within the timeout; <c>false</c> on timeout.</returns> /// <returns><c>true</c> on response match within the timeout; <c>false</c> on timeout.</returns>
/// <remarks>
/// <para>
/// <b>Implicit reset echo (Gitea #36, 2026-11-10).</b> When THIS run wrote
/// <paramref name="responseAttr"/> through <see cref="SetAttribute"/> to a value other than
/// <paramref name="responseEncoded"/> — the MES/Delmia pattern
/// <c>CompleteFlag = false; WriteBatchAndWaitAsync(…, "CompleteFlag", true, …)</c> — the call
/// first waits event-driven for the device to echo that reset and only then writes the batch and
/// trigger. Without it the response wait fast-paths on the previous run's cached <c>true</c>
/// (the reset has not echoed yet) and the script reads results the device has not written. The
/// echo wait shares <paramref name="timeout"/> with the response wait, so the call never runs
/// longer than before; a reset that never echoes returns <c>false</c> (timeout) and writes
/// nothing. A call with no such prior write in this run behaves exactly as it always did —
/// the caller still owns the reset, and the nine-argument reset-aware overload remains the
/// explicit, phase-reporting form.
/// </para>
/// </remarks>
public async Task<bool> WriteBatchAndWait( public async Task<bool> WriteBatchAndWait(
IReadOnlyDictionary<string, string?> encodedValues, string triggerAttr, string? triggerEncoded, IReadOnlyDictionary<string, string?> encodedValues, string triggerAttr, string? triggerEncoded,
string responseAttr, string? responseEncoded, TimeSpan timeout) string responseAttr, string? responseEncoded, TimeSpan timeout)
=> (await WriteBatchAndWaitCore(encodedValues, triggerAttr, triggerEncoded, responseAttr, responseEncoded, timeout) {
if (_pendingResetWrites.TryRemove(responseAttr, out var resetEncoded)
&& !string.Equals(resetEncoded, responseEncoded, StringComparison.Ordinal))
{
var budget = Stopwatch.StartNew();
var echo = await WaitInternal(responseAttr, resetEncoded, null, timeout, requireGoodQuality: false)
.ConfigureAwait(false);
if (!echo.Matched)
{
_logger.LogWarning(
"Handshake on {Instance}.{Attribute}: the script's reset write ({Reset}) did not echo within {Timeout}s; "
+ "trigger '{Trigger}' NOT written (a stale cached completion must not satisfy the handshake)",
_instanceName, responseAttr, resetEncoded, timeout.TotalSeconds, triggerAttr);
return false;
}
var remaining = timeout - budget.Elapsed;
timeout = remaining > TimeSpan.Zero ? remaining : TimeSpan.FromMilliseconds(1);
}
return (await WriteBatchAndWaitCore(encodedValues, triggerAttr, triggerEncoded, responseAttr, responseEncoded, timeout)
.ConfigureAwait(false)).Matched; .ConfigureAwait(false)).Matched;
}
/// <summary> /// <summary>
/// Reset-aware handshake (design 2026-09-10 §5) backing the nine-argument /// Reset-aware handshake (design 2026-09-10 §5) backing the nine-argument
@@ -1038,6 +1090,10 @@ public class ScriptRuntimeContext
: $"Reset wait for '{resetAttr}' did not match")); : $"Reset wait for '{resetAttr}' did not match"));
} }
// The reset leg's own SetAttribute recorded a pending write; it has now been observed,
// so a later legacy handshake in this run must not wait for it again (Gitea #36).
_pendingResetWrites.TryRemove(resetAttr, out _);
// Legs 3 + 4 — unchanged batch/trigger write and response wait. // Legs 3 + 4 — unchanged batch/trigger write and response wait.
var response = await WriteBatchAndWaitCore( var response = await WriteBatchAndWaitCore(
encodedValues, triggerAttr, triggerEncoded, responseAttr, responseEncoded, timeout).ConfigureAwait(false); encodedValues, triggerAttr, triggerEncoded, responseAttr, responseEncoded, timeout).ConfigureAwait(false);
@@ -87,10 +87,11 @@ public class HandshakeResetEchoTests : TestKit, IDisposable
=> new Dictionary<string, string?> { ["MoveOutBatchID"] = AttributeValueCodec.Encode(batchId) }; => new Dictionary<string, string?> { ["MoveOutBatchID"] = AttributeValueCodec.Encode(batchId) };
/// <summary> /// <summary>
/// Pins the PERMANENT legacy behaviour, not a bug awaiting a fix: the six-argument overload is /// Pins the legacy behaviour when the run did NOT write a reset itself: the six-argument
/// deliberately unchanged (deployed scripts keep their semantics) and answers from the stale /// overload answers from the cache (level-triggered, the caller owns the reset). The waiter's
/// cache — callers migrate to the reset-aware overload instead. Never "fix" the fast-path in /// fast-path is not "fixed" in place — the implicit reset echo (Gitea #36, 2026-11-10) engages
/// place; delete this test only if the legacy overload itself is removed. /// only when this run's own <c>SetAttribute</c> reset the response attribute; see
/// <see cref="LegacyOverload_AfterTheScriptsOwnReset_WaitsForTheEcho_ThenMatchesTheFreshTrue"/>.
/// </summary> /// </summary>
/// <returns>A task that represents the asynchronous operation.</returns> /// <returns>A task that represents the asynchronous operation.</returns>
[Fact] [Fact]
@@ -109,6 +110,131 @@ public class HandshakeResetEchoTests : TestKit, IDisposable
Assert.True(await call); Assert.True(await call);
} }
private async Task ResetThroughScript(TestProbe dcl, ScriptRuntimeContext ctx)
{
// The MES script's own reset: `rx.Attributes["MoveOutCompleteFlag"] = false;` — a device
// write the DCL acks, with NO echo yet (the cache still holds the previous run's True).
var set = ctx.SetAttribute("MoveOutCompleteFlag", AttributeValueCodec.Encode(false)!);
var reset = dcl.ExpectMsg<WriteTagRequest>(TimeSpan.FromSeconds(5));
Assert.Equal(CompleteTag, reset.TagPath);
dcl.Reply(new WriteTagResponse(reset.CorrelationId, true, null, DateTimeOffset.UtcNow));
await set;
}
/// <summary>
/// Gitea #36 regression (MesMoveOut, QA 2026-09-10): the script resets CompleteFlag and then
/// calls the SIX-argument overload. Before the fix the response wait fast-pathed on the previous
/// run's cached True (0 ms) and the script read stale results. Now the batch is held until the
/// reset echoes, and only the device's fresh True completes the call.
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task LegacyOverload_AfterTheScriptsOwnReset_WaitsForTheEcho_ThenMatchesTheFreshTrue()
{
var (actor, dcl, ctx) = Boot();
await ResetThroughScript(dcl, ctx);
var call = ctx.WriteBatchAndWait(
Values(28950), "MoveOutFlag", AttributeValueCodec.Encode(true),
"MoveOutCompleteFlag", AttributeValueCodec.Encode(true), TimeSpan.FromSeconds(10));
// Stale True in the cache, reset not echoed → no batch, no completion.
dcl.ExpectNoMsg(TimeSpan.FromMilliseconds(500));
Assert.False(call.IsCompleted);
actor.Tell(new TagValueUpdate(Conn, CompleteTag, false, QualityCode.Good, DateTimeOffset.UtcNow));
var batch = dcl.ExpectMsg<WriteTagBatchRequest>(TimeSpan.FromSeconds(5));
Assert.Equal(TriggerTag, batch.TriggerTagPath);
dcl.Reply(new WriteTagBatchResponse(batch.CorrelationId, true, null, DateTimeOffset.UtcNow));
// The cache holds the echoed False — only THIS request's completion may finish the call.
dcl.ExpectNoMsg(TimeSpan.FromMilliseconds(200));
Assert.False(call.IsCompleted);
actor.Tell(new TagValueUpdate(Conn, CompleteTag, true, QualityCode.Good, DateTimeOffset.UtcNow));
Assert.True(await call);
}
/// <summary>
/// Gitea #36: a reset that never echoes makes the legacy handshake report a timeout and write
/// NOTHING — it must not complete from the stale cached True, nor send the trigger.
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task LegacyOverload_AfterTheScriptsOwnReset_NoEcho_ReturnsFalse_AndNeverWritesTheBatch()
{
var (_, dcl, ctx) = Boot();
await ResetThroughScript(dcl, ctx);
var matched = await ctx.WriteBatchAndWait(
Values(28950), "MoveOutFlag", AttributeValueCodec.Encode(true),
"MoveOutCompleteFlag", AttributeValueCodec.Encode(true), TimeSpan.FromMilliseconds(700));
Assert.False(matched);
dcl.ExpectNoMsg(TimeSpan.FromMilliseconds(300));
}
/// <summary>
/// Gitea #36: the pending reset is consumed by the handshake that observed it — a second legacy
/// handshake in the same run (no new reset) keeps the plain level-triggered behaviour instead
/// of waiting for an echo of a reset that already happened.
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task LegacyOverload_ResetIsConsumedByTheHandshakeThatObservedIt()
{
var (actor, dcl, ctx) = Boot();
await ResetThroughScript(dcl, ctx);
var first = ctx.WriteBatchAndWait(
Values(1), "MoveOutFlag", AttributeValueCodec.Encode(true),
"MoveOutCompleteFlag", AttributeValueCodec.Encode(true), TimeSpan.FromSeconds(10));
actor.Tell(new TagValueUpdate(Conn, CompleteTag, false, QualityCode.Good, DateTimeOffset.UtcNow));
var b1 = dcl.ExpectMsg<WriteTagBatchRequest>(TimeSpan.FromSeconds(5));
dcl.Reply(new WriteTagBatchResponse(b1.CorrelationId, true, null, DateTimeOffset.UtcNow));
actor.Tell(new TagValueUpdate(Conn, CompleteTag, true, QualityCode.Good, DateTimeOffset.UtcNow));
Assert.True(await first);
var second = ctx.WriteBatchAndWait(
Values(2), "MoveOutFlag", AttributeValueCodec.Encode(true),
"MoveOutCompleteFlag", AttributeValueCodec.Encode(true), TimeSpan.FromSeconds(5));
var b2 = dcl.ExpectMsg<WriteTagBatchRequest>(TimeSpan.FromSeconds(5));
dcl.Reply(new WriteTagBatchResponse(b2.CorrelationId, true, null, DateTimeOffset.UtcNow));
Assert.True(await second);
}
/// <summary>
/// Gitea #36: the reset-aware overload's own reset write is observed by its reset leg, so it
/// must not be left pending for a later six-argument handshake in the same run (which would
/// otherwise wait for an echo of a reset that already happened and time out).
/// </summary>
/// <returns>A task that represents the asynchronous operation.</returns>
[Fact]
public async Task ResetAwareOverload_ConsumesItsReset_SoALaterLegacyHandshakeIsNotGated()
{
var (actor, dcl, ctx) = Boot();
var first = ctx.WriteBatchResetAndWait(
Values(1), "MoveOutFlag", AttributeValueCodec.Encode(true),
"MoveOutCompleteFlag", AttributeValueCodec.Encode(true), TimeSpan.FromSeconds(10),
"MoveOutCompleteFlag", AttributeValueCodec.Encode(false)!, TimeSpan.FromSeconds(10));
var reset = dcl.ExpectMsg<WriteTagRequest>(TimeSpan.FromSeconds(5));
dcl.Reply(new WriteTagResponse(reset.CorrelationId, true, null, DateTimeOffset.UtcNow));
actor.Tell(new TagValueUpdate(Conn, CompleteTag, false, QualityCode.Good, DateTimeOffset.UtcNow));
var b1 = dcl.ExpectMsg<WriteTagBatchRequest>(TimeSpan.FromSeconds(5));
dcl.Reply(new WriteTagBatchResponse(b1.CorrelationId, true, null, DateTimeOffset.UtcNow));
actor.Tell(new TagValueUpdate(Conn, CompleteTag, true, QualityCode.Good, DateTimeOffset.UtcNow));
Assert.True((await first).Matched);
var second = ctx.WriteBatchAndWait(
Values(2), "MoveOutFlag", AttributeValueCodec.Encode(true),
"MoveOutCompleteFlag", AttributeValueCodec.Encode(true), TimeSpan.FromSeconds(3));
var b2 = dcl.ExpectMsg<WriteTagBatchRequest>(TimeSpan.FromSeconds(2));
dcl.Reply(new WriteTagBatchResponse(b2.CorrelationId, true, null, DateTimeOffset.UtcNow));
Assert.True(await second);
}
/// <summary>Verifies that the reset-aware overload holds the batch until the reset echoes and then matches the fresh true value.</summary> /// <summary>Verifies that the reset-aware overload holds the batch until the reset echoes and then matches the fresh true value.</summary>
/// <returns>A task that represents the asynchronous operation.</returns> /// <returns>A task that represents the asynchronous operation.</returns>
[Fact] [Fact]