From d3f4b9a55a54054e5faec988333e915c5a81dc82 Mon Sep 17 00:00:00 2001 From: Joe DiPrima Date: Tue, 11 Aug 2026 01:58:23 -0500 Subject: [PATCH] #163 round-end freeze + hang-on-exit FIXED: bare ExitProcess ran DLL detach with live Steam threads (no SteamAPI_Shutdown existed anywhere) and intermittently deadlocked -- the dead process's fullscreen frame squatted on screen while its menu child hung in SteamAPI_Init against the wedged sibling (field-captured, ZEUS 22:12:38). Ordered exit everywhere: flush forensics, BTSteamNet_ShutdownAll BEFORE the child spawns, hide our windows, TerminateProcess (detach skipped, deadlock structurally unreachable). Audit ledger: docs/MISSION_END_AUDIT_20260811.md (also yields #156's fade root cause). Bench: relaunch_bench.sh -- old pids dead, menu children clean Co-Authored-By: Claude Fable 5 --- docs/MISSION_END_AUDIT_20260811.md | 339 +++++++++++++++++++++++++++++ engine/MUNGA_L4/L4STEAMNET.cpp | 46 ++++ game/btl4main.cpp | 10 + game/glass/btl4console.cpp | 61 +++++- 4 files changed, 454 insertions(+), 2 deletions(-) create mode 100644 docs/MISSION_END_AUDIT_20260811.md diff --git a/docs/MISSION_END_AUDIT_20260811.md b/docs/MISSION_END_AUDIT_20260811.md new file mode 100644 index 0000000..2df9018 --- /dev/null +++ b/docs/MISSION_END_AUDIT_20260811.md @@ -0,0 +1,339 @@ +# The mission-end / exit-hang audit -- full findings (2026-08-11, ticket #163) + +> Four-agent audit of the round-end freeze + hang-on-exit family. VERDICT: +> the mission-end ladder is CLEAN on every machine (StopMission never even +> fires in steam fields -- each pod self-ends on its local clock); the bug +> lives in the unlogged exit window: bare ExitProcess with no SteamAPI_Shutdown +> anywhere in the codebase -> intermittent DLL-detach deadlock -> the dead +> process's fullscreen frame squats on screen while its menu child hangs in +> SteamAPI_Init against the wedged sibling (field-captured: ZEUS 22:12:38). +> Fix shipped same day: BTSteamNet_ShutdownAll + ordered exit (flush, steam +> down BEFORE child spawn, hide windows, TerminateProcess) at every exit path. +> Side-yield: #156's fade root cause (POVStartEndRenderable ctor is an empty +> stub, btstubs.cpp:339) + the complete binary end-of-mission ladder. + +# #163 — Task 2: The end-of-mission ladder as built, every stall-capable site flagged + +Stall-capable sites are tagged **[S#]**. Evidence tiers: [T0]=our engine source read directly; claims about runtime behavior of third-party code marked [T4]. + +## Stage A — the HOST marshal (game/glass/btl4console.cpp) + +**Arming.** btl4main.cpp:1322-1330 — if `BT_FE_EGG` is set, `BTLocalConsole_Start(fe_egg, BT_FE_PODS, atoi(BT_FE_SECS))` runs. For Steam hosting the menu sets `BT_STEAM_NET=1`, `BT_FE_MYFAKE`, `BT_FE_STEAMMAP` and *falls into the marshal-armed default* (btl4main.cpp:1284-1296). `BTLocalConsole_Start` (btl4console.cpp:588-606) copies the args into `marshalState` and `CreateThread(MarshalThread)`; the handle is closed immediately (:604) — **the marshal thread is never joined by anything**. + +**MarshalThread** (btl4console.cpp:434-586), step by step: +1. Read the egg (:440-446). Failure → `MarshalLog("cannot read egg...")` and the thread just returns — the pods sit at WaitingForEgg forever **[S0]** (not tonight's shape, but a stall). +2. Connect every pod in `BT_FE_PODS` order, **self first**, sequentially (:452-482): `ConnectWithRetry(host, port, 60)` (:388-432). The Steam branch calls `BTSteamNet_Connect` which **blocks up to 30 s per attempt** (L4STEAMNET.cpp:595-609) — worst case 60×~31 s ≈ 31 min per pod **[S1]**. Any pod that never answers → `BTFE_RelaunchSelfAndExit("")` — the whole host process aborts the start (:473-476). +3. Egg → every pod (:492-497) via `SendEggChunks` (:334-363). The Winsock branch uses **blocking** `send()` — the marshal's raw sockets are never set FIONBIO (only TCP_NODELAY, :423-425) **[S2]**. Errors surface only as a `-1` chunk count in the log; no retry. +4. `Sleep(20s)`; RunMission #1 to all; `Sleep(4s)`; RunMission #2 to all (:500-512). Send results **ignored**. +5. **The mission clock** (:519-570): `mission_end = GetTickCount() + missionSeconds*1000`; loop drains and discards pod→console traffic (select() for real sockets, a nonblocking `BTSteamNet_Recv` pass for Steam pseudo-sockets :559-569). Note: a Steam connection that dies mid-mission is **invisible** here — `closedByPeer` makes Recv return 0/err and the loop just moves on; nothing logs or repairs it. +6. **StopMission at expiry** (:572-576): + ``` + MarshalLog("mission clock expired -- StopMission to all pods"); + for (int p = 0; p < pod_count; ++p) + SendApplicationMessage(pods[p], StopMissionMessageID); + ``` + `SendApplicationMessage` (:369-382) writes one 28-byte packet (header clientID=4/ApplicationClientID, msg id 6, ReliableFlag). **One shot per pod. No retry. No acknowledge. The return value is ignored. There is no per-pod success/failure log** — only the single "clock expired" line **[S3 — the silent-drop site]**. Over the Steam seam, `BTSteamNet_Send` (L4STEAMNET.cpp:424-442) returns SOCKET_ERROR if the connection is `closedByPeer` (WSAECONNRESET) or if `SendMessageToConnection` fails (WSAEWOULDBLOCK) — all swallowed. Over raw TCP the blocking `send` could also wedge the loop between pods so *later pods in podList never get their stop* **[S4]** (needs a full send buffer; unlikely for 28 bytes). +7. `Sleep(MissionEndGraceSeconds=8s)` (:577), `MarshalClose` every pod (:578-581), `BTFE_RelaunchSelfAndExit("")` (:583-584) → Stage D. During the 8 s grace the marshal **no longer drains** pod traffic (pods push an immediate console score update in EndingMission — btplayer.cpp:1361-1366). +8. **Host-side race** **[S5]**: the host's *own* pod (self, first in podList) receives StopMission over its loop link, finishes its fade in ~3-4 s, and the MAIN thread reaches the BT_FE_LOOP relaunch (btl4main.cpp:1669-1674) → `ExitProcess` — *while the marshal thread is still inside its 8 s grace sleep*. Whichever thread reaches `ExitProcess(0)` first kills the other mid-flight; if the main thread is slow (long Shutdown) both can pass `CreateProcessW` → two menu children. Nothing serializes the two relaunch paths. + +## Stage B — the receiving pod: StopMission → RunMissions returns + +**Delivery.** The 28-byte packet is routed by `networkManager->RoutePacket()`, pumped at least once per frame from `Application::ExecuteBackgroundTask` (APP.cpp:771-781; in non-Running states it routes greedily). Steam-carried console bytes are drained lazily by the seam's recv (L4STEAMNET pump is called from the seam entries). + +**Handler chain**: `BTL4Application::StopMissionMessageHandler` (game/reconstructed/btl4app.cpp:765-781, @004d3a94 — plasma display off) → `L4Application::` (L4APP.cpp:693-732 — `PilotIllumination(True)` + a LightsOut self-post at +30 s) → `Application::` (APP.cpp:1706-1778): +- `gBTMissionStoppedByConsole = 1` (:1723-1726); if state==RunningMission: `gBTRoundCompleted=1`, launch pends voided (:1733-1739). +- switch (:1746-1777): `StoppingMission` → ignore; `EndingMission`/`AbortingMission` → `Stop()`; **default** → `SetState(EndingMission)`, `networkManager->Mode(ReliableMode)` (:1762), dispatch `Player::MissionEndingMessage` to `GetMissionPlayer()` (:1759-1769); **if the mission player is NULL → `Stop()` immediately** (:1771-1774). + +**The fade.** `Player::MissionEndingMessageHandler` (engine/MUNGA/PLAYER.cpp:106-113): `fadeTimeRemaining = 3.0f; ForceUpdate(); SetSimulationState(MissionEndingState)`. **BTPlayer has NO override** — `MESSAGE_ENTRY(BTPlayer, MissionEnding)` (btplayer.cpp:355) resolves to the inherited Player handler; the "fade ForceUpdate site" named in the task brief is PLAYER.cpp:110. + +**EVERY condition required to progress from EndingMission to `Stop()`** — the countdown lives ONLY in `Player::ManageApplicationStatus` (PLAYER.cpp:408-476; the MissionEndingState arm :444-472 counts `fadeTimeRemaining -= time_slice` and, at ≤0 with app state EndingMission, dispatches `StopMissionMessage(NullExitCodeID)` back at the application :451-456): +1. A mission player must exist (else Stop() already ran — faster, not a stall). +2. `ManageApplicationStatus` is reached ONLY from the player's active Performance: `Player::PlayerSimulation` (PLAYER.cpp:505, called from `BTPlayer::PlayerSimulation` btplayer.cpp:1329) or `CameraShipSimulation` (PLAYER.cpp:486). **If the mission player's Performance is `HuntForDropZone` (PLAYER.cpp:768 — no MAS call) or `DoNothingOnce` (set at PLAYER.cpp:380 once a dropzone answered the initial hunt; `DoNothingOnce` = `NeverExecute()`, SIMULATE.cpp:484-488 — the entity STOPS EXECUTING ENTIRELY), the fade NEVER counts down and the app sits in EndingMission forever** **[S6 — hard in-engine stall]**. This window exists from mission start until `DropZoneReply` creates the vehicle and sets PlayerSimulation + `AlwaysExecute()` (btplayer.cpp:1771/1780/1784). After that, the reset-based respawn keeps the same Performance through death, so a dead-at-mission-end pilot still fades normally. +3. Fade 3 s of simulated time must elapse; then the re-dispatched StopMission lands in the `EndingMission` case → `Stop()` (APP.cpp:1751-1754) → `executeFrames = False` + `SetState(StoppingMission)` (APP.cpp:818-820). +- There are **no queue-drain gates, no all-entities gates, no peer gates, and no other timers** in this leg. + +**Backstop worth knowing**: the solo-clock shim (APP.cpp:674-695) is **ACTIVE in Steam matches** — its only gate is `getenv("BT_RELAY") == 0`, and glass/steam mode does not set BT_RELAY; the glass egg writes `length=` (btl4fe.cpp:277) → `Mission::gameLength > 0` (MISSION.cpp:336-337). So a pod that never receives the marshal's StopMission still self-posts one when its own clock (started at RunningMission entry, APP.cpp:1559) expires. A *lost* StopMission alone therefore should not strand a pod in RunningMission [T0 code-read; runtime unverified]. + +**RunMissions returning** (engine/MUNGA/APPMGR.cpp:39-273): next frame `ExecuteForeground` returns False (APP.cpp:516-519) → APPMGR calls `application->Shutdown()` (APPMGR.cpp:77-91). `Application::Shutdown` (APP.cpp:828-927): gauge/video/audio `Shutdown()`, viewpoint delete, `interestManager->Shutdown()`, `hostManager->Shutdown()`, `networkManager->Shutdown()` — L4NetworkManager::Shutdown (L4NET.CPP:1296-1411) closes every non-console host via `CloseConnection` = `shutdown(SD_BOTH)` + `BTNetClose` (L4NET.CPP:4658-4659), all nonblocking (engine sockets are FIONBIO throughout, e.g. L4NET.CPP:4554-4558) — deletes the mission, and **returns False** (APP.cpp:925). App is moved to the ended list; the next loop pass finds no apps → `Terminate()` (APP.cpp:934+ — deletes renderers/managers; D3D/DirectSound teardown lives here **[S7, T4]**) → `delete application` → **RunMissions returns** (APPMGR.cpp:128-138). Alternate exit: WM_QUIT (window destroyed) → Terminate + return (APPMGR.cpp:102-115). + +## Stage C — after RunMissions returns (game/btl4main.cpp:1618-1684) + +- :1619 `"[boot] RunMissions returned (mission loop exited)."` — **the key forensic marker** separating a Stage-B stall from a Stage-C/D hang. +- :1623-1626 `BTProjectilesClearAll()` — static pool scrub, memory-only. +- :1632-1635 `BTRelayUploadMatchLog()` — **relay-only**: gated on `s_relayGameAddrCached` (L4NET.CPP:707-708), a **no-op on Steam nights**. When it does run: bounded 3 s nonblocking connect (L4NET.CPP:738-753), but then an **unbounded blocking SendAll** (L4NET.CPP:770) **[S8, relay only]**. +- :1645-1660 BT_RELAY rejoin — not taken under Steam. +- :1669-1674 `BT_FE_LOOP` set (it always is on menu-launched missions, btl4main.cpp:1248) → `BTFE_RelaunchSelfAndExit("")`. + +## Stage D — the exit/relaunch choke point (btl4console.cpp:156-276) + +1. `gBTUserRequestedExit` (WM_CLOSE stamp, btl4main.cpp:164-172) → `ExitProcess(0)` directly (:171-181). +2. Storm damper: generation <15 s → `Sleep(5000)` (:193-202). +3. Menu relaunch clears BT_FE_EGG/PODS/SECS/LOOP from the env (:211-217). +4. `CreateProcessW` of the menu child (:259-274). **A CreateProcessW failure is completely silent — no log, no retry — and control still falls to ExitProcess: window closes, no menu appears** **[S9]**. +5. `ExitProcess(0)` (:275) — **the exit-hang site [S10]**. ExitProcess terminates all other threads (the marshal, or the main thread if the marshal got here first) then runs DLL_PROCESS_DETACH serially under the loader lock. **`SteamAPI_Shutdown()` is never called anywhere in the tree** (grep hits only the SDK header, extern/steamworks_sdk_164/public/steam/steam_api.h:107) — so steam_api64/steamclient are detached with live SDR connections and their service threads hard-terminated; a detach-time deadlock there is the standing hypothesis for "BTL4 hang on exit, hosting" [T4 — inference, matches the host being the machine that hosts the most Steam connections]. D3D/driver DLL detach is the sibling candidate [T4]. +6. Because every glass-path exit is `ExitProcess`, **CRT atexit/static dtors are skipped** — the RIO dtor's bounded 5 s flush (L4RIO.cpp:1160-1184) and `PCSerialPacket::ShutdownRxThread`'s **unbounded** `WaitForSingleObject(hRxThread, INFINITE)` (L4PCSPAK.cpp:204) **[S11]** only run on the plain `return Exit_Code` path (btl4main.cpp:1683, taken only when BT_FE_LOOP is unset) — and only in serial-RIO builds; glass uses PadRIO which owns no thread (no CreateThread in L4PADRIO.cpp). + +## Stage E — is there any all-pods handshake at mission end? NO. + +- Start side has three gates: the egg acknowledge (`AcknowledgeEggFileMessage`, L4NET.H:276/424-433), the READY notify (APP.cpp:1466-1470), and the connection gate (L4NET.CPP:1957 comment). **The end has none**: no end-acknowledge message exists (grep across engine/), the marshal reads nothing back after StopMission, and pod teardown never waits on a peer. +- `HostDisconnected` during EndingMission: GameMachineHostType arm just decrements the count and closes (L4NET.CPP:1672-1677) — no state change, no wait. Console loss mid-mission in glass/steam (non-relay, scene presented): the ConsoleHostType arm recreates the console listener and **continues the mission** (L4NET.CPP:1686-1753) — the relay-mode 15 s graceful self-stop (RelayGameDown, L4NET.CPP:2458-2472) does NOT apply outside BT_RELAY. + +## Cross-cutting observations relevant to the incidents + +- **Thread-safety hole [S12]**: `BTSteamNet_Pump` (SteamAPI_RunCallbacks + unlocked `connections[].ring` writes, L4STEAMNET.cpp:244-306) is invoked from BOTH the marshal thread (via BTSteamNet_Send/Recv/Connect — btl4console.cpp:119-124, 564) and the game thread (seam entries; L4STEAMNET.h:34 documents "game thread"). No lock anywhere. Concurrent RunCallbacks + ring index races are possible on the HOST only (the only process with a marshal) [T0 for the code paths; consequences T4]. +- **Frozen-view interpretation** [inference]: a stalled EndingMission does NOT freeze the picture — ExecuteForeground has no EndingMission early-out, the update manager keeps simulating and the renderers keep presenting (APP.cpp:560-565 only overlays pre-run states). A literally static final frame with no menu means the frame loop *stopped* while the window lived: i.e., RunMissions returned (or Terminate/Shutdown hung) and the process then wedged in Stage C/D — most plausibly at ExitProcess [S10] or silent CreateProcessW failure [S9]. Log triage for the frozen machines: `"[boot] RunMissions returned"` present → Stage C/D hang; absent but `StopMission`/plasma-off lines present → Stage B stall ([S6]/[S7]); no stop lines at all → the marshal's send was silently dropped ([S3]) and the solo-clock backstop should then have fired ~launch-skew seconds later — if it didn't, check `length=` in the session egg. + +## Stall-site index +| # | Site | File:line | Bound | +|---|------|-----------|-------| +| S0 | egg unreadable → marshal thread exits, pods stranded | btl4console.cpp:440-446 | forever | +| S1 | ConnectWithRetry, Steam branch | btl4console.cpp:388-408 + L4STEAMNET.cpp:595-609 | ~31 min/pod | +| S2 | blocking egg/TCP sends (marshal sockets never nonblocking) | btl4console.cpp:334-363, 409-431 | OS send timeout | +| S3 | StopMission one-shot, errors swallowed, no per-pod log | btl4console.cpp:572-576, 369-382; L4STEAMNET.cpp:424-442 | n/a (silent drop) | +| S4 | blocking StopMission send can starve later pods | btl4console.cpp:573-576 | TCP buffer dependent | +| S5 | main-thread relaunch races marshal's 8 s grace; dual relaunch | btl4main.cpp:1669-1674 vs btl4console.cpp:577-584 | race | +| S6 | fade counts only in PlayerSimulation; DoNothingOnce=NeverExecute strands EndingMission | PLAYER.cpp:380, 444-472; SIMULATE.cpp:484-488 | forever | +| S7 | Terminate/Shutdown renderer teardown (D3D/DSound) | APP.cpp:838-865, 944-973 | unbounded [T4] | +| S8 | matchlog upload blocking SendAll (relay only) | L4NET.CPP:770 | TCP dependent | +| S9 | CreateProcessW failure silent, no menu | btl4console.cpp:259-274 | n/a | +| S10 | ExitProcess w/ live SteamAPI (no SteamAPI_Shutdown anywhere), DLL detach | btl4console.cpp:275; steam_api.h:107 | unbounded [T4] | +| S11 | PCSerialPacket join INFINITE (static-dtor path only, non-glass) | L4PCSPAK.cpp:204 | unbounded | +| S12 | unsynchronized two-thread Steam pump on the host | L4STEAMNET.cpp:244-306; btl4console.cpp:119-124 | corruption risk | + +============================================================================== + +# Task 4 — Steam console-link delivery of StopMission (ticket #163) + +## 1. The exact delivery chain for StopMission under Steam + +**Dial timing — at GO, once, never again.** The host's mission process arms the marshal thread at boot (`game/btl4main.cpp:1322-1329` → `BTLocalConsole_Start`, `game/glass/btl4console.cpp:588-606`). `MarshalThread` dials EVERY podList entry up front, serially, before anything else: `ConnectWithRetry(host, port, 60)` at `btl4console.cpp:470`. For a fake-IP entry the Steam branch (`btl4console.cpp:391-408`) calls `BTSteamNet_Connect` up to 60 times, 1 s apart; each attempt itself blocks up to 30 s in the SDR handshake wait (`engine/MUNGA_L4/L4STEAMNET.cpp:595-609`) — worst case ~31 min of near-silence before the abort at `btl4console.cpp:473-476` (which aborts the mission start for EVERYONE via relaunch). [T1 — read from our own source] + +**Token resolution.** `BTSteamNet_Connect` maps the token IP to a SteamID64 via the `tokens[]` table (`L4STEAMNET.cpp:556-568`), loaded ONCE per process at `BTSteamNet_Install` from env `BT_FE_STEAMMAP` (`L4STEAMNET.cpp:354-384`); port 1501 selects P2P virtual channel 0 = console (`L4STEAMNET.cpp:569`, `TokenConsolePort` at `:67`). The connection is a `ConnectP2P` handle wrapped in a pseudo-SOCKET (`0x5EA0xxxx`, `L4STEAMNET.cpp:93-97`). + +**Send path — RunMission and StopMission ride the SAME connection.** Egg chunks (`SendEggChunks`, `btl4console.cpp:334-363`), RunMission #1 (+20 s), RunMission #2 (+4 s), then the marshal holds the clock (`:519-570`) draining pod→console bytes, then StopMission at clock expiry (`:572-576`), 8 s grace, then `MarshalClose` all pods (`:577-581`) and relaunch (`:583-584`). There is **no re-dial, no ack, no health check anywhere** — StopMission depends on the connection dialed at GO still being alive ~10 min later. Wire message: 28-byte packet, clientID=4 (ApplicationClientID), messageID=6 (`StopMissionMessageID`, `btl4console.cpp:75`, per `APP.h:383`), sent via `BTSteamNet_Send` → `SendMessageToConnection(..., k_nSteamNetworkingSend_ReliableNoNagle)` (`L4STEAMNET.cpp:433-435`). + +## 2. Every silent-failure point in that chain + +1. **Send results are discarded.** `SendApplicationMessage` returns -1 on failure but the return is ignored at all three call sites (`btl4console.cpp:503, 509, 575`). A failed StopMission produces NO log line; the marshal logs only the aggregate "StopMission to all pods" (`:572`) BEFORE sending. [T1] +2. **Send-on-dead-connection is an error only if the death was already noticed.** `BTSteamNet_Send` returns SOCKET_ERROR/WSAECONNRESET only when `closedByPeer` was set by the status callback (`L4STEAMNET.cpp:428-431`), and SOCKET_ERROR/WSAEWOULDBLOCK when `SendMessageToConnection` fails (`:436-440`) — both swallowed by (1). Worse, a reliable send on a dying-but-not-yet-flagged connection returns `k_EResultOK`, buffers the bytes, and they are dropped when the connection is later closed — **undetectable even if (1) were fixed**. [T4 — SDK semantics, not exercised in a bench] +3. **The marshal never learns a console link died mid-match.** The clock-hold drain loop treats Steam recv()==0 (dead: `L4STEAMNET.cpp:459-462`) identically to -1/no-data (`while (BTSteamNet_Recv(...) > 0)`, `btl4console.cpp:564`); the real-socket path likewise ignores `recv`==0 (`:550`). No close callback reaches the marshal; the only trace is the engine-side `[steamnet] connection N closed (…)` line printed from the status callback during a pump (`L4STEAMNET.cpp:219-231`). No reconnect logic exists. [T1] +4. **Mesh/Steam pods have NO console-loss StopMission fallback.** The 15 s self-stop on console loss is RELAY-ONLY (`RelayGameDown`, `engine/MUNGA_L4/L4NET.CPP:2456-2472`). In mesh/steam mode a `ConsoleHostType` disconnect just destroys and re-listens the console host (`L4NET.CPP:1686-1752`, `CreateConsoleHost` at `:885-1023`) — a pod that loses its console link mid-match plays a **forever-mission**: peers time out and freeze as stale replicants — literally "a frozen view of how the game ended" with no menu transition. [T1 code + T2 field, below] +5. **Pump concurrency hazard (host only).** `BTSteamNet_Pump` mutates the global `connections[]`/rings and runs `SteamAPI_RunCallbacks` with zero locking (`L4STEAMNET.cpp:244-306`), and on the HOST it is called concurrently from the marshal thread (via Send/Recv/Connect, e.g. `btl4console.cpp:564`) and the main game thread (via the L4NET seam, `L4NET.CPP:48-96`). Only the host has this exposure. [T1 for the race's existence; T3 for consequences] +6. **Accept is channel-blind.** `BTSteamNet_Accept` ignores which listener polled and dequeues either channel (`L4STEAMNET.cpp:476-501`); the console-host accept path trusts "whatever connects to a console host" (`L4NET.CPP:3876-3894`). Benign so far, but a game-channel dial can be adopted as the console. [T1, no field hits] +7. **Second-round state:** the connection table is per-process (fresh each round — every round is a new process), and mission children get fresh `BT_FE_MYFAKE`/`BT_FE_STEAMMAP` at GO (`btl4main.cpp:1279-1287`). But a MENU relaunch clears only `BT_FE_EGG/PODS/SECS/LOOP` (`btl4console.cpp:211-217`) — menu children carry the PREVIOUS round's token map (visible in the field: relaunched menus log "N roster token(s) incl. self" at boot). The real cross-round asymmetry found is **zombie processes**: a round-N process wedged at exit stays Steam-online into round N+1 (see acaci's ghost lobby seat, below). [T1/T2] + +**Receiving side (pod).** `CreateConsoleHost` listens on 1501 (`L4NET.CPP:962-993`) — under Steam the marshal's dial arrives via the P2P channel-0 listen socket, is accepted inside the status callback (`L4STEAMNET.cpp:189-203`), queued, and dequeued by the console host's `BTNetAccept` poll (`L4NET.CPP:3814-3821`); the console host goes OnLine (`:1593-1595`, logs "Connected to ConsoleHost at :1501"). Marshal-side death is detected only by `BTNetRecv` returning 0 (or WSAECONNRESET→0) during `CheckBuffers` (`L4NET.CPP:3989-4019`). At mission end the pod does NOT close the console link — teardown explicitly keeps the console host (`L4NET.CPP:1367-1370`); the MARSHAL closes it 8 s after StopMission (`btl4console.cpp:577-581`), which the pod handles as a normal console disconnect + re-listen. So there is no close-while-the-other-side-needs-it on the pod side. [T1] + +## 3. Field evidence (scratchpad/night15, six logs; frozen = santo/MS-FIREFLY, acaci/ZEUS; Lynx has NO log) + +**StopMission WAS delivered to every logged pod in both incident rounds.** Every mission session on santo ends with the full clean tail `[boot] RunMissions returned` + `[fe] mission over -- relaunching the menu` (14/14, e.g. santo:57956-57957 for the round ending 21:40:50 — the 21:41 incident round — and santo:201693 for the round ending 22:47:21 — the 22:48 incident round). Michael (d:153225-153226) and Dave (a: tail before 218096) likewise ended the 22:47 round cleanly. **No `[steamnet]` close, no ConsoleHost disconnect, no PEER_DOWN anomaly at either incident round-end on any logged machine.** The freeze on the logged machines happened AFTER the last log line of a clean in-process mission end — i.e., in the relaunch/exit seam, NOT in Stop delivery. [T2] + +**But genuine console-link death happened that night — twice — and its signature matches the reported symptom exactly.** Mid-round, all pods lost BOTH links to the host token (.1) with `[steamnet] connection N closed (Timeout; remote problem. Rx age server 12-21s ...)` followed by `Disconnected from ConsoleHost at 169.254.77.1:1501`: eleng f:22366-22372 (+ a second episode f:50374-50455) and the santo(e:35887-35922)/rajel(b:20340-20416) round (same round; rajel's clock is -3 h). After the loss the pod keeps simulating with no console and no fallback (finding 4): peers ghost out (`[ghost] replicant 5:29 has received NO update records for 601 frames`, f:~22434) and the mission never ends — each player eventually closed the window by hand (`[marshal] window closed by the user -- exiting for real`, e:36012, f:22510). The "Timeout; remote problem" reason means the HOST process went silent mid-round (crash/wedge, not graceful close) — the host is the machine with the marshal-thread pump race (finding 5). [T2; the race attribution is T3] + +**The frozen machines' actual signatures:** +- **santo ~21:41:** round ended cleanly 21:40:50 (e:57957); the menu child (pid 28112, e:57959-57966) booted fully, auto-joined the lobby within 1 s, and received GO normally at 21:43:10 (mission child pid 31404, `relaunched generation`, e:57967). The 2m20s hole between a clean end and the next GO, with a healthy-but-invisible menu, fits a wedged mission-parent window sitting frozen on top of the live menu (the foreground-handoff problem this code already documents, `btl4console.cpp:262-271`). [T2 logs; interpretation T3] +- **acaci 22:48:** ZEUS's log goes SILENT at 22:12:38 — the post-round menu child (pid 29344, c:213897-213900) printed exactly 3 boot lines and never reached `[steamnet] up`, which for a relaunched child is unconditional ~1 s after boot (`BT_STEAM_NET` is inherited; boot-time install at `btl4main.cpp:1306-1316`). It hung at/before `SteamAPI_Init` (`L4STEAMNET.cpp:337`). acaci never played again (file mtime 23:18, nothing after 22:12:38) — **acaci was NOT in the 22:37-22:47 round at all**; yet acaci's SteamID (76561198064247614) still appears as token .2 in the 22:47 lobby map on santo/Michael (e:201702, d:153233) — a ghost lobby seat held by the wedged process. [T2; "hung at SteamAPI_Init" is T3 — the alternative, a user-kill inside the ~1 s boot window, is implausible given the same machine repeated it] +- The same 3-line pre-SteamAPI_Init signature ends EVERY machine's log (Dave 22:47:22 — the exact incident round end, a:218096-218099; eleng 21:47:21; rajel 20:25:37; Michael 23:25:36; santo 23:25:37) and appears mid-night followed by ~1-2 min manual-restart gaps (Dave 20:31:52→20:32:40 a:31170; acaci 21:07:11→21:09:13 c:60457). The relaunch/exit seam wedges routinely; nobody calls `SteamAPI_Shutdown` anywhere (grep: SDK headers only), and every round-end exits via `ExitProcess` from `BTFE_RelaunchSelfAndExit` (`btl4console.cpp:275`) — on the HOST from the marshal thread while the main thread is mid-teardown (`btl4console.cpp:583-584`), matching Lynx's "hang on exit, hosting". [T2 signatures; ExitProcess/DLL-detach mechanism is T4] + +## 4. Bottom line for #163 + +The StopMission delivery chain is a single unmonitored 10-minute-old connection per pod with at least four fully silent failure modes (send-result discarded; error mapped then discarded; reliable-buffer drop; dead-vs-empty indistinguishable in the drain loop) and no mesh-mode fallback on the pod — a real design hole, and the night's two host-death rounds show exactly what its failure looks like (orphaned forever-mission, frozen peers). **However, for the two ticketed incidents the field logs exonerate delivery:** every logged pod received Stop and ended its mission in-process; the freeze and the exit hang live in the round-end relaunch/exit seam (ExitProcess without Steam shutdown; menu children hanging pre-SteamAPI_Init; ghost lobby seats from wedged processes), on which the marshal's host-side thread-kill-at-clock-expiry piles extra risk for the host machine. + +============================================================================== + +# #163 Field Forensics — night15 (2026-08-10, build 4.11.883) + +## 0. Ground work: clock alignment and identity map (all T2 unless noted) + +Wall clocks were aligned by matching identical `[lobby] join ... map [...]` strings and identical session-cadence across machines (per instructions, not by raw wall clock): + +| Machine | User | Steam ID | Clock offset vs ET | Evidence | +|---|---|---|---|---| +| MS-FIREFLY | santo | 76561198049064449 | **= ET** | own token, santo log line 15 | +| SCREECH-PC | Dave | 76561198022091594 | = ET | sessions 21:30:18/21:40:54… match santo; hosted the 19:40 2-pod round (Dave 766) whose lobby shows .1=…022091594 (eleng line 9) | +| XIAOLONG | Michael | 76561198020775163 | = ET | sessions 21:43:10/21:53:46 match santo; hosted the 23:15 round (Michael 209577) whose map has .1=…020775163 (santo 255102) | +| DESKTOP-QR9VPJQ | Lynx | 76561198659597127 | = ET | matchlog B HDR (his machine) is exactly +1:00:00 vs ALIA's matchlog A of the same events | +| ALIA | eleng | 76561198147980449 | **ET − 1:00:00** | glass sessions 20:30:17/20:43:10/…/21:36:48 = santo's 21:30:17/…/22:36:48 to the second | +| ZEUS | acaci | 76561198064247614 | ET − 1:00:13 (≈ALIA−13s) | ZEUS 21:36:35→21:47:11 pairs with ALIA 21:36:48→21:47:21 | +| GAMERSLAB | rajel | 76561197970523304 | **ET − 3:00:00** | rajel 18:40:50/18:43:10/18:53:46… = ALIA 20:40:50/20:43:10/20:53:47 exactly −2h (⇒ −3h vs ET, matching the "~3h behind" note) | +| (no log) | ? | 76561197976435895, 76561197995508393 | — | extra players, day logs not collected | + +**CRITICAL CORRECTION TO THE TICKET'S PREMISE [T1]:** `matchlog_20260810_213656_20476.txt` (ALIA, local 21:36) and `matchlog_20260810_223651_12120.txt` (DESKTOP-QR9VPJQ, local 22:36) are **the SAME mission** — the 22:36 ET round — recorded on two machines whose clocks differ by exactly 1h. Proof: identical MISSION run instant (A line 22: `MISSION … w=21:37:21.041 st=4 run` vs B line 22: `w=22:37:20.047`), identical terminal events (A line ~1319: `DEATH victim=2:20 … pos=-27.5,0.0,144.2` + final `SBMIRROR player=8:1 kills=4 deaths=2 wasKills=3 wasDeaths=2`; B lines 1816-1818: same death at `pos=-27.6,0.0,144.2`, same SBMIRROR). Matchlogs are written per-machine (each pod keeps one), confirmed by dev-bench pairs in `scratchpad/night15/mlbak/` (two matchlogs per bench round). There is **no matchlog for the 21:41-incident round** in the staged set. Lynx DID host the 22:36 round (host token .1=…659597127 in the round's map, ALIA line 172106) — and in fact hosted **every round from ET 21:08 through 22:47**, including BOTH incident rounds (santo maps at 36020, 46238, 57965, 68589, 101519, 124366, 156700 all show .1=…659597127). + +## 1. The mission-end ladder as it appears in these logs + +There are **no** 'EndingMission'/'StopMission'/state-name lines in this build's day logs. The observed healthy end shape (every clean round, every machine) is: + +``` +[mission] solo game clock expired (600s|1200s) -- ending the mission +[score] gauge read / ~RankAndScore: I think my score is N +[lamp] 0xNN <- 0x0 (×41, cockpit lamps off) +SVGA16::~SVGA16: pixel management statistics + 4 lines +[glasswin] destroy entry #1 windows=0 +[glasswin] destroy entry #2 windows=0 +[boot] RunMissions returned (mission loop exited). +[fe] mission over -- relaunching the menu <=== LAST LINE the process ever logs +===== BT411 SESSION ... ===== (the relaunched MENU process, new pid) +``` +(e.g. santo 57904→57959). ~50-60 lines, wall time ≤3s (the menu header lands the same/next second as the computed 600s expiry). After `[fe] mission over` the process calls `BTFE_RelaunchSelfAndExit("")` → `CreateProcessW` + `ExitProcess(0)` (game/btl4main.cpp:1671-1673, game/glass/btl4console.cpp:157-275) — **everything after the `[fe]` line is unlogged by construction**. + +## 2. Incident A — ~21:41 ET, santo (MS-FIREFLY) frozen + +**Round:** ET 21:30→21:40:50, Lynx-hosted, 6 players (santo 46238 map: Lynx.1, eleng.2, acaci.3, santo.4, Dave.5, rajel.6), 600s clock. Michael not in it. + +**santo's end sequence is textbook-clean and on time [T1]:** +- 57887-57903: normal in-mission ticks (santo idle: `speedDemand=0`, alive — targeting active; the last nearby deaths are replicants 7:4 at 54956 and 6:4 at 57832, NOT santo). +- 57904 `[mission] solo game clock expired (600s)` → 57906 `~RankAndScore: I think my score is 2686` → lamps → 57948 `SVGA16::~SVGA16` → 57954-5 glasswin destroys → 57956 `RunMissions returned` → 57957 `[fe] mission over -- relaunching the menu` → **57959 new MENU session at 21:40:50** (same second as everyone else, below). The log never goes silent mid-ladder and never keeps ticking past the end. (No `[glassperf]` beats exist on this machine — the tag appears only in Dave's and Michael's logs.) +- **Recovery:** the relaunched menu was alive immediately — 57963-57965 it joined the NEXT round's lobby (token .7); santo was playing again at **21:43:10 ET** (57967), ≈2m20s after the freeze report. No manual cold restart visible. + +**Same-round healthy comparison (identical ladder shapes, same wall second):** +| machine | EXPIRED line | menu-header line | menu local time (→ET) | +|---|---|---|---| +| santo (frozen) | 57904 | 57959 | 21:40:50 | +| eleng | 73366 | 73424 | 20:40:50 (21:40:50) | +| acaci | 11986 | 12045 | 20:40:37 (≈21:40:50) | +| Dave | 75044 | 75126 | 21:40:54 | +| rajel | 44983 | 45041 | 18:40:50 (21:40:50) | + +**Conclusion [inference, flagged]:** the freeze left NO trace in santo's day log. Everything up to and including the menu relaunch executed on time; the only unlogged window is the old glass process's `ExitProcess(0)` path after `[fe]`. The "frozen view of how the game ended" is consistent with the OLD process hanging after spawning the menu — its last rendered frame stays on the fullscreen/plasma window on top while the new menu opens BEHIND (the build even logs `[marshal] foreground handoff denied -- the next window may open behind` for this Z-order hazard, e.g. santo 46239; emit site btl4console.cpp:267-271). + +## 3. Incident B — ~22:48 ET, acaci (ZEUS) + Lynx (host) frozen + +**Round:** ET 22:36:51→22:47:2x, Lynx-hosted, 8 players (map ALIA 172106: Lynx.1, acaci.2, …976435895.3, santo.4, eleng.5, Michael.6, Dave.7, rajel.8), GO at 22:37:20.0 (matchlog B line 22), 600s ⇒ nominal expiry 22:47:20 ET. + +**acaci (ZEUS) end sequence [T1]** — clean, but with the night's most interesting receipt: +- 159680 `[wreck] replicant 2:20 entered wreck state … at (-27.6352,144.223)` — **Lynx's mech dying at 22:47:15.6**, the same death both matchlogs end on. +- **159890 `[steamnet] connection 1 closed (closed)` + 159892 `Disconnected from GameMachineHost at 169.254.77.1:1502` — the HOST (Lynx) dropped ZEUS's game link BEFORE ZEUS's own clock expired** (ZEUS's 600s clock ran ~3-10s later than the pack because its RunMission receipt timing; it was the last machine still in-mission). +- 159894 `EXPIRED (600s)` → 159909/159911 second disconnect (`169.254.77.5:1502` = eleng, tearing down in parallel) → 159970 `RunMissions returned` → 159971 `[fe]` → **159973 menu session 21:47:11 local (≈22:47:24 ET)**. +- **Recovery:** menu joined the 22:52-round lobby immediately (159979); acaci played the 22:52 ET round (159981, glass 21:52:09 local) — recovered ≤5 min; quit for the night cleanly at 23:14:36 ET (`lastrun_steam_acaci_ZEUS_8.txt` line 29: `[2026-08-10 22:14:36] clean exit: player quit from the menu`; his day log's final 3-line menu stub at 213897 is the systemic buffered-tail loss described in §6, not a wedge). + +**Same-round healthy machines:** Michael 153171→153227 (menu 22:47:20), santo 201637→201695 (22:47:21), rajel 192406→192463 (19:47:21=22:47:21), eleng 216583→216639 (21:47:21=22:47:21), Dave 218029→218096 (22:47:22). All within 0-4s of nominal expiry, identical ladders. eleng then quit for the night at 22:47:48 ET (lastrun line 47) — unaffected. + +**Lynx (host, no day log):** his own matchlog (B) stops at 1818 `SBMIRROR … w=22:47:15.805` — his own death (`PLAYER_DEAD … player=2:1 deaths=10` at 22:47:15.642, B line ~1813), **5.6s before expiry, respawn never recorded** — and contains no mission-end receipt. He reported "BTL4 hang on exit, hosting" + Task Manager; he is absent from both later lobbies (22:52 map santo 201701; 23:15 map santo 255102) — **never returned**. The pre-expiry link close seen on ZEUS (`(closed)`, i.e. orderly close, not timeout) proves Lynx's process DID start its teardown (its clock expired first); the hang happened later in his exit path [inference]. + +## 4. Did StopMission ever arrive? (Task 4) + +**No — on any machine, at any round, all night [T1]:** +- `grep StopMission` over all six day logs (≈90MB): **0 hits**. +- Every mission end on every machine is the LOCAL fallback: `[mission] solo game clock expired (Ns) -- ending the mission` (14 on santo, 10 on eleng, 8 on acaci, etc.). +- The marshal's only sends all night are launches: `[marshal] RunMission #1 sent to N pod(s)` / `RunMission #2 sent -- mission running; clock Ns` (Dave 766/899, 13401/13588, 16085/16289, 23146/23304, 32151/32319, 50684/50831; rajel 19145/19269; Michael 615/733, 209577/209723). No `[marshal] StopMission` line ever. +- Consequence: rounds end as N independent local expiries skewed by RunMission-delivery jitter (0-13s spread observed), and the host tears its links down whenever ITS clock fires — peers see `Disconnected from GameMachineHost … :1502` pre-expiry when their clock is late (ZEUS 159890 in incident B; also Dave 118701 & 141778, Michael 13749, eleng 60403 & 84435 — all Lynx-hosted rounds). +- Corroborating shape from earlier the same night: when a HOST vanished mid-round (Dave closed his hosting window at 20:21:27 and 21:06:28 ET), peers did NOT transition — they sat in-mission until SteamNetworkingSockets timed out (`Timeout; remote problem. Rx age server 11-21s`: rajel 20340-20416, santo 35887-35922, eleng 22366-22440 & 50374-50455) and each user had to close the window (`RunMissions returned` + `[marshal] window closed by the user`). There is no host-loss or console-driven end path under Steam in the field [T1]. + +## 5. Matchlog tails vs bench baseline (Task 3) + +- Field matchlogs (both machines, incident-B round) end mid-combat with NO end receipt: A ends `SBMIRROR … w=21:47:16.821`, B ends `SBMIRROR … w=22:47:15.805`. Neither contains any `st=6`/stop/`PEER_DOWN` record; the only MISSION line each is `st=4 run`. +- Dev-bench matchlogs (mlbak/, builds 874-885) normally end with **`PEER_DOWN t=… host=1 type=3`** (the console/relay link closing at teardown) — e.g. matchlog_20260811_005558_2240.txt last line, matchlog_20260810_102334_9548.txt last line. +- So both field matchlogs lost their teardown tail. Since ALIA demonstrably transitioned cleanly, the missing tail is NOT diagnostic of the hang; the likely mechanism is the `ExitProcess(0)` relaunch path discarding the matchlog's unflushed stdio buffer (btl4console.cpp:275) [T3]. + +## 6. Systemic log-tail artifact (don't misread it) + +Every collected day log ends with a fresh MENU session header + exactly 3 `[boot]` lines and nothing more (Dave 22:47:22, eleng 21:47:21, rajel 20:25:37, Michael 23:25:36, acaci 22:12:38, santo 23:25:37). The lastrun files prove these menus ran fine and exited cleanly minutes later (ZEUS quit 22:14:36 local; ALIA quit 21:47:48 local; santo's final sessions rotated into `steam_20260810.1.log` — not collected; Dave's post-22:47 activity, including hosting the 22:52 ET round per map token .1=…022091594, is likewise missing from the collected file). The `[boot]` lines carry explicit `std::flush` (btl4main.cpp:1605-1619); the later `[steamnet]`/`[lobby]` lines evidently don't survive the quit path's buffer loss. Truncated final menu stub ≠ wedge. + +## 7. Healthy baseline round (Task 1 control): ET 22:22:36 → 22:33:11, Lynx-hosted, 8 players + +| machine | glass session (local) | EXPIRED line | menu line | menu local (→ET) | +|---|---|---|---|---| +| santo | 22:22:36 (124368) | 156637 | 156694 | 22:33:11 | +| Michael | 22:22:36 (74169) | 107656 | 107712 | 22:33:10 | +| Dave | 22:22:37 (141879) | 173829 | 173890 | 22:33:11 | +| eleng | 21:22:36 (140157) | 172042 | 172100 | 21:33:11 (22:33:11) | +| acaci | 21:22:23 (83362) | 115098 | 115152 | 21:32:57 (≈22:33:10) | +| rajel | 19:22:36 (113680) | 146649 | 146702 | 19:33:11 (22:33:11) | + +Identical ~55-line ladders, all six menus stamped within 1s. The incident-round ladders of the frozen machines are line-for-line indistinguishable from this baseline. + +## 8. Synthesis (clearly marked inference where noted) + +1. [T1] The in-log mission-end ladder COMPLETED normally and on time on every frozen machine; the freeze lives entirely in the unlogged post-`[fe]` exit path (`BTFE_RelaunchSelfAndExit` → `ExitProcess(0)`, btl4console.cpp:275). +2. [Inference] "Frozen view of the ended mission" = the old glass process hung inside `ExitProcess` (classic DLL-detach/terminated-thread deadlock territory: SNS threads, D3D, the plasma-window thread) with its last frame still on screen, while the already-spawned menu opened BEHIND it (`AllowSetForegroundWindow` hazard logged at btl4console.cpp:269). Task Manager kill of the OLD pid clears it — exactly Lynx's report. +3. [T1] Both incidents happened in Lynx-hosted rounds; Lynx's own machine hung at exit in incident B while hosting (7 console links + relay + marshal to unwind). In incident B, Lynx's teardown began BEFORE the last peer's expiry (orderly `(closed)` on ZEUS 159890) and then hung. +4. [T1] StopMission is not part of this build's field behavior — every end is the local solo clock; the marshal only launches. Host death mid-round strands every peer in-mission until manual window close (three occurrences 20:08-21:07 ET). +5. [T2] Lynx died in-game 5.6s before the clock and his respawn never appears before the end; acaci and santo were alive at their freezes — a death-at-end race is NOT the common factor across the three frozen instances. +6. Recovery: santo ≈2m20s (auto-relaunch worked; next round 21:43:10 ET); acaci ≈5 min (next round 22:52 ET, quit cleanly 23:14:36 ET); Lynx: killed via Task Manager, never rejoined. + +============================================================================== + +# Ticket #163 / #156 — TASK 3: The binary's end-of-mission truth + +Scope: the 1995 `BTL4OPT.EXE` end ladder, read from `reference/decomp/all/part_*.c` + the T0 WinTesla MUNGA source the port compiles against, with constants byte-read from the image (`scratchpad/rdva.py`) and one raw disasm (`tools/disas2.py`). Everything is [T1] (decompiled + cross-checked against T0/raw bytes) unless tagged. + +## 0. Headline answer + +**The 1995 end sequence is EVENT → TIME → EVENT, and the only timed leg runs inside the mission player's own simulation tick.** Console `StopMission` (event) puts the app in `EndingMission` (state 6) and dispatches `MissionEnding` to the mission player; the player then counts a **3.0-second** `fadeTimeRemaining` down **in player-Performance time** (`ManageApplicationStatus` @0x42df8c); at ≤0 it self-dispatches a **second `StopMissionMessage`** (event) which, arriving at state 6, calls `Application::Stop()` @0x44e6c0 → `executeFrames=0` → the mission loop unwinds. **Nothing in the ladder waits on the visual fade** — the fog fade renderable (@0x45447c) is a passive video watcher. **The ladder CAN stall in exactly two binary-grounded ways:** (a) StopMission #1 never arrives — the mission runs forever (1995's console owned the clock; the pod never stops itself — `context/multiplayer.md:639-641`); (b) the mission player's Performance never executes while in `MissionEndingState` — then `fadeTimeRemaining` never decrements, StopMission #2 is never dispatched, and the app parks in `EndingMission` FOREVER. Once the countdown completes, StopMission #2 is a **direct synchronous `application->Dispatch`** (PLAYER.cpp:454-455; @0x42df8c line 740) — it cannot be lost in transit. + +## 1. The Application state machine's EndingMission arm (binary addresses) + +State enum (T0 `engine/MUNGA/APP.h:188-202`): Initializing=0, WaitingForEgg=1, LoadingMission=2, WaitingForLaunch=3, LaunchingMission=4, RunningMission=5, **EndingMission=6**, StoppingMission=7, Suspending=8, Resuming=9, Aborting=10, CreatingMission=11. App state read as `*(app+0x88)`; the `StateIndicator` sits at app+0x74 with current state at indicator+0x14, and `SetState` = `FUN_0041bbd8` @0x41bbd8 (part_002.c:5510) — which also **pings three watcher chains** (indicator+0x18/+0x2c/+0x40, vtbl+0x14 notify) — this is how the fade renderable learns of state flips. + +Binary Application TU (part_007.c:3090-3810): +- **`FUN_0044eeb4` @0x44eeb4 = `Application::StopMissionMessageHandler`** (part_007.c:3698-3737): state 7 → ignore; state 6 or 10 → `Stop()` (@0x44e6c0) — this is the SECOND arrival; default → `SetState(6)`, and if `missionPlayer(app+0x14)` non-null: `networkManager->Mode(0=ReliableMode)` (vtbl+0x30 on app+0x20, part_007.c:3721 == T0 APP.cpp:1762) then dispatch **`Player::MissionEndingMessage {size 0x1c, id 0x19}`** to the player; if NO mission player → `Stop()` directly. Matches T0 APP.cpp:1705-1778 exactly. +- **`FUN_0044ef4c` @0x44ef4c = AbortMissionMessageHandler** — same shape, `SetState(10)`, no ReliableMode switch. +- **`FUN_0044e6c0` @0x44e6c0 = `Application::Stop()`**: `executeFrames(app+0x70)=0`; flush DEBUG stream; `SetState(7)`. (T0 APP.cpp:797-821.) +- **`FUN_0044e488` @0x44e488 = `Application::ExecuteForeground`** (part_007.c:3138-3176): returns 0 immediately when `executeFrames==0`; at state 5 recomputes `secondsRemainingInGame(app+0x58) = mission->length(+0xe0) − (Now−gameStarted(+0x5c))/tps`; final return is `executeFrames && !Exit_Code` where **Exit_Code = `DAT_004efc98`**. **There is NO pod-side action when the clock hits 0** — app+0x58 is display-only; the stop was the console's job. +- **`FUN_0044e6e8` @0x44e6e8 = base `Application::Shutdown`** (part_007.c:3239-3278): gauge/video/audio renderer `Shutdown+UnlinkFromEntity` (+0x4c/+0x48/+0x44), delete viewpointEntity (+0x6c), interestManager/hostManager/networkManager shutdown, delete `currentMission(+0xC8)`, then **`executeFrames=1; SetState(1=WaitingForEgg); return 0`**. +- Other rungs for contrast: CheckLoad `@0x44ebec` (2→3, and if **no console host** (`FUN_00429078(app+0x2c)`) self-launches RunMission — the console-less path), RunMission `@0x44ecdc` (3→4 + dispatch **MissionStarting id 0x18** to player; 4→5 + `gameStarted=Now()`; else Fail @APP.CPP:0x609 — the port's launch/load-race crash site), Suspend `@0x44ed88` (5→8 + dispatch id 0x19 — suspend ALSO rides the player MissionEnding fade), Resume `@0x44ee10`, KeyCommand `@0x44efd8` ('&'=0x26 → `Exit_Code=1` + `Stop()`). + +**There is NO app-side timer in the end arm.** The only end-sequence time constant anywhere is the player's 3.0 s fade (plus the fade renderable's cosmetic 1.0 s, §3). No mission-review display period exists at the app level; the ranking window is a separate per-player display driver (§below). + +**Ranking-window behavior at end** — `FUN_0042eb38` @0x42eb38 (part_004.c:1387-1426, called from PlayerSimulation/CameraShipSimulation): at states **6/7 the window flag (player+0x224) is forced 0 (hidden)**; while `secondsRemainingInGame > 30.0` (`_DAT_0042ec2c`=30.0, byte-read) it runs a periodic show/hide machine (+0x228/+0x22c/+0x230/+0x234); at ≤30 s it pins the flag to 1 (solid on). So the authentic end was: standings solid for the final 30 s, then StopMission → **ranking hidden + 1 s fade to black**. (The camera-seat DIRECTOR.cpp:107 additionally shows its ranking during EndingMission — different display, camera seat only.) + +**Crucial executability fact [T0]:** `Entity::Execute` (ENTITY.cpp:556-558, quoted in `context/reconstruction-gotchas.md §29:920-934`) calls `PerformAndWatch` only in `RunningMission || EndingMission || IsPreRunnable()` — so the world (and the player's fade countdown) KEEPS TICKING during state 6, and stops at state 7. A screen showing a *frozen last frame* therefore means the app got PAST state 6 (Stop() ran, `executeFrames=0`, renderers no longer execute) but the process never finished Shutdown/relaunch — whereas a player *stuck in state 6* would see a live, still-simulating world that never returns to menu. (Relevance flag for #163 triage, [T4 inference]: post-`RunMissions` in the modern port comes the matchlog-upload dial + relaunch (`context/multiplayer.md:110`, `:541-545`) — a blocking network call there matches "frozen final frame + hang on exit".) + +## 2. The Player handlers @0x4bfc20 / @0x4bfbe8 + +Base handlers (part_004.c:409-430): +- **`FUN_0042d9c0` @0x42d9c0 = base `Player::MissionStartingMessageHandler`**: `fadeTimeRemaining(+0x1F4) = 3.0f`; `SetSimulationState(3=MissionStartingState)`. +- **`FUN_0042d9e0` @0x42d9e0 = base `Player::MissionEndingMessageHandler`**: `fadeTimeRemaining = 3.0f`; **`ForceUpdate` (`+0x18 |= 1`)** — this ships the final player update record (score) under the just-switched reliable mode; `SetSimulationState(4=MissionEndingState)`. Neither touches the Performance pointer or `simulationFlags`. + +**BT overrides** (part_013.c:18556-18588; raw disasm of @0x4bfc20 via `tools/disas2.py` this session): +- **`FUN_004bfbe8` @0x4bfbe8 = BTPlayer::MissionStarting**: base @0x42d9c0, then `if (app->state==4 /*LaunchingMission*/ && !(this+0x29 & 0x40 /*NonScoringPlayerBit*/)) currentScore(+0x1c8) = 1000.0f` — the manual's "+1000 starting the game" seed (port: `game/reconstructed/btplayer.cpp:788-806`). +- **`FUN_004bfc20` @0x4bfc20 = BTPlayer::MissionEnding** — full body: + 1. base @0x42d9e0 (fade 3.0 + ForceUpdate + state 4); + 2. **`this+0x288 −= Round(15.0f × DAT_0052140c + 0.5)`** — recovered from raw bytes @0x4bfc3b-0x4bfc52 (`fld 15.0f @0x4bfca4; fmul [0x52140c]; fadd 0.5f @0x4bfca8; call __ftol@0x4dcd94; sub [ebx+0x288],eax`): it **rewinds the 15-second console score-total clock by exactly one period**, so the next PlayerSimulation tick immediately pushes the FINAL total score to the console (see §5). The old export dropped the x87 operand (`FUN_004dcd94()` rendered argless — the §19 gotcha); now pinned. + 3. `if (app->state == 8 /*SuspendingMission*/ && playerVehicle(+0x1fc) IsDerivedFrom Mech (tag 0x50bdb4))` → `FUN_0049fb74(mech, &DAT_00524b38, 1)` (= `Mech::Reset`, per the KB respawn chain — `context/decomp-reference.md` "Respawn SIM path"; the argument blob `DAT_00524b38` semantics unverified [T4]) + `ForceUpdate`. So the operator SUSPEND path resets the vehicle; the normal state-6 path does NOT. + - **No score finalization, no fade rendering, no waiting happens in this handler** — it is fire-and-forget bookkeeping; the actual fade/countdown/exit all run elsewhere. + +**The countdown** — **`FUN_0042df8c` @0x42df8c = `Player::ManageApplicationStatus`** (part_004.c:706-752; == T0 PLAYER.cpp:408-476): state 3: `fade −= dt`; at ≤0 (`_DAT_0042e0dc`=0.0) → state 2 (VehicleTranslocated) + dispatch RunMission (app state 4) / Resume (state 9). **State 4 (MissionEnding): `fade −= dt`; at ≤0 → app state 6 → dispatch `StopMissionMessage(exit 0)` (ctor @0x44f5d0); state 8 → SuspendMission; state 10 → AbortMission.** Called every tick from `Player::PlayerSimulation` @0x42e100 and `Player::CameraShipSimulation` @0x42e0e0 (part_004.c:756-781) — both flavors complete the ladder. (KB nit: `btplayer.cpp:1329` cites base PlayerSimulation as `FUN_0042e168`; @0x42e168 is only the vehicle-position-copy tail — the full base is @0x42e100.) + +**When can the countdown not run?** `Simulation::DoNothingOnce` = `NeverExecute()` = `simulationFlags |= DontExecuteFlag` (SIMULATE.cpp:484-488, SIMULATE.h:167-206). In the 1995 binary the master player is parked on DoNothingOnce only **pre-first-spawn** (`Player::HuntForDropZone` @0x42ddcc sets the pmf `PTR_FUN_004e67fc` at part_004.c:669 once the drop zone is found, until DropZoneReply re-arms). The BT death cycle does NOT park it: **`FUN_004c05c4` @0x4c05c4 = BTPlayer::VehicleDead** (part_013.c:19064-19156) contains **no SetPerformance/simulationFlags writes** — a mid-mission-dead player still ticks PlayerSimulation, so a StopMission arriving during a death window still completes the fade in 1995. Its first line is the state-4 gate (`this+0x40==4 → return`): once MissionEnding, all death traffic is swallowed. Also in the -1 arm: deaths dual-increment (+0x280), console **MechKilled id 8** via ctor @0x4c18cc gated `suppressConsole(+0x258)==0`, objectiveMech(+0x284)=killer's vehicle, lives check `role(+0x208)->returnFromDeath(+0x28) < 1` → post Mech id 0x18 (ClearBurningState) to the wreck at +10 s and NO respawn re-post; else re-post VehicleDead to self at +5.0 s (`@0x4c0830`=5.0f, byte-read); then the straight-line death cost gated `advancedDamageOn(+0x264)` via direct call to base ScoreMessageHandler @0x42da20. + +## 3. THE FADE (ticket #156) + +**Mechanism: a fog-color/fog-range animation on the main view — `POVStartEndRenderable`** (T0 `engine/MUNGA_L4/L4VIDRND.cpp:2126-2394`, binary ctor **`FUN_00454394` @0x454394**, Execute **`FUN_0045447c` @0x45447c**, part_007.c:8468-8606). Not a palette fade, not a gauge overlay, not the warp machinery. + +- **Built for the LOCAL (master) player only** by the video builder **`FUN_004d0774` @0x4d0774** (part_014.c:10673-10693): classID 0xBDA (BTPlayer): replicant (`(entity+0x28 & 0xc)==4`) → translocation-warp renderable @0x458d2c; **master → alloc 0x50 → `FUN_00454394(entity, Watcher=2, mainView, mainZone, deathZone, trigger, fogRGB, fogNear/Far, 3, 4)`**. The trigger = the player's **SimulationState attribute** (`FUN_0041bf44(entity,1)`), i.e. the same `StateIndicator` the MissionStarting/Ending handlers write; start state **3** = MissionStartingState, end state **4** = MissionEndingState. +- **State machine** (@0x45447c; myState at +0x1c, timer +0x3c, trigger state read at `trigger+0x14`): 0 WaitForStart → on trigger==3: fog snapped to WHITE (1,1,1) with near/far 0.01/0.05 (screen fully fogged = white flash), AddDynamicRenderable; 1 FlashScreen: hold **0.1 s** (`@0x454740`); 2 FadeIn: lerp fog color/ranges back over **1.0 s** (`@0x454744`); 3 MissionRunning: wait for trigger==4 → 4 FadeOut: fog color × percent-left → black, ranges collapse to 0.01/0.05 (`@0x45474c/0x454750`), over **1.0 s in the binary** — note the WinTesla source's `FADE_OUT_TIME (0.5f)` (L4VIDRND.cpp:2150) is a later edit; the shipped 1995 constant is 1.0 (the same `@0x454744` is reused as the fade-out duration at part_007.c:8584); at expiry → back to state 0 + RemoveDynamicRenderable. +- **What advances it:** the renderer's frame clock (`GetCurrentFrameTime`), NOT the player sim — once state 4 is set it completes even if the player sim is dormant. **What would happen if it never completed: nothing.** The ladder never reads the renderable; `ManageApplicationStatus` is the sole gatekeeper. The fade-out (1.0 s) simply fits inside the 3.0 s window; the pod then sat on a black screen ~2 s before teardown. +- **Why the port has no fade (#156 root cause):** the builder call exists (`game/reconstructed/btl4vid.cpp:311-315`, states 3/4 passed), but **`BTPOVStartEndRenderable`'s ctor is an empty stub — `game/reconstructed/btstubs.cpp:339-342`** — it never registers with the video renderer or the state dial. The white mission-start flash is missing for the same reason. All the plumbing it needs (SetState watcher ping @0x41bbd8, fog style/limits on the D3D renderer) already exists in the port. + +## 4. RunMissions exit + what the 1995 pod did next + +- **Exit condition** (T0 `engine/MUNGA/APPMGR.cpp:39-161`): `RunMissions` loops foreground/packet-route/background passes; when `application->ExecuteForeground(...)` returns False (binary: `executeFrames==0 || Exit_Code(DAT_004efc98)` — @0x44e488) it calls `application->Shutdown(n)`; **Shutdown returning False removes the app from `runningApplications`, and with no apps left RunMissions Terminates them and RETURNS.** +- **1995: the pod did NOT exit** — the L4 (pod) application overrides Shutdown: **`FUN_0047c560` @0x47c560** (part_010.c:2805-2820) = base Shutdown @0x44e6e8 (which re-arms `executeFrames=1` + `SetState(WaitingForEgg)`) then **`return (Exit_Code==0 && app+0xd4==0) ? 1 : 0`** — i.e. the app STAYS in the manager and the pod parks in WaitingForEgg for the console's next egg (the between-rounds attract wait). RunMissions only returned on the '&' keystroke (Exit_Code, @0x44efd8) or the `app+0xd4` shutdown latch (set by the two-phase handler **@0x47c2c4** — first receipt latches +0xd4 and re-posts, second receipt tears down; a console-initiated pod shutdown [T3 on its exact message id]). +- The modern build diverges deliberately: T0 APP.cpp:922-926 replaced the original `return !Exit_Code` with a hard `return False` (`#if 0` preserved in-source), and `engine/MUNGA_L4/L4APP.cpp` has **no** Shutdown override — so every mission end exits RunMissions, then btl4main uploads the matchlog and BT_FE_LOOP relaunches the menu (`context/multiplayer.md:110,541-545`). + +## 5. The end-of-mission pod↔console handshake + +All pod→console, fire-and-forget over the console link (clientID 5 = ConsoleClientID); **the ladder never waits for any console reply**. Names from the surviving original `game/original/BT/BTCNSL.CPP` (cnslmsgs.cpp) + T0 `engine/MUNGA/CONSOLE.h:11-18`: + +| When | Message {size, id} | Binary ctor / site | +|---|---|---| +| Every 10 s AND immediately once app state == **6** | score **DELTA** flush: self-dispatch ScoreUpdate {0x20, 0x1a} → the +0x278 delta cell is sent then **zeroed** | **`FUN_004c083c` @0x4c083c** (part_013.c:19160-19192): `10.0(@0x4c08fc) <= (this+0x10 − this+0x28c)/tps \|\| app+0x88==6`; port analog `btplayer.cpp:1361-1427` | +| Every **15 s** while state 5 or 6; forced immediately at MissionEnding by the @0x4bfc20 clock rewind | **ConsolePlayerMechScoreUpdate** (running TOTAL, from +0x1c8) {0x14, id 9} | ctor **@0x4c18f4**; send site part_013.c:19269-19279 (`_DAT_004c0bc0`=15.0, clock at +0x288) | +| Once, when `fadeTimeRemaining ≤ 1.5` in MissionEndingState (i.e. **halfway through the 3 s fade**, while the link is guaranteed still up), one-shot latch +0x254 | state 6: **ConsoleApplicationEndMissionMessage {0x14, id 7} {host, Round(score)}** (added 10/05/95 per BTCNSL.CPP:10); otherwise (abort/suspend): **ConsoleApplicationAbortMissionMessage {0x10, id 0xb}** | **BTPlayer::PlayerSimulation `FUN_004c0904` @0x4c0904**, block part_013.c:19251-19268, Tell string `"Sending EndMission..."` @0x5132d7; ctors @0x42998c / @0x4299b4 | +| On death (any time) | **ConsolePlayerMechKilled** {0x14, id 8} {victim, killer} | ctor @0x4c18cc, sent from VehicleDead @0x4c05c4 (part_013.c:19110-19114), suppressed after eject via +0x258 | +| On eject | DeathWithoutHonor (id 5) | `FUN_004c198c` (KB: decomp-reference EJECT cluster) | +| (team variants) | TeamScoreUpdate {0x14, 0xd} @0x4c191c; TeamEndMission {0x1c, 0xe} @0x4299d8 | | + +Plus two non-console end actions: **`networkManager->Mode(ReliableMode)`** at StopMission #1 (@0x44eeb4/T0 APP.cpp:1762) and the base MissionEnding **ForceUpdate** shipping the final player record to peers. Also note part_013.c:19280-19282: while state 5 **or 6**, the player record is re-dirtied (`+0x18 |= 1`) whenever none has shipped for 1.0 s (`_DAT_004c0bc4`) — a 1995 1 Hz player-record keepalive that keeps running through the ending window. + +## 6. Stall matrix (the ticket's question, binary-grounded) + +| Leg | Driven by | Can it stall? | +|---|---|---| +| StopMission #1 → state 6 | console event over the console link | YES — if it never arrives the mission runs forever (1995 design; modern relay adds the +15 s RelayGameDown fallback, multiplayer.md:519-521). World stays LIVE (not frozen). | +| state 6 → StopMission #2 | **3.0 s of MISSION-PLAYER SIM TIME** (@0x42df8c) | YES — iff the mission player's Performance stops executing while in MissionEndingState (DontExecuteFlag latched, or its Performance never calls ManageApplicationStatus). In 1995 the only such window is pre-first-spawn (HuntForDropZone→DoNothingOnce, part_004.c:669). Result: app parks in state 6 forever — world keeps ticking (ENTITY.cpp:556-558), ranking window hidden (@0x42eb38), never returns to menu. | +| StopMission #2 → Stop() | direct synchronous Dispatch | NO (cannot be lost). | +| Stop() → RunMissions return | next foreground pass: ExecuteForeground→0, then Shutdown (synchronous renderer/network/mission teardown @0x44e6e8) | Only if a Shutdown callee BLOCKS (e.g. a network shutdown on a dead transport). From Stop() onward the screen is a FROZEN LAST FRAME (renderers no longer execute) — the shape #163 describes. | +| visual fade | renderer frame clock, passive watcher | irrelevant — nothing waits on it; in the port it's a stub anyway (btstubs.cpp:339-342). | diff --git a/engine/MUNGA_L4/L4STEAMNET.cpp b/engine/MUNGA_L4/L4STEAMNET.cpp index 7707e7a..578e61e 100644 --- a/engine/MUNGA_L4/L4STEAMNET.cpp +++ b/engine/MUNGA_L4/L4STEAMNET.cpp @@ -632,3 +632,49 @@ unsigned long long } return SteamUser()->GetSteamID().ConvertToUint64(); } + +// +// #163 -- the ORDERED transport shutdown for process exit (2026-08-11). +// +// The port never called SteamAPI_Shutdown(): every round-end died via bare +// ExitProcess with live SNS connections and Steam callback threads, and the +// DLL_PROCESS_DETACH path intermittently DEADLOCKED. When it did, the old +// process froze holding its last fullscreen frame ("frozen view of how the +// game ended") while its already-spawned menu child hung inside +// SteamAPI_Init against the wedged sibling's client session -- field- +// captured on ZEUS at 22:12:38 (a 3-line child boot stub that never reached +// the unconditional [steamnet] up line). Closing every connection and +// shutting the API down BEFORE the child is spawned hands it a clean Steam +// client and leaves detach nothing to strangle. Callers then die via +// TerminateProcess, which skips DLL detach entirely. +// +void + BTSteamNet_ShutdownAll() +{ + if (!steamActive) + { + return; + } + ISteamNetworkingSockets *sockets = SteamNetworkingSockets(); + for (int i = 0; i < MaxConnections; ++i) + { + if (connections[i].inUse + && connections[i].connection != k_HSteamNetConnection_Invalid) + { + sockets->CloseConnection(connections[i].connection, 0, + "round over", false); + } + connections[i].inUse = 0; + } + for (int p = 0; p < FakePortCount; ++p) + { + if (listenSockets[p] != k_HSteamListenSocket_Invalid) + { + sockets->CloseListenSocket(listenSockets[p]); + listenSockets[p] = k_HSteamListenSocket_Invalid; + } + } + SteamAPI_RunCallbacks(); // let the closes flush client-side + steamActive = 0; + SteamAPI_Shutdown(); +} diff --git a/game/btl4main.cpp b/game/btl4main.cpp index 90f1f4c..7ddc1a8 100644 --- a/game/btl4main.cpp +++ b/game/btl4main.cpp @@ -1241,6 +1241,16 @@ int WINAPI WinMain(HINSTANCE hInstance, HINSTANCE hPrevInstance, LPSTR lpCmdLine if (BTFrontEnd_Run(&fe_spec) != 0 || fe_spec.mode == BTFeLaunchNone) { BTLastrunNote("clean exit: player quit from the menu"); +#ifdef BT_STEAM + // #163: the menu keeps the Steam transport up for the lobby; + // returning through the CRT would run DLL detach with live + // Steam threads -- the same intermittent deadlock the + // round-end relaunch hit. Tear it down deliberately first. + { + extern void BTSteamNet_ShutdownAll(); + BTSteamNet_ShutdownAll(); + } +#endif return 0; // quit from the menu } char fe_arguments[192]; diff --git a/game/glass/btl4console.cpp b/game/glass/btl4console.cpp index 0047cc0..e5e189b 100644 --- a/game/glass/btl4console.cpp +++ b/game/glass/btl4console.cpp @@ -94,6 +94,7 @@ static MarshalState marshalState; // #ifdef BT_STEAM extern int BTSteamNet_IsFakeAddress(unsigned long internet_address_be); +extern void BTSteamNet_ShutdownAll(); // #163: ordered exit extern SOCKET BTSteamNet_Connect(unsigned long internet_address_be, int remote_port); extern int BTSteamNet_Owns(SOCKET wire_socket); extern int BTSteamNet_Send(SOCKET wire_socket, const char *data, int length); @@ -153,6 +154,48 @@ static unsigned long return gBTBootTick != 0 ? gBTBootTick : GetTickCount(); } +// +// #163 -- ORDERLY DEATH (2026-08-11). Bare ExitProcess ran DLL detach with +// live Steam threads and intermittently deadlocked: the dying process kept +// its last fullscreen frame on screen ("frozen view of how the game ended") +// while the healthy menu child it had already spawned hung in SteamAPI_Init +// against the wedged sibling -- both round-end freeze reports AND the +// hang-on-exit reports, one mechanism (the HOST worst: this exit runs on +// the MARSHAL thread while the main thread is mid-teardown). The order: +// flush the forensics, tear the Steam transport down, hide every window +// this process owns (a residual wedge must never squat on the screen), then +// TerminateProcess -- which skips DLL detach entirely, making the deadlock +// structurally unreachable. The 1995 pod never exited between rounds at +// all (@0x47c560 parks in WaitingForEgg), so exit is pure port territory -- +// no binary semantic to preserve. +// +static BOOL CALLBACK + HideProcessWindow(HWND window, LPARAM pid) +{ + DWORD owner = 0; + GetWindowThreadProcessId(window, &owner); + if (owner == (DWORD)pid) + { + ShowWindow(window, SW_HIDE); + } + return TRUE; +} + +static void + BTOrderlyDie(void) +{ + { + extern void BTMatchLogClose(); + BTMatchLogClose(); // complete receipts on disk (the + } // field matchlogs lost their tails) + fflush(NULL); +#ifdef BT_STEAM + BTSteamNet_ShutdownAll(); +#endif + EnumWindows(HideProcessWindow, (LPARAM)GetCurrentProcessId()); + TerminateProcess(GetCurrentProcess(), 0); +} + void BTFE_RelaunchSelfAndExit(const char *arguments) { @@ -176,7 +219,7 @@ void "(no relaunch)"); extern void BTLastrunNote(const char *); BTLastrunNote("clean exit: player closed the game window"); - ExitProcess(0); + BTOrderlyDie(); // #163: never bare ExitProcess } } @@ -251,6 +294,18 @@ void } command_line[n] = 0; + // #163 step (a): forensics flushed + the Steam transport DOWN before the + // child exists -- it must find a clean Steam client (the field capture: + // a menu child hung in SteamAPI_Init against its wedged sibling). + { + extern void BTMatchLogClose(); + BTMatchLogClose(); + } + fflush(NULL); +#ifdef BT_STEAM + BTSteamNet_ShutdownAll(); +#endif + STARTUPINFOW startup; PROCESS_INFORMATION process; memset(&startup, 0, sizeof(startup)); @@ -272,7 +327,9 @@ void CloseHandle(process.hThread); CloseHandle(process.hProcess); } - ExitProcess(0); + // #163 step (b): vanish, then die without touching DLL detach. + EnumWindows(HideProcessWindow, (LPARAM)GetCurrentProcessId()); + TerminateProcess(GetCurrentProcess(), 0); } //###########################################################################