fix(#170): stop per-frame interpreted re-dispatch flooding pending_motions (partial — flood fixed, run install not yet sustained)

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 <noreply@anthropic.com>
This commit is contained in:
Erik 2026-07-04 20:29:10 +02:00
parent d2ccc80e59
commit 427332acaa
3 changed files with 96 additions and 34 deletions

View file

@ -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(),

View file

@ -738,6 +738,12 @@ public sealed class MoveToManager
/// (<see cref="PreviousDistance"/>/<see cref="OriginalDistance"/> = dist,
/// both times = now).
/// </summary>
// #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
/// </summary>
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
/// </summary>
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
/// </summary>
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;

View file

@ -2286,9 +2286,34 @@ public sealed class MotionInterpreter : IMotionDoneSink
/// <param name="contextId">Retail <c>arg2</c> — <c>MotionNode.context_id</c>.</param>
/// <param name="motion">Retail <c>arg3</c> — <c>MotionNode.motion</c>.</param>
/// <param name="jumpErrorCode">Retail <c>arg4</c> — <c>MotionNode.jump_error_code</c>.</param>
// #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}"));
}
}
/// <summary>
@ -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++;
}
}
/// <summary>