From 427332acaad27f2b94920fd764089bf0328ac78a Mon Sep 17 00:00:00 2001 From: Erik Date: Sat, 4 Jul 2026 20:29:10 +0200 Subject: [PATCH] =?UTF-8?q?fix(#170):=20stop=20per-frame=20interpreted=20r?= =?UTF-8?q?e-dispatch=20flooding=20pending=5Fmotions=20(partial=20?= =?UTF-8?q?=E2=80=94=20flood=20fixed,=20run=20install=20not=20yet=20sustai?= =?UTF-8?q?ned)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Live retail cdb tracing + acdream probes root-caused the creature chase "slide" end-to-end, SUPERSEDING the earlier MovementManager-coexistence hypothesis (eb423fb7): Chase run cycle is manufactured client-side from mt-6 MoveToObject: HandleUpdateTarget -> MoveToObject_Internal -> (TurnToHeading node completes via UseTime) -> BeginMoveForward -> _DoMotion(RunForward) sets substate. BeginTurnToHeading (MoveToManager 0x00529b90) bails while CMotionInterp.motions_pending is non-empty (retail-faithful). acdream's pending_motions EXPLODED to ~1.3M entries (live: add=1.37M vs done=5.7K) because the NPC per-tick called rm.Motion.apply_current_movement EVERY FRAME, which for a remote (has a DefaultSink) re-ran ApplyInterpretedMovement and re-dispatched the WHOLE interpreted state (stance 0x8000003C + forward=attack + sidestep/turn stops), each appending a pending_motions node that barely drains. => MotionsPending() permanently true => the chase turn never started => BeginMoveForward/RunForward ~never fired => the creature slid in an idle+attack pose. Retail dispatches per MOTION EVENT (per UM), never per frame — cdb drain trace: retail add_to_queue == MotionDone. FIX: delete the per-frame apply_current_movement call in the grounded remote-NPC dead-reckon path (GameWindow ~9992). The motion is already dispatched per UM by the funnel (MoveToInterpretedState) + by the MoveToManager per node; body velocity is refreshed directly by the existing get_state_velocity line. RESULT (verified live): pending_motions depth 1.3M -> ~1 (add~=done); "stuck in attack animation" GONE (user-confirmed); run cycle now installs (BeginMoveForward 1->10, RunForward held 0->7). PARTIAL: still not fully sustained — BeginTurnToHeading still blocked motionsPending=True 256/272 (94%) because a residual Ready (0x41000003) stop-node backlog keeps the queue from fully emptying between swings (retail hits add==done exactly). acdream gets ~10 run-starts vs retail's ~21, so it now twitches+glides instead of a clean run-then-stop. Residual = the R2/R3 Ready-stop drain (next session; see docs/research/2026-07-04-*-handoff.md). Also includes the env-gated #170 diagnostic probes used to find this (ACDREAM_MVTO_DIAG=1: [mvto]/[npc-tick]/[drain]/[drainq]) — TEMPORARY, strip when #170 closes. No effect on normal runs. Core suite green. Co-Authored-By: Claude Opus 4.8 --- src/AcDream.App/Rendering/GameWindow.cs | 74 ++++++++++--------- .../Physics/Motion/MoveToManager.cs | 28 +++++++ src/AcDream.Core/Physics/MotionInterpreter.cs | 28 +++++++ 3 files changed, 96 insertions(+), 34 deletions(-) diff --git a/src/AcDream.App/Rendering/GameWindow.cs b/src/AcDream.App/Rendering/GameWindow.cs index d46ccf37..198ec19a 100644 --- a/src/AcDream.App/Rendering/GameWindow.cs +++ b/src/AcDream.App/Rendering/GameWindow.cs @@ -9959,6 +9959,9 @@ public sealed class GameWindow : IDisposable | AcDream.Core.Physics.TransientStateFlags.Active; if (!IsPlayerGuid(serverGuid) && rm.HasServerVelocity) { + if (Environment.GetEnvironmentVariable("ACDREAM_MVTO_DIAG") == "1") + Console.WriteLine(System.FormattableString.Invariant( + $"[npc-tick] guid={serverGuid:X8} branch=SERVERVEL (skips UseTime) mtState={rm.MoveTo?.MovementTypeState}")); double velocityAge = nowSec - rm.LastServerPosTime; if (velocityAge > ServerControlledVelocityStaleSeconds) { @@ -9979,42 +9982,45 @@ public sealed class GameWindow : IDisposable else { // R4-V4: the retail MoveToManager drives - // server-directed movement per tick — the P4 - // TargetTracker adapter feeds HandleUpdateTarget - // from the live entity table (full TargetManager - // port is R5; register row), then UseTime runs - // HandleMoveToPosition/HandleTurnToHeading - // (steering + arrival + fail-distance), and - // apply_current_movement recomputes velocity from - // whatever the manager dispatched — the same - // per-tick shape ordinary locomotion uses. + // server-directed movement per tick — UseTime runs + // HandleMoveToPosition/HandleTurnToHeading (steering + // + arrival + fail-distance), dispatching its OWN + // per-node locomotion (turn / RunForward) through the + // sink. That per-node dispatch is the only motion the + // per-tick update should issue for a remote. + if (Environment.GetEnvironmentVariable("ACDREAM_MVTO_DIAG") == "1") + Console.WriteLine(System.FormattableString.Invariant( + $"[npc-tick] guid={serverGuid:X8} branch=MOVETO (UseTime runs) mtState={rm.MoveTo?.MovementTypeState}")); TickRemoteMoveTo(rm); - rm.Motion.apply_current_movement(cancelMoveTo: false, allowJump: false); - // #170 glide fix (2026-07-04): refresh the body's - // translation velocity from the current interpreted - // state, matching retail. apply_current_movement's - // SINK path (all remotes have a DefaultSink) only - // dispatches the ANIMATION — the - // get_state_velocity → set_local_velocity write - // that retail's apply_current_movement performs - // lives ONLY in acdream's no-sink fallback - // (MotionInterpreter.ApplyCurrentMovementInterpreted, - // ~1702), so a remote's body.Velocity is never - // recomputed and goes STALE. get_state_velocity - // (0x00527d50, already a verbatim port) returns - // WalkForward→3.12×spd, RunForward→4.0×spd, and 0 - // for every other forward command — so when a - // chasing creature's ForwardCommand switches to an - // attack (0x1000006x, action-class), the body - // stops instead of coasting at the last run - // velocity while playing an idle+attack pose (the - // user-reported "glides after me"). Grounded only - // (this branch already asserted Contact+OnWalkable); - // airborne velocity is owned by the jump arc. - // Confirmed vs a live ACDREAM_DUMP_MOTION capture of - // Mite Scamp 0x80000244 (66 mt-0 attack UMs carrying - // ForwardCommand=0x62/63/64 vs 2 mt-6 chase UMs). + // #170 ROOT FIX (2026-07-04): the per-frame + // rm.Motion.apply_current_movement(...) call that used + // to be here is DELETED. For a remote (which has a + // DefaultSink) it re-ran ApplyInterpretedMovement EVERY + // FRAME, re-dispatching the whole interpreted state — + // stance (0x8000003C), forward=attack, sidestep/turn + // stops — and each successful DoInterpretedMotion + // appends a CMotionInterp.pending_motions node. Those + // nodes barely drain for a remote, so pending_motions + // EXPLODED to ~1.3M entries (live capture: add=1.37M vs + // done=5.7K; ~671K of them the unchanged stance). + // MotionsPending() then stayed permanently true, so + // MoveToManager.BeginTurnToHeading (0x00529b90, + // `if (motions_pending) return`) could never start the + // chase turn → the chase never reached BeginMoveForward + // → RunForward, so the creature SLID in an idle+attack + // pose instead of running. Retail dispatches per MOTION + // EVENT (per UM), never per frame — a live cdb drain + // trace showed retail add_to_queue == MotionDone (queue + // stays shallow). The motion is already dispatched per + // UM by the funnel (MoveToInterpretedState) and by the + // MoveToManager per node above; the only thing the + // deleted call still provided was body velocity, which + // the get_state_velocity refresh below performs + // directly. get_state_velocity (0x00527d50, verbatim) + // returns WalkForward→3.12×spd, RunForward→4.0×spd, 0 + // otherwise; grounded-only (this branch already asserted + // Contact+OnWalkable), airborne velocity owns the jump. if (rm.Body.OnWalkable) rm.Body.set_local_velocity( rm.Motion.get_state_velocity(), diff --git a/src/AcDream.Core/Physics/Motion/MoveToManager.cs b/src/AcDream.Core/Physics/Motion/MoveToManager.cs index ac943c80..37e3cce8 100644 --- a/src/AcDream.Core/Physics/Motion/MoveToManager.cs +++ b/src/AcDream.Core/Physics/Motion/MoveToManager.cs @@ -738,6 +738,12 @@ public sealed class MoveToManager /// (/ = dist, /// both times = now). /// + // #170 temp diag (ACDREAM_MVTO_DIAG): trace the MoveTo dispatch/re-drive/cancel + // events to compare acdream's run-cycle install cadence against a live retail + // cdb count. Strip once #170 is understood. + private static readonly bool s_mvtoDiag = + System.Environment.GetEnvironmentVariable("ACDREAM_MVTO_DIAG") == "1"; + public void BeginMoveForward() { if (!HasPhysicsObj) @@ -756,6 +762,10 @@ public sealed class MoveToManager Params.GetCommand(dist, heading, out uint cmd, out HoldKey holdKey, out bool movingAway); + if (s_mvtoDiag) + System.Console.WriteLine(System.FormattableString.Invariant( + $"[mvto] BeginMoveForward dist={dist:F2} cmd=0x{cmd:X8} hold={holdKey} movingAway={movingAway}")); + if (cmd == 0) { RemovePendingActionsHead(); @@ -816,6 +826,10 @@ public sealed class MoveToManager return; } + if (s_mvtoDiag) + System.Console.WriteLine(System.FormattableString.Invariant( + $"[mvto] BeginTurnToHeading motionsPending={_interp.MotionsPending()} curCmd=0x{CurrentCommand:X8}")); + if (_interp.MotionsPending()) { return; @@ -952,6 +966,10 @@ public sealed class MoveToManager /// public void UseTime() { + if (s_mvtoDiag && (MovementTypeState != MovementType.Invalid || _pendingActions.First is not null)) + System.Console.WriteLine(System.FormattableString.Invariant( + $"[mvto] UseTime enter contact={_contact()} pending={_pendingActions.Count} mtState={MovementTypeState} init={Initialized} hasPhys={HasPhysicsObj}")); + if (!HasPhysicsObj || !_contact()) return; if (_pendingActions.First is null) return; @@ -960,6 +978,9 @@ public sealed class MoveToManager if (!objectMoveGate) return; MovementType type = _pendingActions.First.Value.Type; + if (s_mvtoDiag) + System.Console.WriteLine(System.FormattableString.Invariant( + $"[mvto] UseTime dispatch node={type} mtState={MovementTypeState}")); if (type == MovementType.MoveToPosition) { HandleMoveToPosition(); @@ -1228,6 +1249,10 @@ public sealed class MoveToManager /// public void HandleUpdateTarget(TargetInfo info) { + if (s_mvtoDiag) + System.Console.WriteLine(System.FormattableString.Invariant( + $"[mvto] HandleUpdateTarget objId=0x{info.ObjectId:X8} myTgt=0x{TopLevelObjectId:X8} match={(TopLevelObjectId == info.ObjectId)} init={Initialized} mtState={MovementTypeState} status={info.Status}")); + if (!HasPhysicsObj) { CancelMoveTo(WeenieError.NoPhysicsObject); @@ -1460,6 +1485,9 @@ public sealed class MoveToManager /// public void CancelMoveTo(WeenieError error) { + if (s_mvtoDiag && MovementTypeState != MovementType.Invalid) + System.Console.WriteLine($"[mvto] CancelMoveTo (real) wasType={MovementTypeState} err={error}"); + _ = error; // retail: never read in the body (decomp §7c) — kept for parity/logging. if (MovementTypeState == MovementType.Invalid) return; diff --git a/src/AcDream.Core/Physics/MotionInterpreter.cs b/src/AcDream.Core/Physics/MotionInterpreter.cs index 8639688c..e30a7dfa 100644 --- a/src/AcDream.Core/Physics/MotionInterpreter.cs +++ b/src/AcDream.Core/Physics/MotionInterpreter.cs @@ -2286,9 +2286,34 @@ public sealed class MotionInterpreter : IMotionDoneSink /// Retail arg2 — MotionNode.context_id. /// Retail arg3 — MotionNode.motion. /// Retail arg4 — MotionNode.jump_error_code. + // #170 temp drain diag (ACDREAM_MVTO_DIAG): aggregate add_to_queue vs + // MotionDone counts + this interp's pending depth — the apples-to-apples of + // the retail cdb drain trace (retail: add==done). Strip after #170. + private static readonly bool s_drainDiag = + System.Environment.GetEnvironmentVariable("ACDREAM_MVTO_DIAG") == "1"; + private static int s_addCount; + private static int s_doneCount; + public void AddToQueue(uint contextId, uint motion, uint jumpErrorCode) { _pendingMotions.AddLast(new MotionNode(contextId, motion, jumpErrorCode)); + if (s_drainDiag) + { + s_addCount++; + // Dump this interp's queue CONTENTS whenever a backlog is present + // (depth >= 2 = something isn't draining) so we can see WHICH motion + // lingers and keeps MotionsPending() true (blocking the chase turn). + if (_pendingMotions.Count >= 2) + { + var sb = new System.Text.StringBuilder(); + foreach (var n in _pendingMotions) { sb.Append("0x"); sb.Append(n.Motion.ToString("X8")); sb.Append(' '); } + System.Console.WriteLine(System.FormattableString.Invariant( + $"[drainq] depth={_pendingMotions.Count} lag={s_addCount - s_doneCount} q=[{sb}]")); + } + else if (s_addCount % 50 == 0) + System.Console.WriteLine(System.FormattableString.Invariant( + $"[drain] add={s_addCount} done={s_doneCount} lag={s_addCount - s_doneCount} depth={_pendingMotions.Count}")); + } } /// @@ -2336,7 +2361,10 @@ public sealed class MotionInterpreter : IMotionDoneSink // the same node since nothing else can mutate the queue mid-call. var head1 = _pendingMotions.First; if (head1 is not null) + { _pendingMotions.RemoveFirst(); + if (s_drainDiag) s_doneCount++; + } } ///