diff --git a/docs/architecture/retail-divergence-register.md b/docs/architecture/retail-divergence-register.md index 231a8856..eff9cfe8 100644 --- a/docs/architecture/retail-divergence-register.md +++ b/docs/architecture/retail-divergence-register.md @@ -102,6 +102,7 @@ accepted-divergence entries (#96, #49, #50). | AD-41 | The `candidateMoved` gate (retail UpdateObjectInternal pc:283657 `candidate != m_position`) suppresses ONLY `handle_all_collisions` + `cached_velocity` on a no-move frame; acdream still runs `ResolveWithTransition` (zero-distance) for cell/contact tracking, where retail skips the whole transition (#182 rebuild, 2026-07-07) | `src/AcDream.App/Input/PlayerMovementController.cs` (`candidateMoved` guard) | The load-bearing effect is not re-zeroing the gravity velocity that rebuilds after a stuck-fall bleed; the zero-distance resolve is a near-no-op (numSteps 0 → the zero-step early return, no ValidateTransition, contact plane persists via the writeback), so running it is harmless while keeping acdream's per-frame cell/membership refresh | If the zero-distance resolve ever gains a side effect on a no-move frame (a contact-plane clear, an fsf change), it would diverge from retail's skip — a no-move frame must stay a near-no-op | `CPhysicsObj::UpdateObjectInternal` 0x005156b0 pc:283657 (candidate-moved gate) | | AD-42 | Enter-world placement is split across two Core calls: legacy `Resolve` performs retail `AdjustPosition` + the host's established floor snap, then `ResolvePlacement` runs the verbatim object-aware `find_placement_pos` ring search. Retail runs initial environment placement, ring search, and final step-down inside one `find_placement_position` transition | `src/AcDream.App/Rendering/GameWindow.cs` (`EnterPlayerModeNow`); `src/AcDream.Core/Physics/PhysicsEngine.cs` (`ResolvePlacement`) | The first call has already committed the same validated cell/floor point that feeds the ring search; the second call uses the same sphere dimensions, collision registry, and cell id. Keeping the split preserves the proven indoor-login snap while adding the missing occupied-position behavior | A spawn that requires retail's final placement step-down after a ring candidate (rather than the existing floor snap before it) could settle at a slightly different Z on a ledge/water boundary; the overlap is still cleared | `CPhysicsObj::enter_world` 0x00516170; `CTransition::find_placement_position` 0x0050C170; `CTransition::find_placement_pos` 0x0050BA50 | | AD-43 | A malformed/custom PhysicsScript `CallPES` cycle whose script timeline never advances is rejected with a diagnostic; retail's linked scheduler would continue draining that zero-time tail indefinitely | `src/AcDream.Core/Vfx/PhysicsScriptRunner.cs` (timeline-progress ancestry guard) | Prevents corrupt DAT content from hanging the single update/render thread. Installed-DAT audit plus conformance tests prove the real rolling-weather cycles advance 2.8 seconds per edge and continue unchanged; only a no-progress strongly connected cycle is rejected | A custom DAT that deliberately relies on an infinite zero-time loop observes a rejected play instead of freezing the client | `ScriptManager::AddScriptInternal` 0x0051B310; `ScriptManager::UpdateScripts` 0x0051B480; `CPhysicsObj::CallPES` 0x00511AF0 | +| AD-44 | Native-window close performs retail's complete character-logoff handshake and transport disconnect, then exits the process instead of retaining the authenticated logon connection and returning to character selection. acdream has one active `ReceiverData` equivalent, so `ClientNet::LogOffServer`'s per-receiver disconnect loop sends one header. | `src/AcDream.Core.Net/WorldSession.cs` (`Dispose`); `src/AcDream.Core.Net/Packets/TransportDisconnect.cs` | The application currently auto-selects one character and has no character-selection presentation/state owner to receive the returned authenticated session. Close must still release ACE immediately and in retail order. | Closing is correct, but an eventual in-client "log off character" action cannot reuse this process-exit path; it needs an App/session transition that retains the socket after server `0xF653` rather than calling `Dispose`. | `Proto_UI::LogOffCharacter @ 0x00546A20`; `CPlayerSystem::RequestLogOff @ 0x00562DD0`; `CPlayerSystem::ExecuteLogOff @ 0x0055D780`; `ClientNet::LogOffServer @ 0x00543EF0`; `SharedNet::SendOptionalHeader @ 0x00543160` | --- diff --git a/docs/research/2026-05-10-phase-m-opcode-matrix.md b/docs/research/2026-05-10-phase-m-opcode-matrix.md index a375c230..98310284 100644 --- a/docs/research/2026-05-10-phase-m-opcode-matrix.md +++ b/docs/research/2026-05-10-phase-m-opcode-matrix.md @@ -168,7 +168,7 @@ In-scope: 51. Implemented in acdream: 21. Phase M target delta: 30. | 0xEA60 | inbound | AdminEnvirons | `CPlayerSystem::Handle_Admin__Environs` | – | B | P+W | P+W | Fog presets / sound cues | | 0xF625 | inbound | ObjDescEvent | `SmartBox::HandleObjDescEvent` | PB | B | P+W | P+W | Per-entity appearance update | | 0xF643 | inbound | CharacterCreateResponse | – | PB | B | – | –defer:char-creation | Char-creation flow not yet built | -| 0xF653 | outbound | CharacterLogOff | – | PB | P | B | PB+W | Sent on Dispose; ACE accepts | +| 0xF653 | both | CharacterLogOff | – | PB | P | B | PB+W | Request carries active character GUID; opcode-only server confirmation gates transport disconnect | | 0xF655 | both | CharacterDelete | – | PB | P | – | –defer:char-mgmt | Char-management UI deferred | | 0xF656 | outbound | CharacterCreate | – | PB | P | – | –defer:char-creation | Char-creation flow not yet built | | 0xF657 | outbound | CharacterEnterWorld | `CM_Login::SendNotice_BeginEnterWorld` [^m-2] | PB | P | B | PB+W | Built; sent during handshake | diff --git a/docs/research/2026-07-20-retail-graceful-logout-pseudocode.md b/docs/research/2026-07-20-retail-graceful-logout-pseudocode.md new file mode 100644 index 00000000..363acd7a --- /dev/null +++ b/docs/research/2026-07-20-retail-graceful-logout-pseudocode.md @@ -0,0 +1,70 @@ +# Retail graceful character logout + +## Oracle + +- `Proto_UI::LogOffCharacter` `0x00546A20` +- `CPlayerSystem::RequestLogOff` `0x00562DD0` +- inbound login-message dispatch at `0x0055C963` +- `CPlayerSystem::ExecuteLogOff` `0x0055D780` +- `ClientNet::ExitWorldDisconnect` `0x00541E00` +- `ClientNet::LogOffServer` `0x00543EF0` +- `SharedNet::SendOptionalHeader` `0x00543160` +- `CPlayerSystem::LogOffCharacter` `0x00563520` + +Cross-checks: + +- ACE `CharacterHandler.CharacterLogOff` begins asynchronous player removal. +- ACE `Session.SendFinalLogOffMessages` sends the opcode-only `CharacterLogOff` + confirmation only after the player no longer owns a landblock, then returns + the session to `AuthConnected`. +- Holtburger currently sends opcode-only and disconnects immediately. Its own + comment records that AC normally waits for the server response. That shortcut + is not the retail oracle and was the source of acdream's reconnect race. + +## Pseudocode + +```text +LogOffCharacter(force): + save player module + if force: + ExecuteLogOff() + return + if no interaction is pending: + RequestLogOff() + else: + print "Logging off..." + remember that logout must begin after the interaction + +RequestLogOff(): + print "Logging off..." + send_to_logon([0xF653, active_player_id]) + logOffRequested = true + logOffRequestTime = now + 3 seconds + if player is PK: + logOffRequestTime += 20 seconds + +on inbound login message 0xF653: + ExecuteLogOff() + +ExecuteLogOff(): + clear player-login state + for every live ReceiverData connection: + send a cleartext, empty DISCONNECT optional header + use sequence 0 plus that receiver's network id and iteration + disconnect the world connection + clear the active player id +``` + +## acdream close-only adaptation + +acdream does not yet return to character selection when its native window is +closed. It retains retail's important ordering: send the eight-byte request, +continue receiving until the server's opcode-only confirmation arrives, then +send the transport `DISCONNECT` and release the socket. World callbacks are not +dispatched while shutdown drains the raw receive queue because their App owners +may already be tearing down. A bounded 35-second wait covers retail's additional +20-second PK logout delay and is only a transport safety +limit; the normal path advances on the authoritative confirmation, not elapsed +time. The connected gate separately observes ACE accepting the transport header +before opening a replacement process; ACE removes the authenticated session on +its world-manager tick, after the UDP sender has already completed. diff --git a/docs/research/deepdives/r08-network-protocol-atlas.md b/docs/research/deepdives/r08-network-protocol-atlas.md index 951ee108..6755ea65 100644 --- a/docs/research/deepdives/r08-network-protocol-atlas.md +++ b/docs/research/deepdives/r08-network-protocol-atlas.md @@ -181,7 +181,7 @@ is the opcode itself, followed immediately by the payload. | 0xF619 | PositionAndMovement | GM | S→C | unhandled | P4 | Ghost opcode — declared but never fired by ACE. | | 0xF625 | ObjDescEvent | GM | S→C | unhandled | P1 | `u32 guid, ObjectDescription` — full re-send of visual description (body parts, textures, palettes). Critical for seeing other players' gear changes. | | 0xF643 | CharacterCreateResponse / CharacterRestoreResponse | GM | S→C | unhandled | P0+ | `u32 responseCode` — login-phase, only relevant after char-create. Same opcode, two semantics (disambiguated by session state). | -| 0xF653 | CharacterLogOff | GM | bi | partial | P0 | No payload. Client sends before Disconnect to release the character lock immediately. acdream sends it from `Dispose`. | +| 0xF653 | CharacterLogOff | GM | bi | parsed | P0 | Client request is opcode + active character GUID; server confirmation is opcode-only. acdream waits for confirmation before transport Disconnect. | | 0xF655 | CharacterDelete | GM | bi | unhandled | P4 | `u32 slot` — char-select-screen deletion. | | 0xF656 | CharacterCreate | GM | C→S | unhandled | P4 | Full character-creation blob — heritage, gender, starting town, appearance. | | 0xF657 | CharacterEnterWorld | GM | C→S | done | P0 | `u32 characterGuid, string16L account`. Built by `Messages/CharacterEnterWorld.cs`. | @@ -859,8 +859,9 @@ All the P3/P4 tails. Ship when we need them, not before. - **0x00A3/0x00A4 FellowshipQuit/Dismiss** — same pairing; C→S in GameAction, S→C in GameEvent. - **0xF653 CharacterLogOff** — bi-directional, same opcode, no - envelope. Client sends to request logout; server sends the echo - before Disconnect. + envelope. Retail's client request carries the active character GUID; + the server confirmation is opcode-only. The client waits for that + confirmation before disconnecting the world transport. - **0x01A8 MagicRemoveSpell** — C→S is GameAction, S→C is GameEvent. - **0xF7DE TurbineChat** — bi-directional GameMessage. Blob layout includes a `ChatNetworkBlobType` discriminant (EVENT_BINARY=1, diff --git a/src/AcDream.Core.Net/Messages/CharacterLogOff.cs b/src/AcDream.Core.Net/Messages/CharacterLogOff.cs new file mode 100644 index 00000000..d92a50e0 --- /dev/null +++ b/src/AcDream.Core.Net/Messages/CharacterLogOff.cs @@ -0,0 +1,38 @@ +using System.Buffers.Binary; +using AcDream.Core.Net.Packets; + +namespace AcDream.Core.Net.Messages; + +/// +/// Retail character-logoff request and server confirmation (opcode +/// 0xF653). +/// +/// +/// Retail Proto_UI::LogOffCharacter at 0x00546A20 sends the +/// opcode followed by the active character id. The server confirmation uses +/// the same opcode with no trailing payload. CPlayerSystem::RequestLogOff +/// at 0x00562DD0 waits for that confirmation; its inbound dispatch calls +/// CPlayerSystem::ExecuteLogOff at 0x0055D780, which only then +/// disconnects the world connection. +/// +public static class CharacterLogOff +{ + public const uint Opcode = 0xF653u; + + /// Builds retail's eight-byte client request. + public static byte[] BuildRequestBody(uint characterId) + { + var writer = new PacketWriter(8); + writer.WriteUInt32(Opcode); + writer.WriteUInt32(characterId); + return writer.ToArray(); + } + + /// + /// Returns whether a complete game-message body is the server's logoff + /// confirmation. ACE emits the canonical four-byte opcode-only form. + /// + public static bool IsConfirmation(ReadOnlySpan body) => + body.Length >= sizeof(uint) && + BinaryPrimitives.ReadUInt32LittleEndian(body) == Opcode; +} diff --git a/src/AcDream.Core.Net/Packets/TransportDisconnect.cs b/src/AcDream.Core.Net/Packets/TransportDisconnect.cs new file mode 100644 index 00000000..42e13623 --- /dev/null +++ b/src/AcDream.Core.Net/Packets/TransportDisconnect.cs @@ -0,0 +1,31 @@ +namespace AcDream.Core.Net.Packets; + +/// +/// Builds retail's connection-level disconnect packet. +/// +/// +/// ClientNet::LogOffServer at 0x00543EF0 creates the +/// 0x8000 optional header and sends it through +/// SharedNet::SendOptionalHeader at 0x00543160. That path +/// zero-initializes the packet sequence and copies the receiver's network id +/// and iteration into the fixed header. The disconnect is cleartext and has +/// no body. +/// +public static class TransportDisconnect +{ + public static byte[] Build(ushort networkId, ushort iteration) + { + var header = new PacketHeader + { + Sequence = 0, + Flags = PacketHeaderFlags.Disconnect, + Id = networkId, + Iteration = iteration, + }; + + return PacketCodec.Encode( + header, + ReadOnlySpan.Empty, + outboundIsaac: null); + } +} diff --git a/src/AcDream.Core.Net/WorldSession.cs b/src/AcDream.Core.Net/WorldSession.cs index b5e27ad8..fa9a3366 100644 --- a/src/AcDream.Core.Net/WorldSession.cs +++ b/src/AcDream.Core.Net/WorldSession.cs @@ -28,10 +28,9 @@ namespace AcDream.Core.Net; /// /// /// -/// Not yet provided (deferred): ACK pump, retransmit handling, -/// delete-object processing, position updates, chat, disconnect detection. -/// The current client is one-shot — connect, enter the world, stream -/// events for a few seconds, let the test harness tear it down. +/// Still deferred: retransmit handling and unsolicited-disconnect +/// recovery. ACKs, world updates, chat, and retail-ordered graceful logout +/// are live. /// /// public sealed class WorldSession : IDisposable @@ -627,6 +626,7 @@ public sealed class WorldSession : IDisposable private IsaacRandom? _inboundIsaac; private IsaacRandom? _outboundIsaac; private ushort _sessionClientId; + private ushort _sessionIteration; private uint _clientPacketSequence; private uint _fragmentSequence = 1; @@ -639,6 +639,9 @@ public sealed class WorldSession : IDisposable private ushort _serverControlSequence; private ushort _teleportSequence; private ushort _forcePositionSequence; + private uint _activeCharacterId; + private int _characterLogOffConfirmed; + private int _disposeStarted; // Phase A.3: background receive thread buffers raw UDP datagrams into // a channel so the render thread never blocks on socket I/O. @@ -739,6 +742,10 @@ public sealed class WorldSession : IDisposable _inboundIsaac = new IsaacRandom(serverSeedBytes); _outboundIsaac = new IsaacRandom(clientSeedBytes); _sessionClientId = (ushort)opt.ConnectRequestClientId; + // SharedNet::SendOptionalHeader @ 0x00543160 copies this ReceiverData + // generation into connection-level control packets, including the + // final disconnect. ACE currently emits iteration 1. + _sessionIteration = cr.Header.Iteration; _clientPacketSequence = 2; byte[] crBody = new byte[8]; @@ -772,6 +779,7 @@ public sealed class WorldSession : IDisposable var deadline = DateTime.UtcNow + (timeout ?? TimeSpan.FromSeconds(10)); var chosen = Characters.Characters[characterIndex]; + _activeCharacterId = chosen.Id; Transition(State.EnteringWorld); SendGameMessage(CharacterEnterWorld.BuildEnterWorldRequestBody()); @@ -910,7 +918,10 @@ public sealed class WorldSession : IDisposable return true; } - private void ProcessDatagram(byte[] bytes, List? opcodesOut = null) + private void ProcessDatagram( + byte[] bytes, + List? opcodesOut = null, + bool dispatchWorldEvents = true) { var dec = PacketCodec.TryDecode(bytes, _inboundIsaac); if (!dec.IsOk) return; @@ -954,6 +965,19 @@ public sealed class WorldSession : IDisposable uint op = BinaryPrimitives.ReadUInt32LittleEndian(body); opcodesOut?.Add(op); + // Retail waits for the server's opcode-only CharacterLogOff echo + // before tearing down the world connection. Record it even while + // Dispose is draining the raw receive queue without dispatching + // world callbacks to owners that are already shutting down. + if (CharacterLogOff.IsConfirmation(body)) + { + Interlocked.Exchange(ref _characterLogOffConfirmed, 1); + continue; + } + + if (!dispatchWorldEvents) + continue; + if (op == CharacterList.Opcode && Characters is null) { try { Characters = CharacterList.Parse(body); } @@ -1915,41 +1939,48 @@ public sealed class WorldSession : IDisposable } /// - /// Graceful shutdown: tell the server we're leaving so it releases the - /// character lock immediately instead of waiting 60s for the session to - /// time out. Pattern from - /// references/holtburger/crates/holtburger-core/src/client/commands.rs - /// lines 879-892: send CharacterLogOff game message (opcode - /// 0xF653, no payload) then send a bare DISCONNECT control - /// packet (header flag 0x8000, no payload). + /// Graceful shutdown: request character logoff, wait for the server's + /// authoritative 0xF653 confirmation, and only then disconnect the + /// transport. This is retail's CPlayerSystem::RequestLogOff to + /// inbound confirmation to ExecuteLogOff ordering. It prevents a + /// replacement session from racing the old character's asynchronous + /// removal on ACE. /// public void Dispose() { + if (Interlocked.Exchange(ref _disposeStarted, 1) != 0) + return; + if (CurrentState == State.InWorld) { try { - // Tell ACE "player is leaving the world" so it cleans up - // the character immediately. - var logoff = new Packets.PacketWriter(8); - logoff.WriteUInt32(0xF653u); // CharacterLogOff opcode - SendGameMessage(logoff.ToArray()); + // Proto_UI::LogOffCharacter @ 0x00546A20 sends the active id. + Interlocked.Exchange(ref _characterLogOffConfirmed, 0); + SendGameMessage(CharacterLogOff.BuildRequestBody(_activeCharacterId)); + Console.WriteLine( + $"[session] graceful logout requested character=0x{_activeCharacterId:X8}"); - // Tell the transport layer "close this session." - var disconnectHeader = new PacketHeader - { - Sequence = _clientPacketSequence++, - Flags = PacketHeaderFlags.Disconnect, - Id = _sessionClientId, - }; - byte[] disconnectPacket = PacketCodec.Encode( - disconnectHeader, ReadOnlySpan.Empty, outboundIsaac: null); - _net.Send(disconnectPacket); + if (WaitForCharacterLogOffConfirmation(TimeSpan.FromSeconds(35))) + Console.WriteLine("[session] graceful logout confirmed"); + else + Console.Error.WriteLine( + "[session] graceful logout confirmation timed out; disconnecting transport"); } - catch + catch (Exception error) { - // Best-effort — if the socket is already dead, eat the - // exception and let Dispose finish cleaning up. + Console.Error.WriteLine( + $"[session] graceful logout failed: {error.Message}"); + } + + try + { + SendTransportDisconnect(); + } + catch (Exception error) + { + Console.Error.WriteLine( + $"[session] transport disconnect failed: {error.Message}"); } } @@ -1961,5 +1992,47 @@ public sealed class WorldSession : IDisposable _netCancel.Dispose(); _net.Dispose(); + Transition(State.Disconnected); + } + + private bool WaitForCharacterLogOffConfirmation(TimeSpan timeout) + { + using var timeoutSource = new CancellationTokenSource(timeout); + + try + { + while (Volatile.Read(ref _characterLogOffConfirmed) == 0) + { + while (_inboundQueue.Reader.TryRead(out byte[]? bytes)) + { + ProcessDatagram(bytes, dispatchWorldEvents: false); + if (Volatile.Read(ref _characterLogOffConfirmed) != 0) + return true; + } + + _inboundQueue.Reader.WaitToReadAsync(timeoutSource.Token) + .AsTask() + .GetAwaiter() + .GetResult(); + } + } + catch (OperationCanceledException) + { + return false; + } + catch (ChannelClosedException) + { + return false; + } + + return true; + } + + private void SendTransportDisconnect() + { + byte[] disconnectPacket = TransportDisconnect.Build( + _sessionClientId, + _sessionIteration); + _net.Send(disconnectPacket); } } diff --git a/tests/AcDream.Core.Net.Tests/Messages/CharacterLogOffTests.cs b/tests/AcDream.Core.Net.Tests/Messages/CharacterLogOffTests.cs new file mode 100644 index 00000000..41af606c --- /dev/null +++ b/tests/AcDream.Core.Net.Tests/Messages/CharacterLogOffTests.cs @@ -0,0 +1,36 @@ +using System.Buffers.Binary; +using AcDream.Core.Net.Messages; + +namespace AcDream.Core.Net.Tests.Messages; + +public sealed class CharacterLogOffTests +{ + [Fact] + public void BuildRequestBody_MatchesRetailOpcodeThenCharacterId() + { + byte[] body = CharacterLogOff.BuildRequestBody(0x5000000Au); + + Assert.Equal(8, body.Length); + Assert.Equal( + CharacterLogOff.Opcode, + BinaryPrimitives.ReadUInt32LittleEndian(body)); + Assert.Equal( + 0x5000000Au, + BinaryPrimitives.ReadUInt32LittleEndian(body.AsSpan(4))); + } + + [Fact] + public void IsConfirmation_AcceptsServerOpcodeOnlyBody() + { + byte[] body = BitConverter.GetBytes(CharacterLogOff.Opcode); + + Assert.True(CharacterLogOff.IsConfirmation(body)); + } + + [Fact] + public void IsConfirmation_RejectsTruncatedOrDifferentMessage() + { + Assert.False(CharacterLogOff.IsConfirmation([0x53, 0xF6, 0x00])); + Assert.False(CharacterLogOff.IsConfirmation(BitConverter.GetBytes(0xF654u))); + } +} diff --git a/tests/AcDream.Core.Net.Tests/Packets/TransportDisconnectTests.cs b/tests/AcDream.Core.Net.Tests/Packets/TransportDisconnectTests.cs new file mode 100644 index 00000000..52c71fbf --- /dev/null +++ b/tests/AcDream.Core.Net.Tests/Packets/TransportDisconnectTests.cs @@ -0,0 +1,26 @@ +using AcDream.Core.Net.Packets; + +namespace AcDream.Core.Net.Tests.Packets; + +public sealed class TransportDisconnectTests +{ + [Fact] + public void Build_MatchesRetailOptionalHeaderShape() + { + byte[] datagram = TransportDisconnect.Build(0x1234, 0x0001); + + Assert.Equal(PacketHeader.Size, datagram.Length); + + PacketHeader header = PacketHeader.Unpack(datagram); + Assert.Equal(0u, header.Sequence); + Assert.Equal(PacketHeaderFlags.Disconnect, header.Flags); + Assert.Equal((ushort)0x1234, header.Id); + Assert.Equal((ushort)0x0001, header.Iteration); + Assert.Equal((ushort)0, header.DataSize); + + PacketCodec.PacketDecodeResult decoded = PacketCodec.TryDecode( + datagram, + inboundIsaac: null); + Assert.True(decoded.IsOk); + } +} diff --git a/tools/run-connected-world-lifecycle-gate.ps1 b/tools/run-connected-world-lifecycle-gate.ps1 index 861bd45b..f4360265 100644 --- a/tools/run-connected-world-lifecycle-gate.ps1 +++ b/tools/run-connected-world-lifecycle-gate.ps1 @@ -3,6 +3,7 @@ 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 ) @@ -47,11 +48,44 @@ function Wait-ForPattern( 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(30000)) { return $false } + if (-not $Client.WaitForExit(45000)) { return $false } $Client.WaitForExit() return $true } @@ -79,7 +113,10 @@ function Add-LogFailures([string]$Label, [string]$Stdout, [string]$Stderr) { 'device removed', 'GPU reset', 'live: disconnected', - 'screenshot-failed' + '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) @@ -155,9 +192,11 @@ function Invoke-Session( $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' @@ -180,6 +219,12 @@ function Invoke-Session( -RedirectStandardOutput $stdout -RedirectStandardError $stderr -PassThru Wait-ForPattern $client $stdout '[UI-PROBE] UI probe script complete' $SessionTimeoutSeconds + $clientPort = @(Get-NetUDPEndpoint -OwningProcess $client.Id -ErrorAction SilentlyContinue | + Select-Object -First 1 -ExpandProperty LocalPort) + if ($clientPort.Count -ne 1) { + throw "could not resolve the client's UDP endpoint for ACE disconnect verification" + } + $client.Refresh() $processSample = [pscustomobject][ordered]@{ WorkingSetMiB = [Math]::Round($client.WorkingSet64 / 1MB, 1) @@ -206,7 +251,6 @@ function Invoke-Session( if (-not (Test-Png $png)) { $failures.Add("${Label}: missing or invalid screenshot '$png'") } } - Add-LogFailures $Label $stdout $stderr $graceful = Close-ClientGracefully $client $client.Refresh() if ($client.HasExited) { $exitCode = [int]$client.ExitCode } @@ -214,6 +258,15 @@ function Invoke-Session( 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 $session = [pscustomobject][ordered]@{ Label = $Label @@ -281,6 +334,9 @@ if (@(Get-Process -Name AcDream.App -ErrorAction SilentlyContinue).Count -gt 0) 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 @@ -297,10 +353,9 @@ $capped = Invoke-Session ` Add-SameLocationGates $capped -# The second process is both the session-teardown/reconnect gate and the -# uncapped renderer sample. A short pause lets ACE finish releasing the first -# session before the same account logs in again. -Start-Sleep -Seconds 3 +# The second process starts as soon as ACE records accepting the first +# process's transport Disconnect. No elapsed-time settle delay hides a +# shutdown race. $null = Invoke-Session ` 'uncapped-reconnect' ` (Join-Path $Repository 'tools\connected-world-reconnect.route.txt') `