From 9e13856cfd9f7b7e1fb55e787b9e89e5bdc3f013 Mon Sep 17 00:00:00 2001 From: grom Date: Thu, 22 Oct 2026 17:20:28 -0600 Subject: [PATCH] app: say in the log when the world map stops following the player MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The stale-minimap report needs one fact: did the selection follow the player into the new zone? Everything map-derived rests on it, because `GetPlayerMapPosition` projects onto the **displayed** map — a selection left a zone behind seats pfQuest's minimap pins against the wrong rect, and plausibly rather than obviously wrong wherever two rects overlap, as Ironforge's does inside Dun Morogh's. The `zone:` line could not answer it even after it started printing both pairs, because the pairs disagree constantly and mostly correctly: for a frame or two after every crossing, since this feed publishes the new zone and the `ZONE_CHANGED*` an addon answers by reselecting fires after it; and for as long as the map is open on another zone, which is what browsing is. A marker on that line would have cried wolf on both. So the rule is its own thing, `SelectionLag::step`: an episode starts only on a frame where the *player* moved to a zone the map is not on, and only an episode outliving a 1 s grace is reported — once, at WARN, with the catch-up line when something finally reselects. A selection that wanders under a standing player is never an episode. Five tests, including the 600-frame browse that must stay silent. The line also forks the cause, which is the part that saves a round trip: `UiScript::world_map_resolver_calls` counts Lua's `SetMapToCurrentZone` calls, so the report can say whether the UI never asked to follow — the event did not reach the addon — or asked and still landed wrong, which is the verb reading a zone the feed had not published. Same symptom, different fixes. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01SgstFWtn1RxEJ5kVrpgYwn --- crates/benilla-app/src/ui_world_map.rs | 299 +++++++++++++++++++++-- crates/benilla-ui/src/script/worldmap.rs | 15 ++ 2 files changed, 291 insertions(+), 23 deletions(-) diff --git a/crates/benilla-app/src/ui_world_map.rs b/crates/benilla-app/src/ui_world_map.rs index 31451c57..c09a9f53 100644 --- a/crates/benilla-app/src/ui_world_map.rs +++ b/crates/benilla-app/src/ui_world_map.rs @@ -625,6 +625,216 @@ struct FeedMemos { /// line prints on change rather than every frame — the selection is in the key because a /// selection that stops following the player is the thing the line exists to show. zone_logged: Option<(u32, u32, u32, u32, u32, u32, u32)>, + /// The resolved pair last seen, so the watchdog in [`feed_world_map`] can tell the player + /// moving to a new zone from the map being browsed away from the player's. + last_resolved: Option<(u32, u32, Option)>, + /// An episode of the selection not following the player, and when it started. `None` whenever + /// the map is on the player's zone, and whenever it is merely being browsed off it. + selection_lag: Option, +} + +/// One episode of the world-map selection failing to follow the player into a new zone. +#[derive(Clone, Debug, PartialEq, Copy)] +struct SelectionLag { + since: f32, + warned: bool, + /// `SetMapToCurrentZone` calls counted when the episode began, so the report can say whether + /// the UI even asked to follow. See [`benilla_ui::script::UiScript::world_map_resolver_calls`]. + asked: u32, +} + +/// What one frame of the watchdog has to say. `None` from [`SelectionLag::step`] is the quiet +/// case, which is nearly every frame. +#[derive(Debug, PartialEq, Clone, Copy)] +enum LagReport { + /// The map is still not on the player's zone this long after the player entered it, and the + /// grace has passed. Printed once per episode. `asks` is how many times Lua called + /// `SetMapToCurrentZone` in that window, which forks the cause: none means the event the + /// addon answers never reached it, and some means the verb is landing on a zone the feed had + /// not published yet. + Stuck { age: f32, asks: u32 }, + /// The map caught up this long after the change, having already been reported stuck. + Followed(f32), +} + +impl SelectionLag { + /// One frame of the watchdog: `moved` is "the player's resolved zone changed this frame", + /// `follows` is "the map is on that zone", `asks` is the running count of Lua's + /// `SetMapToCurrentZone` calls. Returns the episode to carry into the next frame and the line + /// to print, so the rule can be read and tested without the feed's two dozen arguments + /// around it. + /// + /// The rule is narrower than "the pairs disagree", which is a thing that happens constantly + /// and mostly correctly: + /// - For a frame or two after every border crossing, because this feed publishes the new zone + /// and the `ZONE_CHANGED*` an addon answers by reselecting fires after it (`crate::area`). + /// The grace covers that. + /// - For as long as the world map is open on another zone, which is what browsing *is*. An + /// episode therefore only ever starts on a frame where the player moved; a selection that + /// wanders under a standing player is never one. + fn step( + prev: Option, + moved: bool, + follows: bool, + now: f32, + asks: u32, + ) -> (Option, Option) { + if follows { + let report = prev + .filter(|lag| lag.warned) + .map(|lag| LagReport::Followed(now - lag.since)); + return (None, report); + } + if moved { + return ( + Some(Self { + since: now, + warned: false, + asked: asks, + }), + None, + ); + } + match prev { + Some(lag) if !lag.warned && now - lag.since > SELECTION_LAG_GRACE => ( + Some(Self { + warned: true, + ..lag + }), + Some(LagReport::Stuck { + age: now - lag.since, + asks: asks.saturating_sub(lag.asked), + }), + ), + // Either no episode is running (the map is simply being browsed) or this one has had + // its one line. + other => (other, None), + } + } +} + +#[cfg(test)] +mod selection_lag_tests { + use super::{LagReport, SelectionLag}; + + /// Walk the watchdog over a `(moved, follows, now, asks)` frame sequence, collecting what it + /// said. + fn run(frames: &[(bool, bool, f32, u32)]) -> Vec { + let mut state = None; + let mut said = Vec::new(); + for &(moved, follows, now, asks) in frames { + let (next, report) = SelectionLag::step(state, moved, follows, now, asks); + state = next; + said.extend(report); + } + said + } + + /// The ordinary crossing: the feed publishes the new zone, the addon reselects a frame later. + /// Nobody needs to hear about it. + #[test] + fn a_reselect_inside_the_grace_says_nothing() { + assert_eq!( + run(&[ + (true, false, 10.0, 7), + (false, false, 10.02, 7), + (false, true, 10.04, 8), + ]), + Vec::new() + ); + } + + /// The defect, in the shape where the event never reached the addon: the player is in a new + /// zone, nothing ever calls the verb. One line, not one per frame, and then the catch-up when + /// something finally does reselect (opening the map). + #[test] + fn a_selection_that_is_never_asked_to_follow_reports_no_asks() { + let said = run(&[ + (true, false, 10.0, 7), + (false, false, 10.5, 7), + (false, false, 11.5, 7), + (false, false, 12.5, 7), + (false, false, 30.0, 7), + (false, true, 40.0, 8), + ]); + assert_eq!( + said, + vec![ + LagReport::Stuck { age: 1.5, asks: 0 }, + LagReport::Followed(30.0) + ], + "one stuck line at the first frame past the grace, then the catch-up" + ); + } + + /// The same defect in the other shape, which has a different fix: the verb *was* called and + /// the map still is not on the player's zone, so what it read was stale. + #[test] + fn a_verb_that_was_called_and_landed_wrong_reports_its_asks() { + assert_eq!( + run(&[ + (true, false, 10.0, 7), + (false, false, 10.1, 8), + (false, false, 11.5, 9), + ]), + vec![LagReport::Stuck { age: 1.5, asks: 2 }], + "two asks since the crossing, and the map still is not on the zone" + ); + } + + /// Browsing the open world map holds the selection off the player's zone for minutes at a + /// time, by design. It must never produce a line, or the one line that matters is unreadable. + #[test] + fn browsing_the_map_under_a_standing_player_is_never_an_episode() { + let frames: Vec<_> = (0..600) + .map(|i| (false, false, 10.0 + i as f32 * 0.5, 7)) + .collect(); + assert_eq!(run(&frames), Vec::new()); + } + + /// Crossing a second border while the first episode is still open restarts the clock: the age + /// in the line has to be the age of *this* zone's wait, not of a stale one. + #[test] + fn a_second_crossing_restarts_the_clock() { + assert_eq!( + run(&[ + (true, false, 10.0, 7), + (false, false, 10.9, 7), + (true, false, 11.0, 7), + (false, false, 11.5, 7), + (false, false, 12.5, 7), + ]), + vec![LagReport::Stuck { age: 1.5, asks: 0 }], + "measured from the second crossing, not the first" + ); + } +} + +const SELECTION_LAG_GRACE: f32 = 1.0; + +/// What a world-map `(continent, zone)` pair names, for a log line: the continent sheet itself at +/// zone 0, the selected zone's area name below that, an instance-map row when the pair is empty +/// but a direct area is selected (the battlegrounds), else the world view. +fn map_label( + data: &WorldMapUiData, + areas: &benilla_formats::AreaTableCatalog, + c: u32, + z: u32, + direct: Option, +) -> String { + data.continents + .get(c.wrapping_sub(1) as usize) + .and_then(|cont| { + if z == 0 { + Some(format!("the continent map of map {}", cont.map_id)) + } else { + cont.zones + .get(z.wrapping_sub(1) as usize) + .map(|zone| areas.name(zone.area_id).unwrap_or("?").to_string()) + } + }) + .or_else(|| direct.map(|id| format!("instance map row {id}"))) + .unwrap_or_else(|| "the world view".to_string()) } /// The `AreaPOI.dbc` half of the landmark list (`0x4a6819`'s walk), in file order: every row the @@ -677,6 +887,7 @@ fn feed_world_map( unit_pos: Query<&GlobalTransform, With>, pois: Option>, world_states: Res, + time: Res