From 4e290f00d86ebd320d2da609fd7cd15d7175c4f0 Mon Sep 17 00:00:00 2001 From: Erik Date: Wed, 29 Jul 2026 16:26:06 +0200 Subject: [PATCH] feat(net): N5 - loss observability, lossy decorator, the connected loss gate Campaign N Slice N5 (docs/plans/2026-07-29-network-transport-campaign.md section 8 rung 3): the permanent removal of the loopback blindness that let #260 ship. Local ACE never drops a datagram, so every historical connected gate was structurally incapable of exercising the N1-N4 recovery machinery; from this slice on, tools/run-connected-loss-gate.ps1 runs the standard lifecycle route through deterministic seeded loss and passes only on proven non-zero recovery. Observability: - [net-tick] gains resend/s nak-out/s nak-in/s rej-in/s dup-drop/s parked/s reclaim/s cache= nakset= - TransportStats window deltas mirroring the acks/s cumulative-delta pattern, plus the two instantaneous depths (the unbounded-like-retail sent-packet cache watchdog and the inbound NAK set). TransportStats gains RejectsReceived (inbound RejectRetransmit packets). Counters increment unconditionally; every string is behind NetDiagnostics.ProbeNet (Code Structure Rule 5). - WorldSession.Dispose emits one cumulative [net-final] totals line so the loss gate asserts exact counters instead of reconstructing them from rounded per-second rates. - LinkStatusSnapshot.PacketLossPercentage is deliberately NOT wired: filed #261 - retail's CLinkStatusAverages formula (LinkStatusHolder::GetPacketLossPercentage @ 0x00411370) must be located first; inventing a ratio is forbidden. N4-review F3 fold-in: - Fresh reliable sends stamp Header.Iteration = the session iteration through the same shared retail header build already cited for Time (N3) and the N4 control packets: FlowQueue::TransmitNewPackets @ 0x00547A60, the stack build at 0x00547A84/0x00547AA8. The control-header rule now holds across all three send shapes (fresh reliable, ack, NAK). ACE reads neither Time nor Iteration inbound (campaign section 3) - wire-safe, and resends keep the stamp verbatim per the N1 rebuild rule. Loss injection (Transport/LossyTransportDecorator): - IWorldSessionTransport wrapper with deterministic seeded per-direction loss. Config via NetDiagnostics typed env properties read once: ACDREAM_NET_DROP_PCT (0 = off = default), ACDREAM_NET_DROP_SEED (default 1), ACDREAM_NET_DROP_DIR (out|in|both, default both). - Arming gate: NOTHING drops in either direction until the decorator has FORWARDED the first ENCRYPTED outbound datagram - parse-free check on length > 20 with EncryptedChecksum set in the LE flags word at bytes 4..8. The cleartext handshake always survives and the arming datagram is never a casualty; handshake-loss testing belongs to N6's ConnectResponse 0.333 s retransmit. - Structurally absent at 0%: WrapIfConfigured returns the raw transport - WorldSession's default factory is the only production seam and a normal run never constructs the decorator. Root-cause fix the gate immediately exposed: - The logoff-confirmation wait in Dispose processed inbound datagrams but never pumped the transport, so a lost S2C logoff confirmation was gap-detected but its healing NAK never went out. Retail's pump (Client::UseTime @ 0x00411C40 -> PacketController::UseTime @ 0x005410D0) runs until LogOffServer; the wait now sweeps per processed datagram, making the logoff wait the third covered blocking pump (after Tick and the handshake loops). A lost C2S logoff REQUEST remains unrecoverable by ACE design (arrival-driven NAK; a quiet client is never NAKed - campaign section 3 row 1), recorded in the gate header. Gates: - tools/run-connected-loss-gate.ps1 (-DropPct 2 -Seed 1): PASS vs local ACE - the first automated observation of packet loss in project history. Decorator ledger: dropped out=3 in=10 of forwarded out=183 in=496. [net-final] resends=2 nak-in=2 nak-out=6 rej-in=0 acks-out=114 acks-in=119 dup-drop=0 sanity-drop=0 cksum-fail=0 parked=9 reclaimed=0 uncached-nak=0 cache=1 nakset=0. Every injected loss healed: both ACE-driven C2S resend recovery (nak-in=2 -> resends=2) and client-driven S2C NAK recovery (parked=9 -> nak-out=6) fired on a real connected route, all six checkpoints validated, graceful logout confirmed, ACE recorded the transport Disconnect. - tools/run-connected-world-lifecycle-gate.ps1 (decorator absent): PASS - zero behavior change on the no-loss baseline; the gate now defensively clears the drop env vars. - Core.Net Release: 747/747 (737 + 10 N5: decorator determinism/direction/ arming/structural-absence/env parsing, the 5% seeded WorldSession lossy lifecycle with zero message loss both ways + ACE Headroom 256, the [net-tick] field pins, the Iteration stamps). - Full solution Release: 9,763 passed / 5 skipped / 0 failed. Test-fixture note: FakeAceTransport gains AutoAdvanceOnBlockingReceive so virtual time can move during the blocking Connect()/EnterWorld() pumps - with the clock frozen there, a dropped handshake-window datagram could never be NAK-healed (a fixture artifact, not a transport property). Campaign section 9 ledger row added (SHA recorded at N6 kickoff). Co-Authored-By: Claude Sonnet 5 --- docs/ISSUES.md | 22 + .../2026-07-29-network-transport-campaign.md | 2 +- src/AcDream.Core.Net/NetDiagnostics.cs | 69 ++- .../Transport/LossyTransportDecorator.cs | 234 +++++++++ .../Transport/OutboundFlowQueue.cs | 20 +- .../Transport/ReliableTransport.cs | 1 + .../Transport/TransportStats.cs | 5 + src/AcDream.Core.Net/WorldSession.cs | 169 +++++- tests/AcDream.Core.Net.Tests/NetProbeTests.cs | 143 +++++ .../Transport/FakeAceTransport.cs | 17 + .../Transport/LossyTransportDecoratorTests.cs | 463 +++++++++++++++++ .../OutboundReliableTransportTests.cs | 17 +- tools/run-connected-loss-gate.ps1 | 488 ++++++++++++++++++ tools/run-connected-world-lifecycle-gate.ps1 | 6 + 14 files changed, 1629 insertions(+), 27 deletions(-) create mode 100644 src/AcDream.Core.Net/Transport/LossyTransportDecorator.cs create mode 100644 tests/AcDream.Core.Net.Tests/NetProbeTests.cs create mode 100644 tests/AcDream.Core.Net.Tests/Transport/LossyTransportDecoratorTests.cs create mode 100644 tools/run-connected-loss-gate.ps1 diff --git a/docs/ISSUES.md b/docs/ISSUES.md index 24ecb5dc..a36232c6 100644 --- a/docs/ISSUES.md +++ b/docs/ISSUES.md @@ -97,6 +97,28 @@ Copy this block when adding a new issue: --- +## #261 — Wire LinkStatusSnapshot.PacketLossPercentage from retail's formula + +**Status:** OPEN +**Severity:** LOW +**Filed:** 2026-07-29 +**Component:** net (link-status presentation) + +**Description:** `LinkStatusSnapshot.PacketLossPercentage` +(`src/AcDream.Core.Net/LinkStatusSnapshot.cs:11`) is a permanent default 0 — +the indicator UI renders it but nothing computes it. Campaign N Slice N5's +`TransportStats` now counts every input a loss figure could want (resends, +NAKs both directions, duplicate drops, parked words), but **locate retail's +`CLinkStatusAverages` loss formula (see +`LinkStatusHolder::GetPacketLossPercentage @ 0x00411370`) before wiring +PacketLossPercentage; inventing a ratio is forbidden** — the displayed number +must be retail's windowed average, not an acdream-invented counter quotient. + +**Acceptance:** the ported formula cites the named-retail symbol + address, +and the indicator shows non-zero loss under `tools/run-connected-loss-gate.ps1`. + +--- + ## #260 — Portal-network wedge: outbound actions die + native/GPU memory climbs **Status:** ROOT-CAUSED 2026-07-29 — **fix in flight as Campaign N** diff --git a/docs/plans/2026-07-29-network-transport-campaign.md b/docs/plans/2026-07-29-network-transport-campaign.md index 0ae4a0a5..a211b450 100644 --- a/docs/plans/2026-07-29-network-transport-campaign.md +++ b/docs/plans/2026-07-29-network-transport-campaign.md @@ -256,5 +256,5 @@ verbatim in each implementer prompt. | N2 | complete | `46d209d0` — **Fable review PASS** (tracker/codec-split/admission verified pre-commit against retail rules; gates lifecycle+nine-stop both PASS) | Inbound sequence-aligned ISAAC + NAK set (`Transport/InboundSequenceTracker`: watermark, sanity window, duplicate/parked-key path, sequence-ordered gap-walk pre-draw, verify-failure re-park, RejectRetransmit abandonment — `ProcessNewSeqNum @ 0x00544690`, `ProcessNewestSeqNum @ 0x00541930`, `SeqIDSanityCheck @ 0x00543A20`, `AddNakked @ 0x00549240`, `HandleEmptyAck @ 0x005448F0`); `PacketCodec` split into keystream-free `TryParseBorrowed` + `VerifyChecksum` (`TryDecodeBorrowed` deleted); `RejectRetransmit` ids exposed on both optional-header decoders; `ReliableTransport` now owns both keystreams; stats gained `InboundDupsDropped`/`InboundSanityDrops`/`ChecksumFailures`/`KeysParked`. Watermark init 1 is the AD-50 ACE adaptation (retail zero-init vs ACE's re-prime dance — first encrypted S2C is sequence 2; holtburger api.rs:30 agrees); pinned by the clean-lifecycle conformance test (zero NAKs, min encrypted S2C sequence == 2). 716 Core.Net tests green. **N3/N4 handoff note:** the interim per-packet reflex ack acks the ARRIVING sequence even while a gap is parked, so ACE prunes the lost id from its S2C cache (`AcknowledgeSequence` strictly-below) before N4 can NAK it — message-level recovery of a real loss needs N3's retail NAK-xor-ack sweep (§2.3's mutual exclusivity is load-bearing). Also noted for N4: ACE's `RejectRetransmit` consumes a fresh CLEARTEXT sequence via FlushPackets (no keystream word), so the client's gap walk parks a word for an id that never had one server-side — a real retail-vs-ACE incompatibility to resolve in N4's design (retail never assigns new sequences to cleartext). | | N3 | complete | `0265cc42` — Opus review PASS (advisories folded into N4: transitional-state wording, SharedInit citation, pump-order wording, control-packet Time/Iteration rule, stale budget-break comment) | AckNakScheduler + 2.0 s cumulative ack (`Transport/AckNakScheduler`): ONE shared timestamp (`ReceiverData::timeStamp_` @ +0x10) arbitrating NAK-xor-ack per sweep (`ClientNet::ProcessConnection @ 0x00545450`); the ack is one cleartext exact-flags `AckSequence` carrying the tracker's `highestIDReceived_` behind the >= 2.0 s gate (`SharedNet::EnqueuePak @ 0x00543B10` — the binary's only 0x4000 construction site), armed at connection birth (`ReceiverData::Init @ 0x00548EF0`). The Phase 4.9 per-packet reflex ack and `WorldSession.SendAck` are DELETED; the `[net-tick]` acks/s probe now reads `Stats.AcksSent`. Sweep order per `FlowQueue::Empty @ 0x00548A20`: interval clock, NAK/ack arbitration, pending resends, prune. **N3 transitional state (closed by N4):** a non-empty NAK set suppressed the ack and emitted NOTHING — the exposure was real even on loopback, just low-probability: one receive-buffer drop parks an id, every later sweep takes the silent NAK branch, acks stop (witness: `[net-tick] acks/s=0`), and ACE disconnects the quiet session at its 60 s timeout. N4 completed the branch. **N1 advisory retired (fold-in):** fresh reliable sends now stamp `Header.Time` = the current interval id (`FlowQueue::TransmitNewPackets @ 0x00547A60`, header build at 0x00547A84); ACE ignores inbound `Header.Time`, so the wire is unaffected. New `WorldSession.TransportClockSource` seam drives the gate on virtual time. 723 Core.Net tests green (keepalive property proven: a quiet session's 2 s acks refresh ACE's 60 s deadline across a 120 s virtual horizon; storm collapse: a 50-packet flood → ONE ack; the model accepts the reused-sequence ack without advancing its watermark). Connected lifecycle + canonical nine-stop gates PASS. | | N4 | complete | `852a59e3` — **Opus review PASS** (reclaim invariant attacked from five angles, held; NAK fidelity verified to the x87 masks; AP-125 filed + F1 false-arithmetic wording + F5 ordinal sentinel fixed in the acceptance commit; F3 Iteration-on-fresh-sends folds into N5) | Client NAK emission + RejectRetransmit consumption. `AckNakScheduler` completes the NAK branch: one cleartext exact-flags `RequestRetransmit` per sweep behind the STRICT 0.6 s gate on the ONE shared timestamp (`SharedNet::EnqueueNaks @ 0x00543BD0` — the 0x41-mask x87 test at 0x00543C03 proceeds only on strictly-greater, contrast the ack's >=), body u32 count + ids ascending capped at 114 (`ReceiverData::GetNaks @ 0x005490C0`, cap 0x72), borrowed sequence, never an ack in a NAK sweep. Control-header rule decided for BOTH emissions: `Time` = interval id, `Iteration` = session iteration, per the shared retail header build (`FlowQueue::TransmitNewPackets @ 0x00547A60` @ 0x00547A84); ACE reads neither. THE design piece: the AD-51 reclaimed-word pool in `InboundSequenceTracker` closes the ACE cleartext-reject keystream hazard the N2 ledger row recorded — ACE's `RejectRetransmit` consumes a fresh cleartext sequence with NO keystream word, so the gap walk mis-parks a word for it and the whole inbound stream runs one word ahead. On a VALIDATED cleartext reject (`WorldSession` calls `OnCleartextRejectSequence` post-checksum), the tracker removes the mis-park, bubble-shifts every later-drawn parked word down one position (per-word draw ordinals; ascending id ⇔ ascending draw order), and pools the excess for the next fresh draws, consumed lowest-draw-order-first — exact for any number of interleaved rejects in any arrival order (a plain FIFO is NOT: reject-after-higher-arrival crosses the parked chain, and dual out-of-order rejects pool out of draw order — both pinned by tests). Reject BODY ids keep N2's discard (word-bearing server-side, consumed-in-place). N3 advisories all folded: honest transitional wording (above), `ReceiverData::SharedInit @ 0x00548EF0` (from `Init @ 0x00548FA0`) citation, `FlowQueue::Empty` pump-order comment (TransmitNaks → TransmitAcks → TransmitNewPackets, interval increment LAST @ 0x00548A9D; our clock-first order is cosmetic vs ACE), the Time/Iteration rule, and the stale `WorldSession` budget-break comment. Gate arithmetic hardened: gate ticks now round (0.6 has no exact double; truncation opened the strict gate AT the boundary). 737 Core.Net tests green, including: strict-gate boundary, shared-timestamp both directions, NAK-suppresses-ack, full wire-shape + 114-cap pins, model-served retransmission round trip, five tracker reclaim proofs, the 130-s virtual prune → fresh-sequence reject system test (victim abandoned, later traffic decodes, pool drains to zero), 10 s long-loss (NAKs on the gate cadence, zero acks, heal inside the window), and the capstone soak: 2% seeded bidirectional loss × 10,000 messages → zero message loss both ways, ACE crypto headroom 256 at convergence with a ≥250 no-erosion floor mid-flight, NAK set / reclaim pool / pending resends / ACE out-of-order buffer all zero, cache at the single watermark entry (retail Flush prunes STRICTLY below the ack). Soak notes: ACE never NAKs a quiet client (§3 row 1), so convergence keeps a C2S trickle flowing — a real idle-client tail loss heals only on the next action, an ACE constraint outside N4's scope. | -| N5 | pending | — | | +| N5 | complete | SHA recorded at N6 kickoff | Loss observability + the LossyTransportDecorator + the connected loss gate — the permanent removal of the loopback blindness (§1). `[net-tick]` gains `resend/s nak-out/s nak-in/s rej-in/s dup-drop/s parked/s reclaim/s cache= nakset=` (window deltas mirroring acks/s; `TransportStats` gains `RejectsReceived`; string work probe-gated, counters unconditional) and `WorldSession.Dispose` emits one cumulative `[net-final]` totals line so the gate asserts exact counters, not rounded rates. N4-review F3 folded: fresh reliable sends stamp `Iteration` = the session iteration through the same shared retail header build already cited for `Time` and the N4 control packets (`FlowQueue::TransmitNewPackets @ 0x00547A60`, the build at 0x00547A84/0x00547AA8) — the control-header rule now holds across all three send shapes; ACE reads neither field inbound. `Transport/LossyTransportDecorator`: deterministic seeded per-direction loss (`ACDREAM_NET_DROP_PCT`/`_SEED`/`_DIR` via `NetDiagnostics` typed properties, Rule 5), armed only after the first ENCRYPTED outbound datagram is forwarded (parse-free flags-word check — the cleartext handshake always survives; handshake loss belongs to N6), structurally absent at 0% (`WrapIfConfigured` returns the raw transport; the default factory is the only production seam). The logoff-confirmation wait now runs the transport sweep — retail's pump (`Client::UseTime @ 0x00411C40`) never stops before `LogOffServer`, and the loss gate exposed that a dropped S2C confirmation was gap-detected but never NAKed during `Dispose`. `tools/run-connected-loss-gate.ps1` (default 2%/seed 1) runs the standard lifecycle route through the decorator vs local ACE and FAILS unless `[net-final]` shows resends>0 OR nak-out>0 OR nak-in>0 AND the decorator's own dropped ledger is non-zero — a loss gate that never dropped proves nothing, asserted explicitly. The lifecycle gate defensively clears the drop vars (decorator-absent baseline). **First loss-observing gate evidence (2026-07-29, 2%/seed 1, local ACE):** decorator dropped out=3 in=10 of forwarded out=183 in=496; `[net-final] resends=2 nak-in=2 nak-out=6 rej-in=0 acks-out=114 acks-in=119 dup-drop=0 sanity-drop=0 cksum-fail=0 parked=9 reclaimed=0 uncached-nak=0 cache=1 nakset=0` — both recovery directions fired on a real connected route (ACE NAK → cached resend; client gap-walk park → NAK → ACE retransmit), all six checkpoints validated, graceful logout confirmed, ACE recorded the transport Disconnect, RESULT=PASS. The gate immediately paid for itself: it exposed that the Dispose logoff-confirmation wait processed inbound but never swept the transport, so a lost S2C confirmation could be gap-detected yet never NAKed — fixed by running the sweep in that third blocking pump (retail's `Client::UseTime @ 0x00411C40` pump runs until `LogOffServer`). Known tail caveat recorded in the gate header: a drop landing on the single-shot logoff request or transport Disconnect (~pct each) is unrecoverable by ACE's arrival-driven NAK design (§3 row 1) — rerun with another seed, never widen teardown tolerances. #261 filed for `LinkStatusSnapshot.PacketLossPercentage` (retail `CLinkStatusAverages` formula required; inventing a ratio forbidden). 747 Core.Net tests green (decorator determinism/direction/arming/structural-absence, the 5% seeded WorldSession lossy lifecycle with zero message loss + Headroom 256, `[net-tick]` field pins, Iteration-stamp pins). | | N6 | pending | — | | diff --git a/src/AcDream.Core.Net/NetDiagnostics.cs b/src/AcDream.Core.Net/NetDiagnostics.cs index e885dd25..dfd1e74f 100644 --- a/src/AcDream.Core.Net/NetDiagnostics.cs +++ b/src/AcDream.Core.Net/NetDiagnostics.cs @@ -1,11 +1,23 @@ namespace AcDream.Core.Net; +/// +/// Direction mask for the N5 LossyTransportDecorator +/// (ACDREAM_NET_DROP_DIR): drop outbound datagrams, inbound +/// datagrams, or both. +/// +public enum NetDropDirection +{ + Out, + In, + Both, +} + /// /// Diagnostic owner for the ACDREAM_PROBE_NET probe family (#260). /// Read once at startup, following the PhysicsDiagnostics pattern. /// /// -/// When enabled, three probe line families are emitted: +/// When enabled, four probe line families are emitted: /// /// [net-out] — one line per outbound reliable game message at the /// WorldSession.SendGameMessage chokepoint: opcode, game-action type + @@ -16,7 +28,16 @@ namespace AcDream.Core.Net; /// [net-tick] — a once-per-second cadence summary from /// WorldSession.Tick: inbound datagrams/s, remaining queue depth, /// budget-break count, worst inter-tick gap (= worst frame stall as seen by -/// the net pump), outbound sends/s, and acks/s. +/// the net pump), outbound sends/s, acks/s, and — the N5 loss-observability +/// extension — per-second reliable-transport rates (resends, NAKs out/in, +/// rejects in, duplicate drops, parked keystream words, AD-51 reclaims) +/// plus the two instantaneous depths (sent-packet cache, inbound NAK set). +/// The counters themselves increment unconditionally in +/// TransportStats; only the string work is gated here. +/// [net-final] — one cumulative TransportStats summary +/// emitted at WorldSession.Dispose, so a connected gate (N5's loss +/// gate) can assert exact totals instead of reconstructing them from +/// rounded per-second rates. /// [cmd-gate] — one line per generation-gated runtime command /// REJECTION in CurrentGameRuntimeCommandAdapter.Validate (status, /// expected vs view generation, lifecycle, IsInWorld) plus the combat-toggle @@ -34,6 +55,50 @@ public static class NetDiagnostics public static bool ProbeNet { get; set; } = Environment.GetEnvironmentVariable("ACDREAM_PROBE_NET") == "1"; + /// + /// ACDREAM_NET_DROP_PCT (int 0–100, default 0 = off) — N5 + /// deterministic loss injection. When > 0 the session's DEFAULT + /// transport factory wraps the socket transport in + /// LossyTransportDecorator; at 0 the decorator is structurally + /// absent (never constructed). Out-of-range or unparsable values read + /// as 0 — a mistyped variable must never inject loss. + /// + public static int NetDropPercent { get; set; } = + ParseDropPercent( + Environment.GetEnvironmentVariable("ACDREAM_NET_DROP_PCT")); + + /// + /// ACDREAM_NET_DROP_SEED (int, default 1) — the decorator's PRNG + /// seed. Same seed ⇒ identical per-direction drop pattern. + /// + public static int NetDropSeed { get; set; } = + int.TryParse( + Environment.GetEnvironmentVariable("ACDREAM_NET_DROP_SEED"), + out int seed) + ? seed + : 1; + + /// + /// ACDREAM_NET_DROP_DIR (out | in | both, + /// default both) — which directions the decorator drops. + /// + public static NetDropDirection NetDropDir { get; set; } = + ParseDropDirection( + Environment.GetEnvironmentVariable("ACDREAM_NET_DROP_DIR")); + + internal static int ParseDropPercent(string? value) => + int.TryParse(value, out int percent) && percent is >= 0 and <= 100 + ? percent + : 0; + + internal static NetDropDirection ParseDropDirection(string? value) => + value?.ToLowerInvariant() switch + { + "out" => NetDropDirection.Out, + "in" => NetDropDirection.In, + _ => NetDropDirection.Both, + }; + /// /// ACDREAM_PROBE_REVEAL=1 — #260 reveal-stall probe: while a /// reveal destination's composite warmup is incomplete, emit one diff --git a/src/AcDream.Core.Net/Transport/LossyTransportDecorator.cs b/src/AcDream.Core.Net/Transport/LossyTransportDecorator.cs new file mode 100644 index 00000000..56487ff0 --- /dev/null +++ b/src/AcDream.Core.Net/Transport/LossyTransportDecorator.cs @@ -0,0 +1,234 @@ +using System.Buffers.Binary; +using System.Diagnostics; +using System.Net; +using AcDream.Core.Net.Packets; + +namespace AcDream.Core.Net.Transport; + +/// +/// Campaign N Slice N5: deterministic seeded packet-loss injection around a +/// real — the permanent removal of the +/// loopback blindness that let #260 ship (local ACE never drops a datagram, +/// so every historical connected gate was structurally incapable of +/// exercising the N1–N4 recovery machinery). The connected loss gate +/// (tools/run-connected-loss-gate.ps1) runs the standard lifecycle +/// route through this decorator and passes only when the transport counters +/// prove real loss was injected AND healed. +/// +/// +/// Configuration comes from the typed +/// env-var owner (Code Structure Rule 5 — read once at startup): +/// ACDREAM_NET_DROP_PCT (0 = off), ACDREAM_NET_DROP_SEED, and +/// ACDREAM_NET_DROP_DIR. is the ONLY +/// production entry point, and it returns the inner transport untouched when +/// the percentage is zero — a normal run never constructs the decorator +/// (structural absence, not an inert wrapper). +/// +/// +/// +/// The arming gate: nothing is dropped in either direction until the +/// decorator has FORWARDED the first ENCRYPTED outbound datagram — detected +/// parse-free as length > 20 with set in the little-endian +/// flags word at bytes 4..8. That first encrypted send only exists after +/// ISAAC negotiation, so the cleartext handshake (LoginRequest → +/// ConnectRequest → ConnectResponse) always completes intact and the arming +/// datagram itself is never dropped. Handshake-loss testing is deliberately +/// out of scope here — it belongs to N6's ConnectResponse 0.333 s +/// retransmit (campaign doc §6). +/// +/// +/// +/// Determinism: one per direction (outbound +/// seeded with seed, inbound with ~seed so the two streams +/// differ), consumed only for droppable datagrams (post-arming, direction +/// enabled), so a given seed yields an identical per-direction drop pattern +/// for a given datagram sequence. Threading matches the transport contract: +/// sends happen on the session's frame thread, receives on the single +/// receive owner, so each PRNG is single-consumer; only the arming latch +/// crosses the two. +/// +/// +internal sealed class LossyTransportDecorator : IWorldSessionTransport +{ + private readonly IWorldSessionTransport _inner; + private readonly int _dropPercent; + private readonly Random _outboundRandom; + private readonly Random _inboundRandom; + private readonly bool _dropOutbound; + private readonly bool _dropInbound; + private volatile bool _armed; + + private int _outboundDropped; + private int _inboundDropped; + private int _outboundForwarded; + private int _inboundForwarded; + + /// Outbound datagrams eaten so far (diagnostic evidence for the + /// loss gate's "the decorator actually dropped" assertion). + public int OutboundDropped => Volatile.Read(ref _outboundDropped); + + /// Inbound datagrams eaten so far. + public int InboundDropped => Volatile.Read(ref _inboundDropped); + + /// True once the first encrypted outbound datagram has been + /// forwarded (the arming gate above). + public bool IsArmed => _armed; + + public LossyTransportDecorator( + IWorldSessionTransport inner, + int dropPercent, + int seed, + NetDropDirection direction) + { + ArgumentNullException.ThrowIfNull(inner); + ArgumentOutOfRangeException.ThrowIfLessThan(dropPercent, 1); + ArgumentOutOfRangeException.ThrowIfGreaterThan(dropPercent, 100); + + _inner = inner; + _dropPercent = dropPercent; + _outboundRandom = new Random(seed); + _inboundRandom = new Random(~seed); + _dropOutbound = direction is NetDropDirection.Out or NetDropDirection.Both; + _dropInbound = direction is NetDropDirection.In or NetDropDirection.Both; + Console.WriteLine( + $"[net-loss] active pct={dropPercent} seed={seed} dir={direction}"); + } + + /// + /// The production seam: wrap only when + /// is non-zero. At zero the + /// decorator is never constructed — the default transport path is + /// byte-for-byte the pre-N5 one. + /// + public static IWorldSessionTransport WrapIfConfigured( + IWorldSessionTransport inner) => + NetDiagnostics.NetDropPercent > 0 + ? new LossyTransportDecorator( + inner, + NetDiagnostics.NetDropPercent, + NetDiagnostics.NetDropSeed, + NetDiagnostics.NetDropDir) + : inner; + + // ---- outbound ---- + + public void Send(ReadOnlySpan datagram) + { + if (DropOutbound()) + return; + _inner.Send(datagram); + AfterOutboundForwarded(datagram); + } + + public void Send(IPEndPoint remote, ReadOnlySpan datagram) + { + if (DropOutbound()) + return; + _inner.Send(remote, datagram); + AfterOutboundForwarded(datagram); + } + + private bool DropOutbound() + { + if (!_armed || !_dropOutbound) + return false; + if (_outboundRandom.Next(100) >= _dropPercent) + return false; + Interlocked.Increment(ref _outboundDropped); + return true; + } + + private void AfterOutboundForwarded(ReadOnlySpan datagram) + { + Interlocked.Increment(ref _outboundForwarded); + if (_armed) + return; + // The arming gate: bytes 4..8 are the little-endian + // PacketHeaderFlags word of the fixed 20-byte header. The first + // forwarded datagram carrying EncryptedChecksum proves negotiation + // completed; from the NEXT datagram on, drops are live. + if (datagram.Length > PacketHeader.Size + && (BinaryPrimitives.ReadUInt32LittleEndian(datagram.Slice(4)) + & (uint)PacketHeaderFlags.EncryptedChecksum) != 0) + { + _armed = true; + Console.WriteLine("[net-loss] armed"); + } + } + + // ---- inbound ---- + + public int Receive( + Span destination, + TimeSpan timeout, + out IPEndPoint? from) + { + // The first inner call gets the caller's timeout verbatim, so the + // no-drop path is behavior-identical to the undecorated transport. + // Only a drop re-enters the loop with the remaining time. + long deadline = Stopwatch.GetTimestamp() + + (long)(timeout.TotalSeconds * Stopwatch.Frequency); + TimeSpan next = timeout; + while (true) + { + int length = _inner.Receive(destination, next, out from); + if (length < 0) + return length; // inner timeout contract: -1 + if (!DropInbound()) + { + Interlocked.Increment(ref _inboundForwarded); + return length; + } + + double remainingMs = + (deadline - Stopwatch.GetTimestamp()) + * 1000.0 / Stopwatch.Frequency; + if (remainingMs < 1.0) + { + // Expired while eating datagrams. NetClient treats a 0 ms + // socket timeout as INFINITE, so never pass ≤ 0 back down. + from = null; + return -1; + } + + next = TimeSpan.FromMilliseconds(remainingMs); + } + } + + public async ValueTask ReceiveAsync( + Memory destination, + CancellationToken cancellationToken) + { + while (true) + { + NetReceiveResult result = await _inner + .ReceiveAsync(destination, cancellationToken) + .ConfigureAwait(false); + if (DropInbound()) + continue; + Interlocked.Increment(ref _inboundForwarded); + return result; + } + } + + private bool DropInbound() + { + if (!_armed || !_dropInbound) + return false; + if (_inboundRandom.Next(100) >= _dropPercent) + return false; + Interlocked.Increment(ref _inboundDropped); + return true; + } + + public void Dispose() + { + Console.WriteLine( + $"[net-loss] dropped out={OutboundDropped} in={InboundDropped}" + + $" forwarded out={Volatile.Read(ref _outboundForwarded)}" + + $" in={Volatile.Read(ref _inboundForwarded)}" + + $" armed={_armed}"); + _inner.Dispose(); + } +} diff --git a/src/AcDream.Core.Net/Transport/OutboundFlowQueue.cs b/src/AcDream.Core.Net/Transport/OutboundFlowQueue.cs index 97fbe26f..26c2ee87 100644 --- a/src/AcDream.Core.Net/Transport/OutboundFlowQueue.cs +++ b/src/AcDream.Core.Net/Transport/OutboundFlowQueue.cs @@ -58,6 +58,7 @@ internal sealed class OutboundFlowQueue : IDisposable private readonly SentPacketStore _store; private readonly ArrayPool _pool; private readonly ushort _sessionClientId; + private readonly ushort _sessionIteration; /// Wrap-safe sorted pending NAKed ids awaiting the next sweep /// (FlowQueue::EnqueueAcks @ 0x005488E0 merge-insert). @@ -83,6 +84,7 @@ internal sealed class OutboundFlowQueue : IDisposable public OutboundFlowQueue( IsaacRandom outboundIsaac, ushort sessionClientId, + ushort sessionIteration, TransportClock clock, TransportStats stats, DatagramSendDelegate send, @@ -97,6 +99,7 @@ internal sealed class OutboundFlowQueue : IDisposable _outboundIsaac = outboundIsaac; _sessionClientId = sessionClientId; + _sessionIteration = sessionIteration; _clock = clock; _stats = stats; _send = send; @@ -118,12 +121,16 @@ internal sealed class OutboundFlowQueue : IDisposable /// it, THEN cache it (retail commits to the sent-packet store only after /// a successful send — FlowQueue::TransmitNewPackets @ 0x00547C85). /// Flags BlobFragments|EncryptedChecksum, session client id, one - /// ISAAC word, and — the N3 fold-in of the N1 review advisory — - /// Time = the current interval id: retail stamps - /// CurLocalInterval_.intervalID_ on every fresh packet - /// (FlowQueue::TransmitNewPackets @ 0x00547A60, the header build - /// at 0x00547A84). ACE never reads inbound Header.Time - /// (campaign §3), so wire compatibility is unaffected. + /// ISAAC word, and the retail control-header rule completed across all + /// three send shapes (fresh reliable here; ack + NAK in + /// ): Time = the current interval id + /// (the N3 fold-in of the N1 review advisory) and Iteration = the + /// session iteration (the N5 fold-in of the N4 review advisory F3). + /// Retail stamps both through one shared header build + /// (FlowQueue::TransmitNewPackets @ 0x00547A60, the stack build + /// at 0x00547A84/0x00547AA8 — CurLocalInterval_.intervalID_ plus + /// the receiver iteration). ACE reads neither field inbound (campaign + /// §3), so wire compatibility is unaffected. /// public void SendGameMessage( ReadOnlySpan gameMessageBody, @@ -147,6 +154,7 @@ internal sealed class OutboundFlowQueue : IDisposable | PacketHeaderFlags.EncryptedChecksum, Id = _sessionClientId, Time = _clock.IntervalId, + Iteration = _sessionIteration, }; int datagramLength = PacketCodec.FinalizeInPlace( header, diff --git a/src/AcDream.Core.Net/Transport/ReliableTransport.cs b/src/AcDream.Core.Net/Transport/ReliableTransport.cs index 7eb27ee7..16b64f09 100644 --- a/src/AcDream.Core.Net/Transport/ReliableTransport.cs +++ b/src/AcDream.Core.Net/Transport/ReliableTransport.cs @@ -54,6 +54,7 @@ internal sealed class ReliableTransport : IDisposable Outbound = new OutboundFlowQueue( outboundIsaac, sessionClientId, + sessionIteration, Clock, Stats, send, diff --git a/src/AcDream.Core.Net/Transport/TransportStats.cs b/src/AcDream.Core.Net/Transport/TransportStats.cs index 96382af3..4b998af9 100644 --- a/src/AcDream.Core.Net/Transport/TransportStats.cs +++ b/src/AcDream.Core.Net/Transport/TransportStats.cs @@ -62,6 +62,11 @@ internal sealed class TransportStats /// adaptation; always zero against a retail server). public long RejectWordsReclaimed; + /// N5: inbound packets carrying RejectRetransmit — the + /// server abandoned ids we NAKed (its cache pruned them). The + /// rej-in/s field of [net-tick]. + public long RejectsReceived; + /// Live sent-packet cache depth — the N5 watchdog value /// (cache=N in [net-tick]; the cache is unbounded like /// retail's, so depth is the health signal, not a cap). diff --git a/src/AcDream.Core.Net/WorldSession.cs b/src/AcDream.Core.Net/WorldSession.cs index 4658374e..13c836e6 100644 --- a/src/AcDream.Core.Net/WorldSession.cs +++ b/src/AcDream.Core.Net/WorldSession.cs @@ -67,10 +67,13 @@ internal sealed class NetClientWorldSessionTransport(IPEndPoint remote) /// /// /// -/// Still deferred: inbound sequence-aligned ISAAC + client NAK -/// emission (Campaign N slices N2/N4) and unsolicited-disconnect recovery. -/// The outbound sent-packet cache + resend on server NAK (N1), ACKs, world -/// updates, chat, and retail-ordered graceful logout are live. +/// Still deferred: unsolicited-disconnect recovery and the optional +/// N6 handshake hardening (ConnectResponse 0.333 s retransmit). The full +/// Campaign N reliable transport is live in both directions: outbound +/// sent-packet cache + resend on server NAK (N1), inbound sequence-aligned +/// ISAAC + NAK set (N2), the retail 2.0 s cumulative-ack sweep (N3), client +/// NAK emission + RejectRetransmit reclaim (N4), and the N5 loss +/// observability + deterministic loss injection seam. /// /// public sealed class WorldSession : IDisposable @@ -761,7 +764,13 @@ public sealed class WorldSession : IDisposable public WorldSession(IPEndPoint serverLogin) : this( serverLogin, - static endpoint => new NetClientWorldSessionTransport(endpoint)) + // N5: ACDREAM_NET_DROP_PCT > 0 wraps the socket transport in the + // deterministic LossyTransportDecorator (the connected loss + // gate's injection point). At the default 0 the decorator is + // structurally absent — WrapIfConfigured returns the raw + // transport and never constructs the wrapper. + static endpoint => LossyTransportDecorator.WrapIfConfigured( + new NetClientWorldSessionTransport(endpoint))) { } @@ -1124,6 +1133,16 @@ public sealed class WorldSession : IDisposable private int _probeBudgetBreaks; private int _probeSendWindow; private long _probeAckSeenTotal; + // N5 loss-observability window baselines — the cumulative TransportStats + // value each counter had when the probe last printed, mirroring + // _probeAckSeenTotal. Only touched when NetDiagnostics.ProbeNet is set. + private long _probeResendSeenTotal; + private long _probeNakOutSeenTotal; + private long _probeNakInSeenTotal; + private long _probeRejInSeenTotal; + private long _probeDupDropSeenTotal; + private long _probeParkedSeenTotal; + private long _probeReclaimSeenTotal; // Probe-owned queue depth: the SingleReader channel's Reader.Count // throws NotSupportedException, so the net thread increments on // enqueue and the frame thread decrements on dequeue instead. @@ -1158,23 +1177,100 @@ public sealed class WorldSession : IDisposable double windowSeconds = (double)windowTicks / Stopwatch.Frequency; double maxGapMs = _probeMaxGapTicks * 1000.0 / Stopwatch.Frequency; int sends = Interlocked.Exchange(ref _probeSendWindow, 0); - long ackTotal = _transport?.Stats.AcksSent ?? 0; - long acks = ackTotal - _probeAckSeenTotal; - _probeAckSeenTotal = ackTotal; - Console.WriteLine( - $"[net-tick] in/s={_probeProcessedWindow / windowSeconds:F0}" - + $" q={Volatile.Read(ref _probeInboundDepth)}" - + $" budget-breaks={_probeBudgetBreaks}" - + $" maxgap={maxGapMs:F0}ms" - + $" out/s={sends / windowSeconds:F0}" - + $" acks/s={acks / windowSeconds:F0}" - + $" st={CurrentState}"); + ReliableTransport? transport = _transport; + TransportStats? stats = transport?.Stats; + long acks = WindowDelta(stats?.AcksSent ?? 0, ref _probeAckSeenTotal); + // N5: reliable-transport window deltas (same cumulative-delta shape + // as acks/s) + the two instantaneous depths. The counters increment + // unconditionally in TransportStats; only this string work is + // probe-gated. + long resends = WindowDelta( + stats?.ResendsSent ?? 0, ref _probeResendSeenTotal); + long naksOut = WindowDelta( + stats?.NaksSent ?? 0, ref _probeNakOutSeenTotal); + long naksIn = WindowDelta( + stats?.NakRequestsReceived ?? 0, ref _probeNakInSeenTotal); + long rejsIn = WindowDelta( + stats?.RejectsReceived ?? 0, ref _probeRejInSeenTotal); + long dupDrops = WindowDelta( + stats?.InboundDupsDropped ?? 0, ref _probeDupDropSeenTotal); + long parked = WindowDelta( + stats?.KeysParked ?? 0, ref _probeParkedSeenTotal); + long reclaimed = WindowDelta( + stats?.RejectWordsReclaimed ?? 0, ref _probeReclaimSeenTotal); + Console.WriteLine(FormatNetTickLine( + windowSeconds, + _probeProcessedWindow, + Volatile.Read(ref _probeInboundDepth), + _probeBudgetBreaks, + maxGapMs, + sends, + acks, + resends, + naksOut, + naksIn, + rejsIn, + dupDrops, + parked, + reclaimed, + stats?.CacheDepth ?? 0, + transport?.Inbound.NakCount ?? 0, + CurrentState)); _probeWindowStartTs = tickStartTs; _probeMaxGapTicks = 0; _probeProcessedWindow = 0; _probeBudgetBreaks = 0; } + private static long WindowDelta(long cumulative, ref long seenTotal) + { + long delta = cumulative - seenTotal; + seenTotal = cumulative; + return delta; + } + + /// + /// The [net-tick] line shape, extracted so the N5 field extension + /// is string-assertable without a wall-clock window. cache and + /// nakset are instantaneous depths (the sent-packet cache is the + /// unbounded-like-retail watchdog value — campaign §4); every other + /// transport field is a per-second rate over the probe window. + /// + internal static string FormatNetTickLine( + double windowSeconds, + int processed, + int queueDepth, + int budgetBreaks, + double maxGapMs, + int sends, + long acks, + long resends, + long naksOut, + long naksIn, + long rejsIn, + long dupDrops, + long parked, + long reclaimed, + int cacheDepth, + int nakSetDepth, + State state) => + $"[net-tick] in/s={processed / windowSeconds:F0}" + + $" q={queueDepth}" + + $" budget-breaks={budgetBreaks}" + + $" maxgap={maxGapMs:F0}ms" + + $" out/s={sends / windowSeconds:F0}" + + $" acks/s={acks / windowSeconds:F0}" + + $" resend/s={resends / windowSeconds:F0}" + + $" nak-out/s={naksOut / windowSeconds:F0}" + + $" nak-in/s={naksIn / windowSeconds:F0}" + + $" rej-in/s={rejsIn / windowSeconds:F0}" + + $" dup-drop/s={dupDrops / windowSeconds:F0}" + + $" parked/s={parked / windowSeconds:F0}" + + $" reclaim/s={reclaimed / windowSeconds:F0}" + + $" cache={cacheDepth}" + + $" nakset={nakSetDepth}" + + $" st={state}"; + /// /// Pure, testable decision for the per-frame inbound bound: stop draining only when /// in-world AND the elapsed Stopwatch ticks have reached the budget. Extracted so the @@ -1446,6 +1542,7 @@ public sealed class WorldSession : IDisposable // consumed-in-place. if ((serverHeader.Flags & PacketHeaderFlags.RejectRetransmit) != 0) { + transport.Stats.RejectsReceived++; if (packet.Optional.RejectRetransmitCount > 0) { transport.Inbound.OnRejectRetransmit( @@ -2569,6 +2666,29 @@ public sealed class WorldSession : IDisposable } _netCancel.Dispose(); + // N5: one cumulative TransportStats summary so the connected loss + // gate asserts exact totals instead of reconstructing them from the + // rounded per-second [net-tick] rates. + if (NetDiagnostics.ProbeNet && _transport is { } finalTransport) + { + TransportStats finalStats = finalTransport.Stats; + Console.WriteLine( + $"[net-final] resends={finalStats.ResendsSent}" + + $" nak-in={finalStats.NakRequestsReceived}" + + $" nak-out={finalStats.NaksSent}" + + $" rej-in={finalStats.RejectsReceived}" + + $" acks-out={finalStats.AcksSent}" + + $" acks-in={finalStats.AcksConsumed}" + + $" dup-drop={finalStats.InboundDupsDropped}" + + $" sanity-drop={finalStats.InboundSanityDrops}" + + $" cksum-fail={finalStats.ChecksumFailures}" + + $" parked={finalStats.KeysParked}" + + $" reclaimed={finalStats.RejectWordsReclaimed}" + + $" uncached-nak={finalStats.UncachedNakIds}" + + $" cache={finalStats.CacheDepth}" + + $" nakset={finalTransport.Inbound.NakCount}"); + } + // N1: return every rented sent-packet cache buffer before the // socket goes away. _transport?.Dispose(); @@ -2674,6 +2794,23 @@ public sealed class WorldSession : IDisposable ProcessDatagram( datagram.Memory, dispatchWorldEvents: false); + // N5: keep the transport pumped while waiting for the + // logoff confirmation — retail's frame pump + // (Client::UseTime @ 0x00411C40 → + // PacketController::UseTime @ 0x005410D0) keeps running + // until LogOffServer, so the logoff wait is the third + // blocking pump the sweep must cover (after Tick and the + // handshake loops). The connected loss gate exposed the + // gap: without a sweep here, a lost S2C confirmation can + // be gap-detected (ACE's next sequenced packet arrives and + // parks a key) but the NAK that would heal it never goes + // out, and the graceful logout dies at the 35 s timeout. + // ACE's 2 s ack cadence guarantees arrivals to hang this + // callback on. (A lost C2S logoff REQUEST remains + // unrecoverable against ACE — its NAK is arrival-driven + // and a quiet client is never NAKed, campaign §3 row 1 — + // the same idle-tail constraint the N4 soak recorded.) + SweepTransport(); return Volatile.Read(ref _characterLogOffConfirmed) != 0; }, ReturnInboundDatagram); diff --git a/tests/AcDream.Core.Net.Tests/NetProbeTests.cs b/tests/AcDream.Core.Net.Tests/NetProbeTests.cs new file mode 100644 index 00000000..ee8f0902 --- /dev/null +++ b/tests/AcDream.Core.Net.Tests/NetProbeTests.cs @@ -0,0 +1,143 @@ +using System.Net; +using AcDream.Core.Net.Tests.Transport; + +namespace AcDream.Core.Net.Tests; + +/// +/// Campaign N Slice N5 — the [net-tick] loss-observability extension. +/// The line shape is pinned through the extracted formatter (no wall-clock +/// window needed), and one real probe-on session proves the once-per-second +/// emission path carries the new fields end-to-end. The probe-off +/// steady-state cost is covered by the existing zero-alloc send-path test +/// (OutboundReliableTransportTests.SendGameMessage_SteadyState_ +/// AllocatesNothingOnceThePoolWarms) — counters increment +/// unconditionally; string work is probe-gated. +/// +public sealed class NetProbeTests +{ + [Fact] + public void FormatNetTickLine_CarriesTheN5TransportFields() + { + string line = WorldSession.FormatNetTickLine( + windowSeconds: 2.0, + processed: 10, + queueDepth: 3, + budgetBreaks: 1, + maxGapMs: 17.4, + sends: 8, + acks: 2, + resends: 4, + naksOut: 6, + naksIn: 8, + rejsIn: 2, + dupDrops: 10, + parked: 12, + reclaimed: 2, + cacheDepth: 5, + nakSetDepth: 7, + WorldSession.State.InWorld); + + Assert.Equal( + "[net-tick] in/s=5 q=3 budget-breaks=1 maxgap=17ms out/s=4" + + " acks/s=1 resend/s=2 nak-out/s=3 nak-in/s=4 rej-in/s=1" + + " dup-drop/s=5 parked/s=6 reclaim/s=1 cache=5 nakset=7" + + " st=InWorld", + line); + } + + [Fact] + public void ProbeOn_EmitsTheExtendedNetTickLine_OncePerSecond() + { + bool savedProbe = NetDiagnostics.ProbeNet; + TextWriter savedOut = Console.Out; + var captured = new LockedStringWriter(); + var fake = new FakeAceTransport(); + var session = new WorldSession( + new IPEndPoint(IPAddress.Loopback, 9000), + fake); + try + { + NetDiagnostics.ProbeNet = true; + Console.SetOut(captured); + + session.Connect( + "testaccount", "testpassword", TimeSpan.FromSeconds(10)); + session.EnterWorld(0, TimeSpan.FromSeconds(10)); + + // The probe window is one REAL second of Tick cadence. + DateTime deadline = DateTime.UtcNow.AddSeconds(5); + while (DateTime.UtcNow < deadline + && !captured.Snapshot().Contains( + "[net-tick]", StringComparison.Ordinal)) + { + session.Tick(); + Thread.Sleep(25); + } + } + finally + { + session.Dispose(); + Console.SetOut(savedOut); + NetDiagnostics.ProbeNet = savedProbe; + } + + string output = captured.Snapshot(); + string tickLine = output + .Split('\n') + .First(l => l.Contains("[net-tick]", StringComparison.Ordinal)); + foreach (string field in new[] + { + "resend/s=", "nak-out/s=", "nak-in/s=", "rej-in/s=", + "dup-drop/s=", "parked/s=", "reclaim/s=", "cache=", "nakset=", + }) + { + Assert.Contains(field, tickLine, StringComparison.Ordinal); + } + + // Dispose also emitted the cumulative [net-final] totals the + // connected loss gate parses. + Assert.Contains("[net-final] resends=", output, StringComparison.Ordinal); + Assert.Contains(" nak-out=", output, StringComparison.Ordinal); + Assert.Contains(" nak-in=", output, StringComparison.Ordinal); + } + + /// + /// Console capture that is safe to snapshot while other threads write: + /// xunit runs test classes in parallel and any of them may hit + /// Console.WriteLine while this test holds the console. A plain + /// snapshot races its own writers + /// (StringBuilder.ToString mid-append throws). + /// + private sealed class LockedStringWriter : TextWriter + { + private readonly System.Text.StringBuilder _buffer = new(); + private readonly object _gate = new(); + + public override System.Text.Encoding Encoding => + System.Text.Encoding.Unicode; + + public override void Write(char value) + { + lock (_gate) + { + _buffer.Append(value); + } + } + + public override void Write(string? value) + { + lock (_gate) + { + _buffer.Append(value); + } + } + + public string Snapshot() + { + lock (_gate) + { + return _buffer.ToString(); + } + } + } +} diff --git a/tests/AcDream.Core.Net.Tests/Transport/FakeAceTransport.cs b/tests/AcDream.Core.Net.Tests/Transport/FakeAceTransport.cs index 2f8356cb..480b78be 100644 --- a/tests/AcDream.Core.Net.Tests/Transport/FakeAceTransport.cs +++ b/tests/AcDream.Core.Net.Tests/Transport/FakeAceTransport.cs @@ -59,6 +59,21 @@ internal sealed class FakeAceTransport : IWorldSessionTransport public LossyLink Link { get; } public AceSessionModel Model { get; } + /// + /// N5: virtual-clock advance applied at the top of every BLOCKING + /// call — the session-thread Connect()/EnterWorld() + /// pump path only; the async in-world receive owner never touches the + /// clock. The lossy-decorator lifecycle test needs time to move during + /// the blocking handshake pumps: with the clock frozen there, a dropped + /// handshake-window datagram could never be NAK-healed (the 0.6 s gate + /// never opens and the model never emits a later sequenced packet to + /// expose the gap) — a fixture artifact, not a transport property. + /// Zero (the default) preserves the pre-N5 fixture behavior exactly. + /// Single-threaded by construction: blocking receives happen on the same + /// thread that owns the clock in every test that sets this. + /// + public TimeSpan AutoAdvanceOnBlockingReceive { get; set; } + public FakeAceTransport(VirtualClock? clock = null, LossyLink? link = null) { Clock = clock ?? new VirtualClock(); @@ -158,6 +173,8 @@ internal sealed class FakeAceTransport : IWorldSessionTransport public int Receive(Span destination, TimeSpan timeout, out IPEndPoint? from) { + if (AutoAdvanceOnBlockingReceive > TimeSpan.Zero) + Clock.Advance(AutoAdvanceOnBlockingReceive); lock (_gate) { PumpServerLocked(); diff --git a/tests/AcDream.Core.Net.Tests/Transport/LossyTransportDecoratorTests.cs b/tests/AcDream.Core.Net.Tests/Transport/LossyTransportDecoratorTests.cs new file mode 100644 index 00000000..10b5390c --- /dev/null +++ b/tests/AcDream.Core.Net.Tests/Transport/LossyTransportDecoratorTests.cs @@ -0,0 +1,463 @@ +using System.Buffers.Binary; +using System.Net; +using AcDream.Core.Net.Messages; +using AcDream.Core.Net.Packets; +using AcDream.Core.Net.Transport; + +namespace AcDream.Core.Net.Tests.Transport; + +/// +/// Campaign N Slice N5 — the deterministic loss-injection decorator that +/// removes the loopback blindness (#260). Pins: seeded determinism, the +/// direction mask, structural absence at 0%, the encrypted-outbound arming +/// gate, and one full lifecycle at 5% seeded +/// bidirectional loss over the N0 ACE double with zero message loss and the +/// 256-key crypto window intact. +/// +public sealed class LossyTransportDecoratorTests +{ + // ===================================================================== + // Determinism + // ===================================================================== + + [Fact] + public void SameSeed_ProducesIdenticalDropPattern_DifferentSeedDiffers() + { + bool[] first = OutboundSurvivalPattern(seed: 42, count: 400); + bool[] second = OutboundSurvivalPattern(seed: 42, count: 400); + bool[] third = OutboundSurvivalPattern(seed: 43, count: 400); + + Assert.Equal(first, second); + Assert.NotEqual(first, third); + // The 25% loss was real in both directions of the comparison. + Assert.Contains(false, first); + Assert.Contains(true, first); + } + + /// Arms a 25% decorator, pushes + /// encrypted datagrams through Send, and records which survived. + private static bool[] OutboundSurvivalPattern(int seed, int count) + { + var inner = new RecordingTransport(); + var lossy = new LossyTransportDecorator( + inner, dropPercent: 25, seed, NetDropDirection.Both); + Arm(lossy, inner); + + bool[] survived = new bool[count]; + int forwardedBefore = inner.Sent.Count; + for (int i = 0; i < count; i++) + { + lossy.Send(EncryptedDatagram(sequence: (uint)(i + 2))); + survived[i] = inner.Sent.Count > forwardedBefore; + forwardedBefore = inner.Sent.Count; + } + + return survived; + } + + // ===================================================================== + // Direction mask + // ===================================================================== + + [Fact] + public void DirectionOut_DropsOutboundOnly_InboundAllDelivered() + { + var inner = new RecordingTransport(); + var lossy = new LossyTransportDecorator( + inner, dropPercent: 100, seed: 1, NetDropDirection.Out); + Arm(lossy, inner); + int armedForwardCount = inner.Sent.Count; + + // Every post-arming outbound datagram dies at 100%. + for (int i = 0; i < 20; i++) + lossy.Send(EncryptedDatagram(sequence: (uint)(i + 2))); + Assert.Equal(armedForwardCount, inner.Sent.Count); + Assert.Equal(20, lossy.OutboundDropped); + + // Inbound is untouched by the Out mask. + for (int i = 0; i < 20; i++) + inner.Inbound.Enqueue(EncryptedDatagram(sequence: (uint)(i + 2))); + Span buffer = stackalloc byte[64]; + for (int i = 0; i < 20; i++) + { + Assert.True( + lossy.Receive(buffer, TimeSpan.FromMilliseconds(50), out _) > 0); + } + + Assert.Equal(0, lossy.InboundDropped); + } + + [Fact] + public void DirectionIn_DropsInboundOnly_OutboundAllForwarded() + { + var inner = new RecordingTransport(); + var lossy = new LossyTransportDecorator( + inner, dropPercent: 100, seed: 1, NetDropDirection.In); + Arm(lossy, inner); + int armedForwardCount = inner.Sent.Count; + + // Outbound is untouched by the In mask. + for (int i = 0; i < 20; i++) + lossy.Send(EncryptedDatagram(sequence: (uint)(i + 2))); + Assert.Equal(armedForwardCount + 20, inner.Sent.Count); + Assert.Equal(0, lossy.OutboundDropped); + + // Every queued inbound datagram is eaten; the exhausted inner then + // reports timeout (-1) and the decorator surfaces it. + for (int i = 0; i < 20; i++) + inner.Inbound.Enqueue(EncryptedDatagram(sequence: (uint)(i + 2))); + byte[] buffer = new byte[64]; + Assert.Equal( + -1, + lossy.Receive(buffer, TimeSpan.FromMilliseconds(50), out _)); + Assert.Equal(20, lossy.InboundDropped); + } + + // ===================================================================== + // Structural absence at 0% + // ===================================================================== + + [Fact] + public void WrapIfConfigured_ZeroPercent_ReturnsTheRawTransport() + { + int savedPercent = NetDiagnostics.NetDropPercent; + int savedSeed = NetDiagnostics.NetDropSeed; + NetDropDirection savedDir = NetDiagnostics.NetDropDir; + try + { + var inner = new RecordingTransport(); + + NetDiagnostics.NetDropPercent = 0; + Assert.Same(inner, LossyTransportDecorator.WrapIfConfigured(inner)); + + NetDiagnostics.NetDropPercent = 2; + NetDiagnostics.NetDropSeed = 7; + NetDiagnostics.NetDropDir = NetDropDirection.Both; + IWorldSessionTransport wrapped = + LossyTransportDecorator.WrapIfConfigured(inner); + Assert.IsType(wrapped); + Assert.NotSame(inner, wrapped); + } + finally + { + NetDiagnostics.NetDropPercent = savedPercent; + NetDiagnostics.NetDropSeed = savedSeed; + NetDiagnostics.NetDropDir = savedDir; + } + } + + [Fact] + public void EnvParsing_RejectsOutOfRangeAndGarbage() + { + Assert.Equal(0, NetDiagnostics.ParseDropPercent(null)); + Assert.Equal(0, NetDiagnostics.ParseDropPercent("")); + Assert.Equal(0, NetDiagnostics.ParseDropPercent("banana")); + Assert.Equal(0, NetDiagnostics.ParseDropPercent("-1")); + Assert.Equal(0, NetDiagnostics.ParseDropPercent("101")); + Assert.Equal(2, NetDiagnostics.ParseDropPercent("2")); + Assert.Equal(100, NetDiagnostics.ParseDropPercent("100")); + + Assert.Equal( + NetDropDirection.Both, NetDiagnostics.ParseDropDirection(null)); + Assert.Equal( + NetDropDirection.Out, NetDiagnostics.ParseDropDirection("out")); + Assert.Equal( + NetDropDirection.In, NetDiagnostics.ParseDropDirection("In")); + Assert.Equal( + NetDropDirection.Both, NetDiagnostics.ParseDropDirection("both")); + Assert.Equal( + NetDropDirection.Both, NetDiagnostics.ParseDropDirection("weird")); + } + + // ===================================================================== + // The arming gate + // ===================================================================== + + [Fact] + public void NothingDrops_UntilTheFirstEncryptedOutboundHasBeenForwarded() + { + var inner = new RecordingTransport(); + var lossy = new LossyTransportDecorator( + inner, dropPercent: 100, seed: 1, NetDropDirection.Both); + + // Pre-arming: cleartext outbound (the handshake shape) always + // forwards, even at 100%. + for (int i = 0; i < 5; i++) + lossy.Send(CleartextDatagram()); + Assert.Equal(5, inner.Sent.Count); + Assert.False(lossy.IsArmed); + Assert.Equal(0, lossy.OutboundDropped); + + // Pre-arming: inbound always delivers. + inner.Inbound.Enqueue(EncryptedDatagram(sequence: 2)); + byte[] buffer = new byte[64]; + Assert.True( + lossy.Receive(buffer, TimeSpan.FromMilliseconds(50), out _) > 0); + Assert.Equal(0, lossy.InboundDropped); + + // The FIRST encrypted outbound datagram both forwards (it is the + // arming witness, never a casualty) and arms the decorator. + lossy.Send(EncryptedDatagram(sequence: 2)); + Assert.Equal(6, inner.Sent.Count); + Assert.True(lossy.IsArmed); + Assert.Equal(0, lossy.OutboundDropped); + + // From the next datagram on, 100% eats everything in both + // directions. + lossy.Send(EncryptedDatagram(sequence: 3)); + lossy.Send(CleartextDatagram()); + Assert.Equal(6, inner.Sent.Count); + Assert.Equal(2, lossy.OutboundDropped); + inner.Inbound.Enqueue(EncryptedDatagram(sequence: 3)); + Assert.Equal( + -1, + lossy.Receive(buffer, TimeSpan.FromMilliseconds(50), out _)); + Assert.Equal(1, lossy.InboundDropped); + } + + [Fact] + public void ShortOrCleartextDatagrams_NeverArm() + { + var inner = new RecordingTransport(); + var lossy = new LossyTransportDecorator( + inner, dropPercent: 100, seed: 1, NetDropDirection.Both); + + // A datagram at exactly the header size cannot be an encrypted + // reliable packet (length must EXCEED 20), and cleartext flags + // never arm regardless of length. + lossy.Send(new byte[PacketHeader.Size]); + lossy.Send(CleartextDatagram()); + Assert.False(lossy.IsArmed); + Assert.Equal(2, inner.Sent.Count); + } + + // ===================================================================== + // The WorldSession-level lossy run (deliverable #5's unit shape): + // 5% seeded bidirectional loss around the N0 ACE double — the scripted + // session completes, every message dispatches both ways, and ACE's + // 256-key crypto window is intact at convergence. + // ===================================================================== + + [Fact] + public void LossySession_FivePercentSeeded_ZeroMessageLoss_Headroom256() + { + var fake = new FakeAceTransport + { + // Time must move during the blocking Connect()/EnterWorld() + // pumps: the decorator arms at the first encrypted outbound + // (the enter-world request), so the ServerReady response is + // already droppable — and healing it needs the NAK gate to open + // and the model's 20 s TimeSync cadence to expose the gap. + AutoAdvanceOnBlockingReceive = TimeSpan.FromSeconds(3), + }; + var lossy = new LossyTransportDecorator( + fake, dropPercent: 5, seed: 424242, NetDropDirection.Both); + var session = new WorldSession( + new IPEndPoint(IPAddress.Loopback, 9000), + lossy); + session.TransportClockSource = + (fake.Clock.GetTimestamp, fake.Clock.Frequency); + try + { + session.Connect( + "testaccount", "testpassword", TimeSpan.FromSeconds(10)); + session.EnterWorld(0, TimeSpan.FromSeconds(10)); + Assert.Equal(WorldSession.State.InWorld, session.CurrentState); + + int s2cReceived = 0; + session.ServerMessageReceived += m => + { + if (m.Message.StartsWith("s2c ", StringComparison.Ordinal)) + s2cReceived++; + }; + int c2sDispatched = 0; + fake.Model.MessageDispatched += body => + { + if (body.AsSpan().IndexOf("c2s "u8) >= 0) + c2sDispatched++; + }; + + const int MessagesEachWay = 1_000; + for (int i = 0; i < MessagesEachWay; i++) + { + fake.Clock.Advance(TimeSpan.FromMilliseconds(25)); + session.SendTalk($"c2s {i}"); + fake.Model.EnqueueGameMessage( + BuildServerMessage($"s2c {i}"), + GameMessageGroup.UIQueue); + fake.PumpServer(); + session.Tick(); + if ((i & 15) == 0) + Thread.Sleep(1); + } + + // Convergence: keep a C2S trickle flowing (ACE's NAK is + // arrival-driven — a quiet client is never NAKed, campaign §3 + // row 1) until every message has landed on both sides. + int trickle = 0; + DateTime deadline = DateTime.UtcNow.AddSeconds(60); + while (DateTime.UtcNow < deadline + && (s2cReceived != MessagesEachWay + || c2sDispatched != MessagesEachWay)) + { + fake.Clock.Advance(TimeSpan.FromMilliseconds(500)); + session.SendTalk($"trickle {trickle++}"); + fake.PumpServer(); + session.Tick(); + Thread.Sleep(1); + } + + int quietIterations = 0; + while (DateTime.UtcNow < deadline) + { + fake.Clock.Advance(TimeSpan.FromMilliseconds(500)); + if (session.Transport!.Outbound.CacheDepth > 1 + && ++quietIterations % 8 == 0) + { + session.SendTalk($"trickle {trickle++}"); + } + + fake.PumpServer(); + session.Tick(); + Thread.Sleep(1); + + if (s2cReceived == MessagesEachWay + && c2sDispatched == MessagesEachWay + && session.Transport.Inbound.NakCount == 0 + && session.Transport.Outbound.PendingResendCount == 0 + && session.Transport.Outbound.CacheDepth <= 1) + { + break; + } + } + + string ledger = + $"s2c={s2cReceived} c2s={c2sDispatched} " + + $"dropped-out={lossy.OutboundDropped} " + + $"dropped-in={lossy.InboundDropped} " + + $"resends={session.Transport!.Stats.ResendsSent} " + + $"naks-sent={session.Transport.Stats.NaksSent} " + + $"headroom={fake.Model.Crypto.Headroom}"; + + // Zero message loss, both directions. + Assert.True(s2cReceived == MessagesEachWay, $"S2C loss: {ledger}"); + Assert.True( + c2sDispatched == MessagesEachWay, $"C2S loss: {ledger}"); + + // The decorator injected real loss in both directions, and the + // N1–N4 machinery healed it. + Assert.True(lossy.OutboundDropped > 0, ledger); + Assert.True(lossy.InboundDropped > 0, ledger); + Assert.True(session.Transport.Stats.ResendsSent > 0, ledger); + Assert.True(session.Transport.Stats.NaksSent > 0, ledger); + + // ACE's crypto search window never eroded (no re-key, no + // unrequested resend) — Headroom back to the full 256. + Assert.Equal(256, fake.Model.Crypto.Headroom); + Assert.Equal(0, fake.Model.Crypto.OrphanCount); + Assert.False(fake.Model.IsTerminated); + Assert.Equal(WorldSession.State.InWorld, session.CurrentState); + } + finally + { + session.Dispose(); + } + } + + // ===================================================================== + // Fixture helpers + // ===================================================================== + + /// Arms the decorator by forwarding one encrypted datagram + /// (the arming witness is never dropped). + private static void Arm( + LossyTransportDecorator lossy, + RecordingTransport inner) + { + int before = inner.Sent.Count; + lossy.Send(EncryptedDatagram(sequence: 2)); + Assert.Equal(before + 1, inner.Sent.Count); + Assert.True(lossy.IsArmed); + } + + private static byte[] EncryptedDatagram(uint sequence) + { + byte[] buffer = new byte[PacketHeader.Size + 8]; + new PacketHeader + { + Sequence = sequence, + Flags = PacketHeaderFlags.BlobFragments + | PacketHeaderFlags.EncryptedChecksum, + DataSize = 8, + }.Pack(buffer); + return buffer; + } + + private static byte[] CleartextDatagram() + { + byte[] buffer = new byte[PacketHeader.Size + 4]; + new PacketHeader + { + Sequence = 2, + Flags = PacketHeaderFlags.AckSequence, + DataSize = 4, + }.Pack(buffer); + return buffer; + } + + private static byte[] BuildServerMessage(string text) + { + var writer = new PacketWriter(64 + text.Length); + writer.WriteUInt32(ServerMessage.Opcode); // 0xF7E0 + writer.WriteString16L(text); + writer.WriteUInt32(1); // ChatMessageType + return writer.ToArray(); + } + + /// In-memory transport double: records outbound datagrams and + /// serves a caller-stocked inbound queue. + private sealed class RecordingTransport : IWorldSessionTransport + { + public List Sent { get; } = new(); + public Queue Inbound { get; } = new(); + public bool Disposed { get; private set; } + + public void Send(ReadOnlySpan datagram) => + Sent.Add(datagram.ToArray()); + + public void Send(IPEndPoint remote, ReadOnlySpan datagram) => + Sent.Add(datagram.ToArray()); + + public int Receive( + Span destination, + TimeSpan timeout, + out IPEndPoint? from) + { + if (Inbound.Count == 0) + { + from = null; + return -1; + } + + byte[] datagram = Inbound.Dequeue(); + datagram.CopyTo(destination); + from = new IPEndPoint(IPAddress.Loopback, 9000); + return datagram.Length; + } + + public ValueTask ReceiveAsync( + Memory destination, + CancellationToken cancellationToken) + { + if (Inbound.Count == 0) + throw new OperationCanceledException(cancellationToken); + byte[] datagram = Inbound.Dequeue(); + datagram.CopyTo(destination); + return ValueTask.FromResult(new NetReceiveResult( + datagram.Length, + new IPEndPoint(IPAddress.Loopback, 9000))); + } + + public void Dispose() => Disposed = true; + } +} diff --git a/tests/AcDream.Core.Net.Tests/Transport/OutboundReliableTransportTests.cs b/tests/AcDream.Core.Net.Tests/Transport/OutboundReliableTransportTests.cs index 8b29ec27..78527549 100644 --- a/tests/AcDream.Core.Net.Tests/Transport/OutboundReliableTransportTests.cs +++ b/tests/AcDream.Core.Net.Tests/Transport/OutboundReliableTransportTests.cs @@ -20,6 +20,7 @@ public sealed class OutboundReliableTransportTests private const uint ClientSeed = 0x11AA22BBu; private const uint ServerSeed = 0x33CC44DDu; private const uint ClientId = 0x1234u; + private const ushort SessionIteration = 0x0007; private const ulong Cookie = 0xFEEDFACECAFEBABEUL; // ===================================================================== @@ -183,6 +184,10 @@ public sealed class OutboundReliableTransportTests // N3 fold-in: fresh sends stamp the current interval id (the clock // starts at 1) — FlowQueue::TransmitNewPackets @ 0x00547A60. Assert.Equal((ushort)1, originalHeader.Time); + // N5 fold-in (N4 review F3): fresh sends stamp the session iteration + // through the same shared header build (0x00547A84/0x00547AA8), + // completing the control-header rule across all three send shapes. + Assert.Equal(SessionIteration, originalHeader.Iteration); // 1.2 s later (interval id 1 → 3) the server NAKs sequence 2. virtualClock.Advance(TimeSpan.FromSeconds(1.2)); @@ -345,7 +350,11 @@ public sealed class OutboundReliableTransportTests clock.Update(); Assert.Equal((ushort)6, clock.IntervalId); queue.SendGameMessage(MakeMessage(0xA1), GameMessageGroup.UIQueue); - Assert.Equal((ushort)6, PacketHeader.Unpack(Assert.Single(sent)).Time); + PacketHeader freshHeader = PacketHeader.Unpack(Assert.Single(sent)); + Assert.Equal((ushort)6, freshHeader.Time); + // N5 fold-in (N4 review F3): the fresh send carries the session + // iteration, and the resend below keeps it verbatim. + Assert.Equal(SessionIteration, freshHeader.Iteration); // The interval advances again; the resend carries the CURRENT id, // newer than the fresh-send stamp. @@ -355,7 +364,9 @@ public sealed class OutboundReliableTransportTests Nak(queue, 2u); sent.Clear(); queue.TransmitPendingResends(); - Assert.Equal((ushort)8, PacketHeader.Unpack(Assert.Single(sent)).Time); + PacketHeader resentHeader = PacketHeader.Unpack(Assert.Single(sent)); + Assert.Equal((ushort)8, resentHeader.Time); + Assert.Equal(SessionIteration, resentHeader.Iteration); } [Fact] @@ -528,6 +539,7 @@ public sealed class OutboundReliableTransportTests var queue = new OutboundFlowQueue( MakeIsaac(ClientSeed), (ushort)ClientId, + SessionIteration, clock, stats, static _ => { }); @@ -572,6 +584,7 @@ public sealed class OutboundReliableTransportTests var queue = new OutboundFlowQueue( MakeIsaac(ClientSeed), (ushort)ClientId, + SessionIteration, clock, stats, datagram => sent.Add(datagram.ToArray())); diff --git a/tools/run-connected-loss-gate.ps1 b/tools/run-connected-loss-gate.ps1 new file mode 100644 index 00000000..ba20f03b --- /dev/null +++ b/tools/run-connected-loss-gate.ps1 @@ -0,0 +1,488 @@ +# Campaign N Slice N5 -- the connected loss gate (verification ladder rung 3). +# +# Runs the standard connected world-lifecycle route against local ACE with the +# LossyTransportDecorator armed (ACDREAM_NET_DROP_PCT > 0): deterministic +# seeded datagram loss in both directions, injected between WorldSession and +# the UDP socket. The gate PASSES only when +# 1. the route completes with graceful teardown (same checkpoint/screenshot/ +# log validation as the lifecycle gate), AND +# 2. the [net-final] transport counters prove the loss was REAL and HEALED: +# resends > 0 OR nak-out > 0 OR nak-in > 0. A loss gate that passes with +# zero recovery activity proves nothing -- if every counter is zero the +# decorator never dropped, and the gate FAILS on that negative +# explicitly. +# +# Loopback ACE never drops packets, so every pre-N5 connected gate was +# structurally blind to the #260 bug class. This gate removes that blindness +# permanently. +# +# Caveat recorded in the campaign doc: ACE's NAK is arrival-driven (a quiet +# client is never NAKed -- campaign section 3 row 1), so a drop landing on the final +# single-shot logoff request or transport Disconnect (~DropPct probability +# each) is unrecoverable by design and fails the teardown checks. Rerun with +# a different -Seed if that tail case is hit; do not widen the teardown +# tolerances. + +[CmdletBinding()] +param( + [string]$Repository = (Resolve-Path (Join-Path $PSScriptRoot '..')).Path, + [string]$Account = $env:ACDREAM_TEST_USER, + [string]$Password = $env:ACDREAM_TEST_PASS, + [string]$AceLogPath = 'C:\ACE\Server\ACE_Log.txt', + [switch]$SkipBuild, + [int]$SessionTimeoutSeconds = 420, + [int]$DropPct = 2, + [int]$Seed = 1 +) + +Set-StrictMode -Version Latest +$ErrorActionPreference = 'Stop' + +if ([string]::IsNullOrWhiteSpace($Account)) { $Account = 'testaccount' } +if ([string]::IsNullOrWhiteSpace($Password)) { $Password = 'testpassword' } +if ($DropPct -lt 1 -or $DropPct -gt 100) { throw "DropPct must be 1..100 (got $DropPct)" } + +$stamp = Get-Date -Format 'yyyyMMdd-HHmmss' +$root = Join-Path $Repository "logs\connected-loss-gate-$stamp" +$null = New-Item -ItemType Directory -Force -Path $root +$reportPath = Join-Path $root 'report.json' +$exe = Join-Path $Repository 'src\AcDream.App\bin\Release\net10.0\AcDream.App.exe' +$failures = [System.Collections.Generic.List[string]]::new() +$warnings = [System.Collections.Generic.List[string]]::new() +$sessions = [System.Collections.Generic.List[object]]::new() +$startedUtc = [DateTime]::UtcNow +$lossEvidence = $null + +function Get-PatternCount([string]$Path, [string]$Pattern) { + if (-not (Test-Path -LiteralPath $Path)) { return 0 } + return @(Get-Content -LiteralPath $Path -ErrorAction SilentlyContinue | + Select-String -SimpleMatch $Pattern).Count +} + +function Wait-ForPattern( + [Diagnostics.Process]$Client, + [string]$Path, + [string]$Pattern, + [int]$TimeoutSeconds) +{ + $deadline = [DateTime]::UtcNow.AddSeconds($TimeoutSeconds) + while ([DateTime]::UtcNow -lt $deadline) { + $Client.Refresh() + if ($Client.HasExited) { + throw "client exited with code $($Client.ExitCode) while waiting for '$Pattern'" + } + if ((Get-PatternCount $Path $Pattern) -gt 0) { return } + Start-Sleep -Milliseconds 250 + } + throw "timed out after $TimeoutSeconds seconds waiting for '$Pattern'" +} + +function Wait-ForFileAppendPattern( + [string]$Path, + [long]$StartOffset, + [string]$Pattern, + [int]$TimeoutSeconds) +{ + $deadline = [DateTime]::UtcNow.AddSeconds($TimeoutSeconds) + while ([DateTime]::UtcNow -lt $deadline) { + if (Test-Path -LiteralPath $Path) { + $stream = [System.IO.File]::Open( + $Path, + [System.IO.FileMode]::Open, + [System.IO.FileAccess]::Read, + [System.IO.FileShare]::ReadWrite) + try { + if ($stream.Length -gt $StartOffset) { + $null = $stream.Seek($StartOffset, [System.IO.SeekOrigin]::Begin) + $reader = [System.IO.StreamReader]::new($stream) + try { $appended = $reader.ReadToEnd() } + finally { $reader.Dispose() } + if ([Text.RegularExpressions.Regex]::IsMatch( + $appended, + $Pattern, + [Text.RegularExpressions.RegexOptions]::CultureInvariant)) { return } + } + } + finally { $stream.Dispose() } + } + Start-Sleep -Milliseconds 100 + } + throw "timed out after $TimeoutSeconds seconds waiting for ACE log '$Pattern'" +} + +function Close-ClientGracefully([Diagnostics.Process]$Client) { + $Client.Refresh() + if ($Client.HasExited) { return $true } + if (-not $Client.CloseMainWindow()) { return $false } + if (-not $Client.WaitForExit(45000)) { return $false } + $Client.WaitForExit() + return $true +} + +function Test-Png([string]$Path) { + if (-not (Test-Path -LiteralPath $Path)) { return $false } + $info = Get-Item -LiteralPath $Path + if ($info.Length -lt 1024) { return $false } + $bytes = [System.IO.File]::ReadAllBytes($Path) + if ($bytes.Length -lt 8) { return $false } + $signature = @(137, 80, 78, 71, 13, 10, 26, 10) + for ($i = 0; $i -lt $signature.Count; $i++) { + if ($bytes[$i] -ne $signature[$i]) { return $false } + } + return $true +} + +function Add-LogFailures([string]$Label, [string]$Stdout, [string]$Stderr) { + $fatalPatterns = @( + 'event=invariant-failure', + 'Unhandled exception', + 'AccessViolation', + 'OutOfMemoryException', + 'WeenieError', + 'device removed', + 'GPU reset', + 'live: disconnected', + '[shutdown]', + 'ObjectDisposedException', + 'screenshot-failed', + 'graceful logout confirmation timed out', + 'graceful logout failed', + 'transport disconnect failed' + ) + foreach ($pattern in $fatalPatterns) { + $count = (Get-PatternCount $Stdout $pattern) + (Get-PatternCount $Stderr $pattern) + if ($count -gt 0) { $failures.Add("${Label}: '$pattern' appeared $count time(s)") } + } + + $missingLandblocks = Get-PatternCount $Stdout 'LandblockLoader.Load returned null' + if ($missingLandblocks -gt 0) { + $warnings.Add("${Label}: $missingLandblocks expected world-edge landblock miss(es)") + } +} + +function Read-Checkpoints([string]$Path) { + if (-not (Test-Path -LiteralPath $Path)) { return @() } + return @(Get-Content -LiteralPath $Path | ForEach-Object { $_ | ConvertFrom-Json }) +} + +function Validate-Checkpoint([string]$SessionLabel, [object]$Checkpoint) { + $name = $Checkpoint.name + $reveal = $Checkpoint.reveal + $environmentOwnership = $Checkpoint.environmentOwnership + $transitOwnership = $Checkpoint.transitOwnership + $resources = $Checkpoint.resources + if (-not $reveal.readiness.isReady) { + $failures.Add("${SessionLabel}/${name}: reveal was not ready") + } + if (-not $reveal.worldViewportObserved) { + $failures.Add("${SessionLabel}/${name}: normal world viewport was never observed") + } + if ($reveal.invariantFailureCount -ne 0) { + $failures.Add("${SessionLabel}/${name}: reveal has $($reveal.invariantFailureCount) invariant failure(s)") + } + if (-not $reveal.readiness.isUnhydratable) { + if (-not $reveal.readiness.isRenderNeighborhoodReady) { + $failures.Add("${SessionLabel}/${name}: render neighborhood was not ready") + } + if (-not $reveal.readiness.areCompositeTexturesReady) { + $failures.Add("${SessionLabel}/${name}: composite textures were not ready") + } + if (-not $reveal.readiness.isCollisionReady) { + $failures.Add("${SessionLabel}/${name}: collision was not ready") + } + } + if (-not $environmentOwnership.isInitialized) { + $failures.Add("${SessionLabel}/${name}: Runtime world environment is not initialized") + } + if (($environmentOwnership.dayGroupDefinitionCount -le 0) -or + ($environmentOwnership.activeDayGroupCount -ne 1)) { + $failures.Add(( + "${SessionLabel}/${name}: Runtime environment ownership is {0}/{1}, expected definitions with one active group" -f + $environmentOwnership.dayGroupDefinitionCount, + $environmentOwnership.activeDayGroupCount)) + } + foreach ($field in @( + 'bufferedTeleportDestinationCount', + 'pendingTeleportStartCount', + 'activeTeleportCount', + 'acceptedTeleportDestinationCount', + 'activeRevealCount', + 'pendingDestinationReadinessCount', + 'hostProjectionCount', + 'pendingHostAcknowledgementCount')) { + if ([int]$transitOwnership.$field -ne 0) { + $failures.Add(( + "${SessionLabel}/${name}: transitOwnership.$field={0}, expected zero at a stable checkpoint" -f + $transitOwnership.$field)) + } + } + if ($resources.pendingLiveTeardowns -ne 0) { + $failures.Add("${SessionLabel}/${name}: $($resources.pendingLiveTeardowns) live teardown(s) pending") + } + if ($resources.pendingLandblockRetirements -ne 0) { + $failures.Add("${SessionLabel}/${name}: $($resources.pendingLandblockRetirements) landblock retirement(s) pending") + } + if ($resources.stagedMeshUploads -ne 0) { + $failures.Add("${SessionLabel}/${name}: $($resources.stagedMeshUploads) staged mesh upload(s) remain at stable checkpoint") + } + if ($resources.compositeWarmupPending -ne 0) { + $failures.Add("${SessionLabel}/${name}: $($resources.compositeWarmupPending) composite warmup item(s) remain") + } + if ($resources.loadedLandblocks -le 0 -or $resources.worldEntities -le 0) { + $failures.Add("${SessionLabel}/${name}: world ownership is empty at a visible checkpoint") + } + if ($null -eq $resources.lastFrameProfile) { + $failures.Add("${SessionLabel}/${name}: no frame-profiler sample was available") + } +} + +# Parse the cumulative [net-final] transport counters emitted by +# WorldSession.Dispose under ACDREAM_PROBE_NET=1 -- exact totals, not the +# rounded per-second [net-tick] rates. +function Read-NetFinal([string]$Stdout) { + if (-not (Test-Path -LiteralPath $Stdout)) { return $null } + $line = @(Get-Content -LiteralPath $Stdout | + Select-String -SimpleMatch '[net-final]' | Select-Object -Last 1) + if ($line.Count -eq 0) { return $null } + $text = [string]$line[0].Line + $counters = [ordered]@{} + foreach ($match in [Text.RegularExpressions.Regex]::Matches( + $text, '([a-z\-]+)=(-?\d+)')) { + $counters[$match.Groups[1].Value] = [long]$match.Groups[2].Value + } + return [pscustomobject]@{ Line = $text; Counters = [pscustomobject]$counters } +} + +# Parse the decorator's own final ledger: "[net-loss] dropped out=N in=N ...". +function Read-NetLossDropped([string]$Stdout) { + if (-not (Test-Path -LiteralPath $Stdout)) { return $null } + $line = @(Get-Content -LiteralPath $Stdout | + Select-String -SimpleMatch '[net-loss] dropped' | Select-Object -Last 1) + if ($line.Count -eq 0) { return $null } + $text = [string]$line[0].Line + $match = [Text.RegularExpressions.Regex]::Match( + $text, 'dropped out=(\d+) in=(\d+)') + if (-not $match.Success) { return $null } + return [pscustomobject]@{ + Line = $text + DroppedOut = [long]$match.Groups[1].Value + DroppedIn = [long]$match.Groups[2].Value + } +} + +function Invoke-Session( + [string]$Label, + [string]$RoutePath, + [bool]$Uncapped, + [string[]]$ExpectedCheckpoints, + [string[]]$ExpectedScreenshots) +{ + $sessionDir = Join-Path $root $Label + $artifactDir = Join-Path $sessionDir 'artifacts' + $null = New-Item -ItemType Directory -Force -Path $artifactDir + $stdout = Join-Path $sessionDir 'stdout.log' + $stderr = Join-Path $sessionDir 'stderr.log' + $timeline = Join-Path $artifactDir 'world-lifecycle.checkpoints.jsonl' + $client = $null + $clientPort = $null + $graceful = $false + $exitCode = $null + $elapsed = [Diagnostics.Stopwatch]::StartNew() + $aceLogOffset = (Get-Item -LiteralPath $AceLogPath).Length + + $env:ACDREAM_DAT_DIR = "$env:USERPROFILE\Documents\Asheron's Call" + $env:ACDREAM_LIVE = '1' + $env:ACDREAM_TEST_HOST = '127.0.0.1' + $env:ACDREAM_TEST_PORT = '9000' + $env:ACDREAM_TEST_USER = $Account + $env:ACDREAM_TEST_PASS = $Password + $env:ACDREAM_RETAIL_UI = '1' + $env:ACDREAM_FRAME_PROF = '1' + $env:ACDREAM_UNCAPPED_RENDER = if ($Uncapped) { '1' } else { $null } + $env:ACDREAM_DEVTOOLS = '0' + $env:ACDREAM_UI_PROBE_DUMP = '0' + $env:ACDREAM_UI_PROBE_SCRIPT = $RoutePath + $env:ACDREAM_AUTOMATION_ARTIFACT_DIR = $artifactDir + $env:ACDREAM_DUMP_MOVE_TRUTH = $null + $env:ACDREAM_WB_DIAG = $null + $env:ACDREAM_RENDER_BACKEND = $null + $env:ACDREAM_COLLISION_SHADOW_EVERY = $null + $env:ACDREAM_COLLISION_SHADOW_DIR = $null + # N5 -- THE point of this gate: deterministic seeded loss + the probe + # that makes the recovery observable. + $env:ACDREAM_NET_DROP_PCT = "$DropPct" + $env:ACDREAM_NET_DROP_SEED = "$Seed" + $env:ACDREAM_NET_DROP_DIR = $null # default: both directions + $env:ACDREAM_PROBE_NET = '1' + + try { + $client = Start-Process -FilePath $exe -WorkingDirectory $Repository ` + -RedirectStandardOutput $stdout -RedirectStandardError $stderr -PassThru + Wait-ForPattern $client $stdout '[UI-PROBE] UI probe script complete' $SessionTimeoutSeconds + + $clientPorts = @(Get-NetUDPEndpoint -OwningProcess $client.Id -ErrorAction SilentlyContinue | + Select-Object -First 1 -ExpandProperty LocalPort) + if ($clientPorts.Count -ne 1) { + throw "could not resolve the client's UDP endpoint for ACE disconnect verification" + } + $clientPort = [int]$clientPorts[0] + + $client.Refresh() + $processSample = [pscustomobject][ordered]@{ + WorkingSetMiB = [Math]::Round($client.WorkingSet64 / 1MB, 1) + PrivateMiB = [Math]::Round($client.PrivateMemorySize64 / 1MB, 1) + HandleCount = $client.HandleCount + ThreadCount = $client.Threads.Count + WindowTitle = $client.MainWindowTitle + } + + $checkpoints = @(Read-Checkpoints $timeline) + if ($checkpoints.Count -ne $ExpectedCheckpoints.Count) { + $failures.Add("${Label}: expected $($ExpectedCheckpoints.Count) checkpoints, found $($checkpoints.Count)") + } + foreach ($name in $ExpectedCheckpoints) { + $matches = @($checkpoints | Where-Object { $_.name -eq $name }) + if ($matches.Count -ne 1) { + $failures.Add("${Label}: expected one checkpoint '$name', found $($matches.Count)") + } + } + foreach ($checkpoint in $checkpoints) { Validate-Checkpoint $Label $checkpoint } + + foreach ($name in $ExpectedScreenshots) { + $png = Join-Path $artifactDir "screenshots\$name.png" + if (-not (Test-Png $png)) { $failures.Add("${Label}: missing or invalid screenshot '$png'") } + } + + $graceful = Close-ClientGracefully $client + $client.Refresh() + if ($client.HasExited) { $exitCode = [int]$client.ExitCode } + if (-not $graceful) { $failures.Add("${Label}: client did not close through WM_CLOSE") } + if ($null -ne $exitCode -and $exitCode -ne 0) { + $failures.Add("${Label}: client exited with code $exitCode") + } + Add-LogFailures $Label $stdout $stderr + if ((Get-PatternCount $stdout '[session] graceful logout confirmed') -ne 1) { + $failures.Add("${Label}: server did not authoritatively confirm graceful character logout") + } + Wait-ForFileAppendPattern ` + $AceLogPath ` + $aceLogOffset ` + "Session .*\\127\.0\.0\.1:$clientPort dropped\..*Reason: PacketHeader Disconnect" ` + 15 + + # ---- N5: the loss-evidence assertions ------------------------- + $netFinal = Read-NetFinal $stdout + $netLoss = Read-NetLossDropped $stdout + if ($null -eq $netFinal) { + $failures.Add("${Label}: no [net-final] transport counter line was emitted") + } + if ($null -eq $netLoss) { + $failures.Add("${Label}: no [net-loss] dropped ledger was emitted (decorator absent?)") + } + if ($null -ne $netFinal) { + $resends = [long]$netFinal.Counters.resends + $nakOut = [long]$netFinal.Counters.'nak-out' + $nakIn = [long]$netFinal.Counters.'nak-in' + if (($resends -eq 0) -and ($nakOut -eq 0) -and ($nakIn -eq 0)) { + $failures.Add(( + "${Label}: loss gate observed ZERO recovery activity " + + "(resends=0, nak-out=0, nak-in=0) -- the decorator never dropped, the gate proves nothing")) + } + } + if ($null -ne $netLoss -and ($netLoss.DroppedOut + $netLoss.DroppedIn) -eq 0) { + $failures.Add("${Label}: the decorator forwarded everything (dropped out=0 in=0) -- no loss was injected") + } + $script:lossEvidence = [pscustomobject][ordered]@{ + NetFinal = $netFinal + NetLoss = $netLoss + } + + $session = [pscustomobject][ordered]@{ + Label = $Label + Uncapped = $Uncapped + DropPct = $DropPct + Seed = $Seed + ElapsedSeconds = [Math]::Round($elapsed.Elapsed.TotalSeconds, 3) + GracefulExit = $graceful + ExitCode = $exitCode + Process = $processSample + LossEvidence = $script:lossEvidence + Checkpoints = @($checkpoints) + Stdout = $stdout + Stderr = $stderr + ArtifactDirectory = $artifactDir + } + $sessions.Add($session) + return $session + } + catch { + $failures.Add("${Label}: $($_.Exception.Message)") + return $null + } + finally { + if ($null -ne $client) { + $client.Refresh() + if (-not $client.HasExited) { + $graceful = Close-ClientGracefully $client + if (-not $graceful -and -not $client.HasExited) { + $failures.Add("${Label}: required forced termination after WM_CLOSE timeout") + Stop-Process -Id $client.Id -Force + $client.WaitForExit(10000) + } + } + $client.Dispose() + } + } +} + +if (@(Get-Process -Name AcDream.App -ErrorAction SilentlyContinue).Count -gt 0) { + throw 'an AcDream.App client is already running; close it gracefully before the gate' +} +if (@(Get-NetUDPEndpoint -LocalPort 9000 -ErrorAction SilentlyContinue).Count -eq 0) { + throw 'local ACE is not listening on UDP port 9000' +} +if (-not (Test-Path -LiteralPath $AceLogPath)) { + throw "ACE log was not found: $AceLogPath" +} + +if (-not $SkipBuild) { + & dotnet build (Join-Path $Repository 'AcDream.slnx') -c Release --no-restore + if ($LASTEXITCODE -ne 0) { throw "Release build failed with exit code $LASTEXITCODE" } +} +if (-not (Test-Path -LiteralPath $exe)) { throw "client executable not found: $exe" } + +$null = Invoke-Session ` + 'loss-capped' ` + (Join-Path $Repository 'tools\connected-world-lifecycle.route.txt') ` + $false ` + @('capped_login', 'aerlinthe_first', 'rynthid', 'facility_hub', 'holtburg_after_dungeon', 'aerlinthe_revisit') ` + @('capped_login', 'aerlinthe_first', 'facility_hub', 'holtburg_after_dungeon', 'aerlinthe_revisit') + +$report = [pscustomobject][ordered]@{ + Passed = $failures.Count -eq 0 + StartedUtc = $startedUtc.ToString('O') + FinishedUtc = [DateTime]::UtcNow.ToString('O') + Commit = (& git -C $Repository rev-parse HEAD).Trim() + SourceStatus = @(& git -C $Repository status --short) + SessionName = $env:SESSIONNAME + DropPct = $DropPct + Seed = $Seed + LossEvidence = $lossEvidence + Failures = @($failures) + Warnings = @($warnings) + Sessions = @($sessions) +} +$report | ConvertTo-Json -Depth 12 | Set-Content -LiteralPath $reportPath -Encoding utf8 + +Write-Output "REPORT=$reportPath" +if ($null -ne $lossEvidence -and $null -ne $lossEvidence.NetFinal) { + Write-Output "NETFINAL=$($lossEvidence.NetFinal.Line)" +} +if ($null -ne $lossEvidence -and $null -ne $lossEvidence.NetLoss) { + Write-Output "NETLOSS=$($lossEvidence.NetLoss.Line)" +} +Write-Output "RESULT=$(if ($report.Passed) { 'PASS' } else { 'FAIL' })" +foreach ($failure in $failures) { Write-Output "FAILURE=$failure" } +foreach ($warning in $warnings) { Write-Output "WARNING=$warning" } + +if ($failures.Count -gt 0) { exit 1 } diff --git a/tools/run-connected-world-lifecycle-gate.ps1 b/tools/run-connected-world-lifecycle-gate.ps1 index 1ceb1d09..0e0b8923 100644 --- a/tools/run-connected-world-lifecycle-gate.ps1 +++ b/tools/run-connected-world-lifecycle-gate.ps1 @@ -269,6 +269,12 @@ function Invoke-Session( # harmless now that nothing reads it: cleared the same way every other # unwanted knob here is, for a variable that is never set by this gate again. $env:ACDREAM_RENDER_BACKEND = $null + # N5: this gate is the DECORATOR-ABSENT baseline -- a leaked + # ACDREAM_NET_DROP_PCT from a loss-gate run in the same shell must never + # inject loss here. Cleared like every other unwanted knob above. + $env:ACDREAM_NET_DROP_PCT = $null + $env:ACDREAM_NET_DROP_SEED = $null + $env:ACDREAM_NET_DROP_DIR = $null $env:ACDREAM_COLLISION_SHADOW_EVERY = if ($CollisionShadowEvery -gt 0) { "$CollisionShadowEvery" } else { $null } $env:ACDREAM_COLLISION_SHADOW_DIR =