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; | AcDream.Core.Physics.TransientStateFlags.Active;
if (!IsPlayerGuid(serverGuid) && rm.HasServerVelocity) 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; double velocityAge = nowSec - rm.LastServerPosTime;
if (velocityAge > ServerControlledVelocityStaleSeconds) if (velocityAge > ServerControlledVelocityStaleSeconds)
{ {
@ -9979,42 +9982,45 @@ public sealed class GameWindow : IDisposable
else else
{ {
// R4-V4: the retail MoveToManager drives // R4-V4: the retail MoveToManager drives
// server-directed movement per tick — the P4 // server-directed movement per tick — UseTime runs
// TargetTracker adapter feeds HandleUpdateTarget // HandleMoveToPosition/HandleTurnToHeading (steering
// from the live entity table (full TargetManager // + arrival + fail-distance), dispatching its OWN
// port is R5; register row), then UseTime runs // per-node locomotion (turn / RunForward) through the
// HandleMoveToPosition/HandleTurnToHeading // sink. That per-node dispatch is the only motion the
// (steering + arrival + fail-distance), and // per-tick update should issue for a remote.
// apply_current_movement recomputes velocity from if (Environment.GetEnvironmentVariable("ACDREAM_MVTO_DIAG") == "1")
// whatever the manager dispatched — the same Console.WriteLine(System.FormattableString.Invariant(
// per-tick shape ordinary locomotion uses. $"[npc-tick] guid={serverGuid:X8} branch=MOVETO (UseTime runs) mtState={rm.MoveTo?.MovementTypeState}"));
TickRemoteMoveTo(rm); TickRemoteMoveTo(rm);
rm.Motion.apply_current_movement(cancelMoveTo: false, allowJump: false);
// #170 glide fix (2026-07-04): refresh the body's // #170 ROOT FIX (2026-07-04): the per-frame
// translation velocity from the current interpreted // rm.Motion.apply_current_movement(...) call that used
// state, matching retail. apply_current_movement's // to be here is DELETED. For a remote (which has a
// SINK path (all remotes have a DefaultSink) only // DefaultSink) it re-ran ApplyInterpretedMovement EVERY
// dispatches the ANIMATION — the // FRAME, re-dispatching the whole interpreted state —
// get_state_velocity → set_local_velocity write // stance (0x8000003C), forward=attack, sidestep/turn
// that retail's apply_current_movement performs // stops — and each successful DoInterpretedMotion
// lives ONLY in acdream's no-sink fallback // appends a CMotionInterp.pending_motions node. Those
// (MotionInterpreter.ApplyCurrentMovementInterpreted, // nodes barely drain for a remote, so pending_motions
// ~1702), so a remote's body.Velocity is never // EXPLODED to ~1.3M entries (live capture: add=1.37M vs
// recomputed and goes STALE. get_state_velocity // done=5.7K; ~671K of them the unchanged stance).
// (0x00527d50, already a verbatim port) returns // MotionsPending() then stayed permanently true, so
// WalkForward→3.12×spd, RunForward→4.0×spd, and 0 // MoveToManager.BeginTurnToHeading (0x00529b90,
// for every other forward command — so when a // `if (motions_pending) return`) could never start the
// chasing creature's ForwardCommand switches to an // chase turn → the chase never reached BeginMoveForward
// attack (0x1000006x, action-class), the body // → RunForward, so the creature SLID in an idle+attack
// stops instead of coasting at the last run // pose instead of running. Retail dispatches per MOTION
// velocity while playing an idle+attack pose (the // EVENT (per UM), never per frame — a live cdb drain
// user-reported "glides after me"). Grounded only // trace showed retail add_to_queue == MotionDone (queue
// (this branch already asserted Contact+OnWalkable); // stays shallow). The motion is already dispatched per
// airborne velocity is owned by the jump arc. // UM by the funnel (MoveToInterpretedState) and by the
// Confirmed vs a live ACDREAM_DUMP_MOTION capture of // MoveToManager per node above; the only thing the
// Mite Scamp 0x80000244 (66 mt-0 attack UMs carrying // deleted call still provided was body velocity, which
// ForwardCommand=0x62/63/64 vs 2 mt-6 chase UMs). // 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) if (rm.Body.OnWalkable)
rm.Body.set_local_velocity( rm.Body.set_local_velocity(
rm.Motion.get_state_velocity(), rm.Motion.get_state_velocity(),

View file

@ -738,6 +738,12 @@ public sealed class MoveToManager
/// (<see cref="PreviousDistance"/>/<see cref="OriginalDistance"/> = dist, /// (<see cref="PreviousDistance"/>/<see cref="OriginalDistance"/> = dist,
/// both times = now). /// both times = now).
/// </summary> /// </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() public void BeginMoveForward()
{ {
if (!HasPhysicsObj) if (!HasPhysicsObj)
@ -756,6 +762,10 @@ public sealed class MoveToManager
Params.GetCommand(dist, heading, out uint cmd, out HoldKey holdKey, out bool movingAway); 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) if (cmd == 0)
{ {
RemovePendingActionsHead(); RemovePendingActionsHead();
@ -816,6 +826,10 @@ public sealed class MoveToManager
return; return;
} }
if (s_mvtoDiag)
System.Console.WriteLine(System.FormattableString.Invariant(
$"[mvto] BeginTurnToHeading motionsPending={_interp.MotionsPending()} curCmd=0x{CurrentCommand:X8}"));
if (_interp.MotionsPending()) if (_interp.MotionsPending())
{ {
return; return;
@ -952,6 +966,10 @@ public sealed class MoveToManager
/// </summary> /// </summary>
public void UseTime() 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 (!HasPhysicsObj || !_contact()) return;
if (_pendingActions.First is null) return; if (_pendingActions.First is null) return;
@ -960,6 +978,9 @@ public sealed class MoveToManager
if (!objectMoveGate) return; if (!objectMoveGate) return;
MovementType type = _pendingActions.First.Value.Type; 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) if (type == MovementType.MoveToPosition)
{ {
HandleMoveToPosition(); HandleMoveToPosition();
@ -1228,6 +1249,10 @@ public sealed class MoveToManager
/// </summary> /// </summary>
public void HandleUpdateTarget(TargetInfo info) 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) if (!HasPhysicsObj)
{ {
CancelMoveTo(WeenieError.NoPhysicsObject); CancelMoveTo(WeenieError.NoPhysicsObject);
@ -1460,6 +1485,9 @@ public sealed class MoveToManager
/// </summary> /// </summary>
public void CancelMoveTo(WeenieError error) 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. _ = error; // retail: never read in the body (decomp §7c) — kept for parity/logging.
if (MovementTypeState == MovementType.Invalid) return; 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="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="motion">Retail <c>arg3</c> — <c>MotionNode.motion</c>.</param>
/// <param name="jumpErrorCode">Retail <c>arg4</c> — <c>MotionNode.jump_error_code</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) public void AddToQueue(uint contextId, uint motion, uint jumpErrorCode)
{ {
_pendingMotions.AddLast(new MotionNode(contextId, motion, 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> /// <summary>
@ -2336,7 +2361,10 @@ public sealed class MotionInterpreter : IMotionDoneSink
// the same node since nothing else can mutate the queue mid-call. // the same node since nothing else can mutate the queue mid-call.
var head1 = _pendingMotions.First; var head1 = _pendingMotions.First;
if (head1 is not null) if (head1 is not null)
{
_pendingMotions.RemoveFirst(); _pendingMotions.RemoveFirst();
if (s_drainDiag) s_doneCount++;
}
} }
/// <summary> /// <summary>