grom/benilla-octo
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

app: say in the log when the world map stops following the player

Browse Source 
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 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01SgstFWtn1RxEJ5kVrpgYwn
This commit is contained in:
grom
2026-10-22 17:20:28 -06:00
co-authored by Claude Opus 5
parent e282410938
commit 9e13856cfd
2 changed files with 291 additions and 23 deletions
Download Patch File Download Diff File Expand all files Collapse all files
crates/benilla-app/src/ui_world_map.rs
+276 -23
View File
@@ -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<u32>)>,
/// 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<SelectionLag>,
}
/// 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<Self>,
moved: bool,
follows: bool,
now: f32,
asks: u32,
) -> (Option<Self>, Option<LagReport>) {
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<LagReport> {
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<u32>,
) -> 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<crate::net::NetEntity>>,
pois: Option<Res<crate::area_poi::AreaPoiRes>>,
world_states: Res<crate::world_state::WorldStates>,
time: Res<Time>,
mut memo: Local<crate::ui_script::VmMemo<FeedMemos>>,
) {
let (Some(mut script), Some(data), Some(map), Some(areas)) = (script, data, map, areas) else {
@@ -718,41 +929,28 @@ fn feed_world_map(
// *resolved* pair, so a selection sitting a zone behind — which is what leaves every
// map-derived overlay stale, `GetPlayerMapPosition` included, since that projects onto the
// **displayed** map — looked from the log exactly like a selection that had followed.
let leaf = world.area().unwrap_or(0);
let (ci, zi) = player_sel.zone.unwrap_or((0, 0));
{
let leaf = world.area().unwrap_or(0);
let (ci, zi) = player_sel.zone.unwrap_or((0, 0));
let (sc, sz, sdirect) = script.world_map_selection();
let key = (map.0, leaf, top_zone.unwrap_or(0), ci, zi, sc, sz);
let memo = memo.get(&script);
if memo.zone_logged != Some(key) {
memo.zone_logged = Some(key);
let name = |id: u32| areas.0.name(id).unwrap_or("?").to_string();
// What a `(continent, zone)` pair names, for either of the two pairs.
let label = |c: u32, z: u32, direct: Option<u32>| {
data.continents
.get(c.wrapping_sub(1) as usize)
.and_then(|cont| {
if z == 0 {
// The continent sheet itself, named by its map.
Some(format!("the continent map of map {}", cont.map_id))
} else {
cont.zones
.get(z.wrapping_sub(1) as usize)
.map(|zone| name(zone.area_id))
}
})
.or_else(|| direct.map(|id| format!("instance map row {id}")))
.unwrap_or_else(|| "the world view".to_string())
};
let resolved = label(ci, zi, player_sel.direct);
let selected = label(sc, sz, sdirect);
let resolved = map_label(&data, &areas.0, ci, zi, player_sel.direct);
let selected = map_label(&data, &areas.0, sc, sz, sdirect);
// Not a verdict. The two pairs disagree for a frame or two every time the player
// crosses a border, because this feed publishes the new zone and the `ZONE_CHANGED*`
// an addon answers by reselecting fires after it (`crate::area`). Whether a
// disagreement lasted long enough to be the defect is the watchdog's line, below.
let follows = if (ci, zi, player_sel.direct) == (sc, sz, sdirect) {
""
} else {
" ← STALE: the map is not on the player's zone"
" \u{2190} the map is not on the player's zone"
};
info!(
"zone: map {} · chunk area {leaf} \"{}\" · zone {} \"{}\" · resolves to \"{resolved}\" (continent {ci}, zone {zi}) · map shows \"{selected}\" (continent {sc}, zone {sz}){follows}",
"zone: map {} \u{b7} chunk area {leaf} \"{}\" \u{b7} zone {} \"{}\" \u{b7} resolves to \"{resolved}\" (continent {ci}, zone {zi}) \u{b7} map shows \"{selected}\" (continent {sc}, zone {sz}){follows}",
map.0,
name(leaf),
top_zone.unwrap_or(0),
@@ -774,6 +972,61 @@ fn feed_world_map(
}
let selection = script.world_map_selection();
// Does the selection *follow* the player? Every map-derived overlay rests on that one fact:
// `GetPlayerMapPosition` projects onto the **displayed** map, so a selection left on the zone
// behind seats pfQuest's minimap pins against the wrong rect — and plausibly rather than
// obviously wrong wherever the two rects overlap, as Ironforge's does inside Dun Morogh's.
//
// The zone line above cannot answer it, which is why this is separate: a disagreement is
// normal between this feed publishing the new zone and the addon answering `ZONE_CHANGED*`
// by reselecting. Only one that outlives the grace is the defect — and then it does not clear
// by itself, because nothing reselects until something calls the verb again (the world map's
// own `OnShow`, say). One WARN per episode, so an ordinary session answers it with no flag.
{
let now = time.elapsed_secs();
let resolved = (ci, zi, player_sel.direct);
let asks = script.world_map_resolver_calls();
let memo = memo.get(&script);
// An episode starts only where the *player* moved to a zone the map is not on. A
// selection that wanders while the player stands still is the map being browsed, which is
// what the map is for: pfQuest reselects on close (`pfQuest/map.lua:1589`), and warning
// about it would bury the one case worth reading.
let moved = memo.last_resolved != Some(resolved);
memo.last_resolved = Some(resolved);
let (next, report) =
SelectionLag::step(memo.selection_lag, moved, resolved == selection, now, asks);
memo.selection_lag = next;
let here = || map_label(&data, &areas.0, ci, zi, player_sel.direct);
match report {
Some(LagReport::Stuck { age, asks }) => {
// The two halves have the same symptom and different fixes, so the line names
// which one this is rather than leaving it to be guessed from a later session.
let why = if asks == 0 {
"nothing has called `SetMapToCurrentZone()` since the player crossed, so the \
`ZONE_CHANGED*` an addon answers with it never reached one (pfQuest answers \
all three while the map is closed, `pfQuest/map.lua:1466`)"
.to_string()
} else {
format!(
"`SetMapToCurrentZone()` has been called {asks}\u{d7} since and the map \
still is not on the player's zone, so the verb read a zone this feed had \
not published yet"
)
};
warn!(
"zone: the world map is still on \"{}\" {age:.1} s after the player entered \"{}\" \u{2014} {why}. Every map-derived overlay is a zone behind until something reselects, `GetPlayerMapPosition` included, which is what seats pfQuest's minimap pins.",
map_label(&data, &areas.0, selection.0, selection.1, selection.2),
here(),
);
}
Some(LagReport::Followed(age)) => info!(
"zone: the world map followed the player to \"{}\" after {age:.1} s",
here()
),
None => {}
}
}
let project =
|pos_map: u32, px: f32, py: f32| project_on_displayed(&data, selection, pos_map, px, py);
let uv = project(map.0, wx, wy);
crates/benilla-ui/src/script/worldmap.rs
+15
View File
@@ -174,6 +174,12 @@ pub struct WorldMapState {
pub direct_area: Option<u32>,
/// The player's `(continent, zone)`, where `SetMapToCurrentZone` lands.
pub player_zone: Option<(u32, u32)>,
/// How many times Lua has called `SetMapToCurrentZone` this session. Nothing in the window
/// reads it; it exists so the app can tell *why* a selection is not on the player's zone —
/// whether the UI never asked to follow (the event never reached the addon) or asked and
/// landed wrong anyway (the verb read a player zone the feed had not published yet). The two
/// have the same symptom and different fixes, and only the engine can see both halves.
pub resolver_calls: u32,
/// The resolver's orphan leg, the `WorldMapArea` row id on the player's map. `0x4a6650`
/// reaches it only when its continent loop misses (`0x4a66c3`), so at most one is set.
pub player_direct_area: Option<u32>,
@@ -454,6 +460,12 @@ impl super::UiScript {
model.worldmap.raid_uv = raid_uv;
}
/// How many times Lua has called `SetMapToCurrentZone`, for the reason
/// [`WorldMapState::resolver_calls`] gives.
pub fn world_map_resolver_calls(&self) -> u32 {
self.model_ref().worldmap.resolver_calls
}
/// The selection's three cells, which the app reads each frame to project the feed: continent,
/// zone, and the direct-area id that overrides them when `Some`. The pair alone reads an
/// instance map as the world sheet.
@@ -633,6 +645,9 @@ pub(super) fn install(lua: &Lua) -> mlua::Result<()> {
let mut model = lua.app_data_mut::<Model>().expect("model app_data");
let (c, z) = model.worldmap.player_zone.unwrap_or((0, 0));
let direct = model.worldmap.player_direct_area;
// Counted here and not in `select_resolved`, which the engine's own world-enter
// sync also reaches: the number is "times the UI asked to follow the player".
model.worldmap.resolver_calls = model.worldmap.resolver_calls.saturating_add(1);
select_resolved(&mut model, c, z, direct);
}
signal_world_map_update(lua);