Files
servuo-plugins/overlay/Scripts/Custom/Bridge/BridgeIdempotency.cs
wtclaude 6061fe39ce fix(bridge): a refusal is not an effect, so it does not spend the key (Phase 16a)
Protocol 7, amended in place. The at-most-once store had two cases and needed a
third.

A handler that THREW keeps its key and stores the failure — correct, because it
may have applied half of itself, and that is the failure this file exists to
prevent. A handler that RETURNED had its reply stored and replayed for ever. There
was no case for a handler that ran to completion and deliberately REFUSED, and
every refusal on this plane is a guard: a missing runId, an unknown item, a cap, a
rate limit, a write that failed and left the value alone. Nothing happened — and
remembering the refusal froze it as the key's answer, so a refusal that WAITING
FIXES could never be retried past.

`uo.world.save` is the case the acceptance walk found it with, and the module says
in as many words what it expected: "429 is the shard's save rate limit, and it is
the one refusal on this plane that waiting fixes … which is what makes a phase
boundary retried rather than abandoned." It was not achievable. Six attempts over
four minutes — three automatic, an operator retry, three more — every one
answering the same frozen sentence, "the last save was 227 seconds ago". The
number could not age because it was the first reply being replayed, and a step's
idempotency key is one value for the life of the step, so the operator's retry
control could not escape it either.

So a refusal releases the key. The refusal is still emitted to the caller, which
is what ends the attempt; it is simply not remembered as this key's answer. A
refusal is recognised by its `kind` ending in `.error`, matched on the suffix so a
handler family added later is covered without extending a list here.
`bridge.error` is excluded deliberately — that is the reply this file writes when
a handler threw, which is exactly the case whose key must be kept. Both completion
paths are covered, including a deferred handler that refuses after its timer arms.

The safety argument is that "nothing happened" holds for every `*.error` reply
here — audited across BridgeWorld, BridgeOneShots, BridgeLeases and
BridgeParticipation, where every refusal is a pre-mutation guard or follows a
`Write` that failed. It is a property this file cannot verify, so it is written
down as a rule handlers must keep: do not answer `*.error` after changing the
world. Report a partial change in an `ok` reply, as the item grant does with
`granted`/`missed` and the despawn with `removed`/`gone`/`refused`.

Verified on a real shard: the same key 25 seconds apart now answers "the last save
was 15 seconds ago" then "40 seconds ago" — a number that moves, with no
`replayed` marker — while a SUCCESSFUL reply is still replayed unchanged, so the
at-most-once guarantee is intact where it matters.

`Status()` gains a `refused=` counter.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_016wDDVXWMDz82WqE1i969r4
2026-09-09 08:28:50 -05:00

542 lines
24 KiB
C#

using System;
using System.Collections.Generic;
namespace Server.Custom.Bridge
{
/// <summary>
/// Protocol 6. Makes a repeated command safe.
///
/// The website's event runner retries a step that did not come back, and until now a command
/// whose acknowledgement was lost was indistinguishable from one that never applied. There
/// was no way to tell the difference from either end, so every world-writing verb had to be
/// declared un-retryable — a lost announcement being cheaper than a doubled one. That is not
/// a position you can hold once an event can spawn creatures or lease a config value.
///
/// So a command may now carry an `idempotencyKey`, and the shard promises: **a key is
/// executed at most once.** A repeat is never re-run. It is answered with the original
/// reply — the same acknowledgement the caller lost — under the repeat's own correlation id.
///
/// ── Reserve on receipt, not on completion ──────────────────────────────────────────────
///
/// The key is recorded BEFORE the handler is dispatched, not after it returns. A handler that
/// finishes inside its own inbound call can never see a repeat (the Core thread processes one
/// line at a time), but a handler that defers — a lease that arms a timer, a spawn that
/// waits for a save — completes long after `OnInboundLine` has returned, and that is exactly
/// the window a lost ack opens. Reserving late would leave it uncovered.
///
/// A repeat of a key that is still in flight is answered `bridge.busy`: it runs nothing and
/// tells the caller to come back. `bridge.busy` is deliberately not an error — the work is
/// happening, and the module classifies it retryable.
///
/// ── A key that has begun is never released — EXCEPT on a refusal ──────────────────────
///
/// Not when the handler throws. Releasing it would let a retry re-run a command that may have
/// applied half of itself, which is precisely the failure this file exists to prevent. A
/// handler that throws stores a `bridge.error` reply instead, so the retry gets a definite
/// answer and the step fails once rather than looping.
///
/// A REFUSAL is the third case, and it was missing until the Phase 16 acceptance walk. A
/// handler that ran to completion and answered `*.error` did not do anything: every refusal
/// on this plane is a guard — a missing runId, an unknown item, a cap, a rate limit, a write
/// that failed and left the value alone. Remembering it froze the answer for ever, so a
/// refusal that WAITING FIXES could never be retried past. `uo.world.save` is the case that
/// found it: the shard saves at most every 300 seconds, the module says in as many words that
/// this is "the one refusal on this plane that waiting fixes", and six attempts over four
/// minutes all replayed one frozen sentence — "the last save was 227 seconds ago" — because
/// the number was the first reply's, not the clock's.
///
/// So a refusal releases the key: nothing happened, and the caller is free to ask again. The
/// refusal is still EMITTED to the caller, which is what ends the attempt; it is simply not
/// remembered as this key's answer. The safety argument is that "nothing happened" is a
/// property of every `*.error` reply here, and it is a property this file cannot verify — so
/// it is a rule handlers must keep: **do not answer `*.error` after changing the world.**
/// Report a partial change in an `ok` reply, as the item grant does with `granted`/`missed`
/// and the despawn with `removed`/`gone`/`refused`.
///
/// ── The one hole, and why it is loud ──────────────────────────────────────────────────
///
/// The set is bounded, so an evicted key's repeat WOULD be applied a second time. The bounds
/// are chosen to put that far outside reach — an hour, against core's fifteen-minute step
/// lease — and an eviction that drops a key which had not yet expired prints a warning naming
/// the count. If the guarantee is ever actually breached, an operator sees it here rather
/// than discovering a doubled spawn in the world.
/// </summary>
public static class BridgeIdempotency
{
/// <summary>
/// How long a key is remembered. Core's step lease is 15 minutes and its retry backoff
/// is bounded well inside that, so an hour is not a tuned number — it is a margin wide
/// enough that expiry should never be the thing that ends a key's life.
/// </summary>
private static readonly TimeSpan Ttl = TimeSpan.FromHours(1.0);
/// <summary>
/// Hard bound on remembered keys, in the same spirit as BridgeLink's outbound queue cap:
/// the Core thread never holds an unbounded collection. At command rates this is days of
/// traffic, so reaching it means something is wrong — hence the warning on eviction.
/// </summary>
private const int Cap = 4096;
/// <summary>
/// The correlation fields the sidecar routes replies on, in the order `rpc.rs` tries
/// them. A command carries exactly one; the reply echoes it. A replay must be stamped
/// with the REPEAT's value, not the original's — the sidecar's `reqId` is a fresh
/// per-process counter, so the retry is waiting on an id the first attempt never used.
/// </summary>
private static readonly string[] CorrFields = { "reqId", "code", "id" };
private sealed class Entry
{
public DateTime Reserved; // when the key was first seen
public bool Done; // the handler has finished (successfully or not)
public string Reply; // the correlated reply line, verbatim; null if there was none
public string Corr; // the correlation value the original reply carries
public string CorrField; // which of CorrFields that value sits in
public string Kind; // for diagnostics only
public bool Refused; // the reply was a `*.error`: nothing happened, so do not keep the key
}
/// <summary>
/// Is this reply a refusal — a handler that ran and deliberately did nothing?
///
/// Every refusal on this plane is emitted as a `kind` ending in `.error`
/// (`world.error`, `lease.error`, `oneshot.error`, `participation.error`, …). Matched on
/// the suffix rather than a list, so a handler family added later is covered without
/// anyone remembering to extend an enumeration here.
///
/// `bridge.error` is deliberately EXCLUDED: that is the reply this file writes itself
/// when a handler THREW, and a throw is exactly the case whose key must be kept.
/// </summary>
private static bool IsRefusal(string replyLine)
{
if (replyLine == null)
return false;
var parsed = BridgeJson.Parse(replyLine);
if (parsed == null)
return false;
var kind = BridgeJson.GetString(parsed, "kind");
if (kind == null || String.Equals(kind, "bridge.error", StringComparison.Ordinal))
return false;
return kind.EndsWith(".error", StringComparison.Ordinal);
}
private static readonly Dictionary<string, Entry> _byKey =
new Dictionary<string, Entry>(StringComparer.Ordinal);
// Insertion order, so the cap evicts oldest-first without sorting the dictionary.
private static readonly Queue<string> _order = new Queue<string>();
// ---- capture state; Core thread only, one keyed command at a time ----
private static Entry _open;
private static string _openCorr;
private static string _openCorrField;
private static long _seen, _replayed, _busy, _evicted, _uncorrelated, _refusals;
/// <summary>
/// True while a keyed command's handler is running. BridgeLink.Emit checks this on every
/// emit, so it is a plain bool read rather than anything that costs the sweep path.
/// </summary>
public static bool Capturing
{
get { return _open != null; }
}
public static string Status()
{
return String.Format(
"idem(keys={0} seen={1} replayed={2} busy={3} evicted={4} uncorrelated={5} refused={6})",
_byKey.Count, _seen, _replayed, _busy, _evicted, _uncorrelated, _refusals);
}
/// <summary>
/// Called by BridgeBoot for every inbound command that carries an `idempotencyKey`,
/// before the handler runs.
///
/// Returns TRUE when the command must not be executed — this call has already emitted the
/// answer (a replay of the original reply, or `bridge.busy`). Returns FALSE when the key
/// is new: the key is now reserved and capture is open, and the caller MUST pair this
/// with <see cref="Finish"/> in a finally.
/// </summary>
public static bool Intercept(string key, Dictionary<string, object> command)
{
_seen++;
Sweep();
string corrField = null;
string corr = null;
for (int i = 0; i < CorrFields.Length; i++)
{
var v = BridgeJson.GetString(command, CorrFields[i]);
if (v != null)
{
corrField = CorrFields[i];
corr = v;
break;
}
}
Entry prior;
if (_byKey.TryGetValue(key, out prior))
{
if (prior.Done)
Replay(key, prior, corrField, corr);
else
Busy(key, prior, corrField, corr);
return true;
}
var entry = new Entry
{
Reserved = DateTime.UtcNow,
Done = false,
Kind = BridgeJson.GetString(command, "kind"),
};
Remember(key, entry);
_open = entry;
_openCorr = corr;
_openCorrField = corrField;
return false;
}
/// <summary>
/// Called by BridgeBoot in a finally, once the handler has returned. Closes capture and
/// marks the key done. `error` is non-null when the handler threw.
///
/// A handler that deferred its work calls <see cref="Hold"/> first; this then leaves the
/// key reserved and in flight, and the handler completes it later.
/// </summary>
public static void Finish(string key, string error)
{
var entry = _open;
_open = null;
var corr = _openCorr;
var corrField = _openCorrField;
_openCorr = null;
_openCorrField = null;
if (entry == null || entry.Done)
return; // Hold() released it to its own completion, or there was nothing open
if (error != null)
{
// The handler threw. The key stays claimed — see the class header — and the stored
// answer is the failure, so the retry ends the step instead of re-running a command
// that may have applied part of itself.
var sb = BridgeJson.Begin("bridge.error");
if (corrField != null)
sb.Str(corrField, corr);
sb.Str("reason", "handler threw: " + error)
.Str("idempotencyKey", key);
entry.Reply = sb.End();
entry.Corr = corr;
entry.CorrField = corrField;
entry.Done = true;
Console.WriteLine("[Bridge] idempotency: {0} threw under key {1}; the retry will be answered with the failure",
entry.Kind, key);
return;
}
if (entry.Reply == null)
{
// Nothing the sidecar could have correlated was emitted. That is a defect in the
// handler rather than a state to model: the FIRST attempt has already timed out at
// the sidecar, and the retry would time out identically forever. Store a definite
// answer so the retry terminates, and say so.
_uncorrelated++;
var sb = BridgeJson.Begin("bridge.error");
if (corrField != null)
sb.Str(corrField, corr);
sb.Str("reason", "the original command produced no correlated reply")
.Str("idempotencyKey", key);
entry.Reply = sb.End();
entry.Corr = corr;
entry.CorrField = corrField;
Console.WriteLine("[Bridge] idempotency: {0} under key {1} emitted no reply the sidecar could correlate",
entry.Kind, key);
}
else if (entry.Refused)
{
// The handler ran and refused, so nothing happened and this key is not spent. The
// refusal has already gone out to the caller; it just is not remembered as the
// answer. Without this, a refusal that waiting fixes could never be retried past —
// see the class header.
Release(key);
_refusals++;
return;
}
entry.Done = true;
}
/// <summary>
/// For a handler that finishes AFTER its inbound call returns. It keeps the key reserved
/// (so a repeat is answered `bridge.busy` rather than executed) and takes on the duty of
/// calling <see cref="Complete"/> with the reply it eventually emits.
///
/// 11a built this door and had nothing to walk through it. `participation.snapshot` is
/// the first: above a threshold it walks its members in chunks across Core ticks, so it
/// completes long after its inbound call returned, and a repeat arriving in between is
/// the first `bridge.busy` this shard can actually produce.
/// </summary>
public static void Hold(string key)
{
var entry = _open;
if (entry == null)
return;
// The caller must be holding the key it was dispatched under. A mismatch would leave
// the OPEN key marked done by Finish while the named one stayed in flight forever, so
// it is refused rather than honoured: capture stays open and the ordinary path runs.
if (key == null || !_byKey.ContainsKey(key))
{
Console.WriteLine("[Bridge] idempotency: Hold called with an unknown key '{0}'; ignoring", key);
return;
}
// Close capture without marking done: the key stays in flight until Complete.
_open = null;
_openCorr = null;
_openCorrField = null;
}
/// <summary>
/// Completes a key a handler previously held. `replyLine` is the line the handler emits
/// as its answer; it is stored so a later repeat replays it.
/// </summary>
public static void Complete(string key, string replyLine)
{
Entry entry;
if (key == null || !_byKey.TryGetValue(key, out entry) || entry.Done)
return;
var parsed = replyLine == null ? null : BridgeJson.Parse(replyLine);
if (parsed != null)
{
for (int i = 0; i < CorrFields.Length; i++)
{
var v = BridgeJson.GetString(parsed, CorrFields[i]);
if (v != null)
{
entry.CorrField = CorrFields[i];
entry.Corr = v;
break;
}
}
}
// A deferred handler can refuse too — a lease whose target vanished while the timer was
// armed answers `lease.error` here rather than from inside the inbound call. Same rule:
// nothing happened, so the key is not spent.
if (IsRefusal(replyLine))
{
Release(key);
_refusals++;
return;
}
entry.Reply = replyLine;
entry.Done = true;
}
/// <summary>
/// Give a key back, as though it had never been seen.
///
/// Only ever called for a refusal — see the class header. It removes the entry from the
/// lookup; the stale key left in `_order` is harmless, because eviction re-reads
/// `_byKey` and skips what is no longer there.
/// </summary>
private static void Release(string key)
{
if (key != null)
_byKey.Remove(key);
}
/// <summary>
/// Every line a keyed handler emits passes through here. Only the one the sidecar would
/// correlate with THIS command is kept: an `admin.audit` broadcast that happens to be
/// emitted alongside the reply is a fact about the world and must not be replayed, while
/// the reply is an answer to a caller and must be.
/// </summary>
public static void Observe(string line)
{
var entry = _open;
if (entry == null || line == null || _openCorrField == null || _openCorr == null)
return;
// Cheap reject before parsing: the correlation value is a string field on the reply, so
// if it does not appear in the line at all this cannot be the reply.
if (line.IndexOf(_openCorr, StringComparison.Ordinal) < 0)
return;
var parsed = BridgeJson.Parse(line);
if (parsed == null)
return;
if (!String.Equals(BridgeJson.GetString(parsed, _openCorrField), _openCorr, StringComparison.Ordinal))
return;
entry.Reply = line;
entry.Corr = _openCorr;
entry.CorrField = _openCorrField;
entry.Refused = IsRefusal(line);
}
// ---- internals ----
private static void Replay(string key, Entry prior, string corrField, string corr)
{
_replayed++;
// A repeat with no correlation field is nobody's outstanding call. Re-emitting the
// original reply would put a stale answer on the event feed, where a subscriber would
// read it as a fresh one, so the repeat is absorbed silently instead.
if (corrField == null || corr == null)
{
Console.WriteLine("[Bridge] idempotency: absorbed an uncorrelated repeat of key {0} ({1})",
key, prior.Kind);
return;
}
// Stamp the repeat's correlation id over the original's. The sidecar is waiting on the
// id IT sent this time; replaying the first attempt's id would leave the call hanging
// until the reply timeout, which is the very failure being answered.
string line = null;
if (prior.Reply != null && String.Equals(corrField, prior.CorrField, StringComparison.Ordinal))
line = BridgeJson.RewriteStringField(prior.Reply, corrField, corr);
if (line == null)
{
// Either the original produced no reply to replay, or the repeat correlates on a
// different field than the original did. Nothing sensible can be replayed under an
// id the caller is not waiting on, so answer plainly rather than hang the call.
BridgeLink.Emit(BridgeJson.Begin("bridge.error")
.Str(corrField, corr)
.Str("reason", "the original reply for this idempotency key cannot be replayed")
.Str("idempotencyKey", key)
.End());
return;
}
line = BridgeJson.WithTrueFlag(line, "replayed");
Console.WriteLine("[Bridge] idempotency: replaying the original reply for key {0} ({1})",
key, prior.Kind);
BridgeLink.Emit(line);
}
private static void Busy(string key, Entry prior, string corrField, string corr)
{
_busy++;
var sb = BridgeJson.Begin("bridge.busy");
if (corrField != null)
sb.Str(corrField, corr);
// **`busyKind`, not `kind`, and the name is the whole bug.** `Begin` has already
// written this frame's own `kind` as `bridge.busy`, so a second `kind` field made the
// object carry two -- and every JSON parser worth the name takes the LAST. The sidecar
// matches `bridge.busy` to decide on a 425, read `participation.snapshot` instead, and
// answered an ordinary 200 with a body saying nothing had happened.
//
// It shipped in 11a and could not be seen there: with only synchronous handlers a
// repeat can never arrive mid-flight, so this arm was unreachable on a live shard and
// the unit test that covers the sidecar's mapping was, correctly, feeding it a frame
// built by hand. The first deferring handler produced it on its first collision.
sb.Str("idempotencyKey", key)
.Str("busyKind", prior.Kind)
.Str("reason", "a command with this idempotency key is still in flight");
BridgeLink.Emit(sb.End());
}
private static void Remember(string key, Entry entry)
{
_byKey[key] = entry;
_order.Enqueue(key);
while (_order.Count > Cap)
{
var oldest = _order.Dequeue();
Entry dropped;
if (!_byKey.TryGetValue(oldest, out dropped))
continue;
_byKey.Remove(oldest);
// Expired keys leave silently; they are supposed to. A key evicted while still
// inside its TTL is the guarantee's one hole, so it never leaves quietly.
if (DateTime.UtcNow - dropped.Reserved < Ttl)
{
_evicted++;
Console.WriteLine(
"[Bridge] idempotency: evicted key {0} ({1}) while still live — the cap of {2} was reached, so a repeat of it WOULD be applied again ({3} so far)",
oldest, dropped.Kind, Cap, _evicted);
}
}
}
/// <summary>Drops keys past their TTL. Runs on the command path, which is human-rate.</summary>
private static void Sweep()
{
if (_order.Count == 0)
return;
var cutoff = DateTime.UtcNow - Ttl;
while (_order.Count > 0)
{
var oldest = _order.Peek();
Entry entry;
if (!_byKey.TryGetValue(oldest, out entry))
{
_order.Dequeue();
continue;
}
if (entry.Reserved > cutoff)
return; // insertion-ordered, so nothing behind this is older
_order.Dequeue();
_byKey.Remove(oldest);
}
}
}
}