perf(monitor): probe the cached blob instead of walking every 10 s

src-tauri/Cargo.toml

@@ -28,6 +28,7 @@ tungstenite = { version = "0.26", features = ["native-tls"] }
 native-tls = "0.2"
 whirlpool = "0.10"
 lzma-rs = "0.3"
+memchr = "2"
 
 [profile.dev]
 opt-level = 1

src-tauri/src/lib.rs

@@ -64,6 +64,11 @@ pub struct AppState {
     /// Controls the raw memory string-dump background thread.
     pub raw_scan_active: Arc<AtomicBool>,
     pub raw_scan_path: PathBuf,
+    /// Set by the EE.log tail when Warframe reports finishing an inventory
+    /// refresh; cleared by the monitor loop when it acts on it. A bool rather
+    /// than a count because the game flushes its log in bursts, so several
+    /// markers can land at once and all of them call for the same single walk.
+    pub blob_sync_pending: Arc<AtomicBool>,
     /// When true, save a timestamped inventory blob to blobs/ on each full scan pass.
     pub blob_log_enabled: Arc<AtomicBool>,
     pub blob_log_dir: PathBuf,
@@ -2852,6 +2857,12 @@ fn start_log_watcher(app: tauri::AppHandle) -> Result<(), String> {
         .map(|d| d.join("Warframe").join("EE.log"))
         .ok_or("Cannot find LocalAppData")?;
 
+    // Second source for the inventory-sync marker, and the slower of the two:
+    // the tail only sees a line once Warframe flushes it. With no EE.log at all
+    // the monitor still escalates on its own interval, so a missing tail costs
+    // latency rather than correctness.
+    let blob_sync_pending = app.state::<AppState>().blob_sync_pending.clone();
+
     std::thread::spawn(move || {
         use std::io::{Read, Seek, SeekFrom};
         let mut file_pos: u64 = std::fs::metadata(&log_path).map(|m| m.len()).unwrap_or(0);
@@ -2891,6 +2902,12 @@ fn start_log_watcher(app: tauri::AppHandle) -> Result<(), String> {
             if f.read_to_string(&mut buf).is_err() { continue; }
             file_pos = len;
             if buf.is_empty() { continue; }
+            // Separates "the game fetched inventory" from "some unrelated
+            // allocation moved". The monitor uses it to decide whether a cache
+            // miss is worth a full memory walk.
+            if buf.contains(memory_scanner::INVENTORY_SYNC_MARKER) {
+                blob_sync_pending.store(true, Ordering::SeqCst);
+            }
             let lower = buf.to_lowercase();
 
             // ── Riven reroll / unveil ─────────────────────────────────────────
@@ -4264,14 +4281,6 @@ async fn dump_memory_probe(state: State<'_, AppState>) -> Result<String, String>
     Ok(output)
 }
 
-/// Toggle the continuous raw memory string-dump.
-/// One-shot manual capture of the full inventory JSON blob.
-#[tauri::command]
-fn capture_inventory_blob(state: State<'_, AppState>) -> Result<String, String> {
-    let path = state.raw_scan_path.with_file_name("inventory_blob.txt");
-    memory_scanner::capture_inventory_blob(&path)
-}
-
 /// Enable or disable automatic per-pass inventory blob logging to blobs/.
 #[tauri::command]
 fn set_blob_log(enabled: bool, state: State<'_, AppState>) {
@@ -4395,6 +4404,51 @@ pub struct InventoryUpdate {
     pub player_name: Option<String>,
 }
 
+/// Floor on walk frequency, inherited from the fixed cadence this policy
+/// replaced: whatever the probe reports, walking is never worth doing faster.
+const WALK_MIN_INTERVAL: std::time::Duration = std::time::Duration::from_secs(10);
+/// A client with no blob found yet is usually at the login screen. The marker
+/// ends that wait as soon as the inventory arrives, so this interval only
+/// applies when no marker reaches us at all.
+const WALK_COLD_INTERVAL: std::time::Duration = std::time::Duration::from_secs(60);
+/// Covers the state a probe cannot detect: the game reallocates the blob but
+/// the old address still holds a parseable copy of the old bytes, so every
+/// probe answers "unchanged". That is rare and a walk costs the player frames,
+/// hence the long interval.
+const WALK_MAX_INTERVAL: std::time::Duration = std::time::Duration::from_secs(900);
+/// Nothing changes the inventory without a sync, and a sync is always logged,
+/// so this only covers syncs that both marker sources missed. Kept below
+/// [`WALK_MAX_INTERVAL`] so the walk intervals still get evaluated on their own
+/// schedule.
+const BLOB_PROBE_FALLBACK: std::time::Duration = std::time::Duration::from_secs(60);
+
+/// Whether a full region walk is worth its cost this tick.
+///
+/// A walk reads gigabytes and drops the player's framerate, so most of these
+/// rules exist to skip walks that cannot find anything new.
+///
+/// None of this depends on the marker for correctness. Every case has an
+/// interval that fires without one, so a missing EE.log or an unlocatable log
+/// buffer costs only latency.
+fn walk_is_due(
+    outcome: &memory_scanner::ScanOutcome,
+    sync_seen: bool,
+    has_cached_blob: bool,
+    since_walk: std::time::Duration,
+) -> bool {
+    use memory_scanner::ScanOutcome;
+    match outcome {
+        ScanOutcome::Updated => false,
+        ScanOutcome::CacheMiss if sync_seen => true,
+        ScanOutcome::CacheMiss if has_cached_blob => since_walk >= WALK_MIN_INTERVAL,
+        // A sync that moved nothing looks identical to a stale address still
+        // holding the old bytes, and the probe cannot tell them apart.
+        ScanOutcome::Unchanged if sync_seen => since_walk >= WALK_MIN_INTERVAL,
+        ScanOutcome::CacheMiss => since_walk >= WALK_COLD_INTERVAL,
+        ScanOutcome::Unchanged => since_walk >= WALK_MAX_INTERVAL,
+    }
+}
+
 #[tauri::command]
 async fn start_monitor(app: tauri::AppHandle, state: State<'_, AppState>) -> Result<(), String> {
     if state.monitor_active.swap(true, Ordering::SeqCst) {
@@ -4479,6 +4533,7 @@ async fn start_monitor(app: tauri::AppHandle, state: State<'_, AppState>) -> Res
     let shared_crafting      = state.current_crafting.clone();
     let blob_log_enabled     = state.blob_log_enabled.clone();
     let blob_log_dir         = state.blob_log_dir.clone();
+    let blob_sync_pending    = state.blob_sync_pending.clone();
     let reward_app = app.clone();  // clone before app is moved into the inventory thread
 
     // Channel for the blob capture thread to deliver a parsed BlobInventory to the monitor loop.
@@ -4598,7 +4653,11 @@ async fn start_monitor(app: tauri::AppHandle, state: State<'_, AppState>) -> Res
             .filter(|(_, v)| !v.archon_shards.is_empty())
             .map(|(k, v)| (k.clone(), v.archon_shards.clone()))
             .collect();
-        let mut last_blob_time: Option<std::time::Instant> = None;
+        // last_probe_time paces the probe itself; last_blob_probe is the last
+        // probe that got as far as re-reading the blob, which most do not.
+        let mut last_walk_time: Option<std::time::Instant> = None;
+        let mut last_probe_time: Option<std::time::Instant> = None;
+        let mut last_blob_probe: Option<std::time::Instant> = None;
         // Guard against overlapping captures: a full memory walk can take >10 s on large
         // game processes, so without this flag we'd stack up concurrent scan threads.
         let blob_scan_active = std::sync::Arc::new(std::sync::atomic::AtomicBool::new(false));
@@ -4803,9 +4862,6 @@ async fn start_monitor(app: tauri::AppHandle, state: State<'_, AppState>) -> Res
                 }
             }
 
-            // Periodic blob capture every 10s while game is running.
-            // blob_scan_active prevents overlapping captures — a full memory walk on a
-            // large game process can exceed 10 s, so without the guard we'd stack threads.
             // Re-enumerate processes at most every 5 s (CreateToolhelp32Snapshot overhead).
             let needs_pid_check = last_pid_check
                 .map_or(true, |t: std::time::Instant| t.elapsed().as_secs() >= 5);
@@ -4816,19 +4872,75 @@ async fn start_monitor(app: tauri::AppHandle, state: State<'_, AppState>) -> Res
                     if current_pid.is_some() {
                         eprintln!("[monitor] Warframe PID changed ({:?} → {:?}), clearing blob region cache", last_pid, current_pid);
                         memory_scanner::reset_last_blob_region();
+                        memory_scanner::reset_log_region();
                     }
                     last_pid = current_pid;
                 }
                 last_pid_check = Some(std::time::Instant::now());
             }
             let game_running = cached_game_running;
             if game_running {
-                let should_capture = last_blob_time
-                    .map_or(true, |t: std::time::Instant| t.elapsed() >= std::time::Duration::from_secs(10));
-                let already_running = blob_scan_active.load(Ordering::SeqCst);
-                if should_capture && !already_running {
+                // ── Blob capture: cheap probe, rate-limited walk ──────────────
+                // The marker is read at this cadence; re-reading the blob is
+                // gated separately, on BLOB_PROBE_FALLBACK below.
+                const PROBE_INTERVAL: std::time::Duration = std::time::Duration::from_secs(2);
+
+                let walk_in_flight = blob_scan_active.load(Ordering::SeqCst);
+                let probe_due = last_probe_time
+                    .map_or(true, |t: std::time::Instant| t.elapsed() >= PROBE_INTERVAL);
+
+                // Probes run inline, so one must never start behind a walk that
+                // is already reading the same process.
+                let mut should_capture = false;
+                if probe_due && !walk_in_flight {
+                    last_probe_time = Some(std::time::Instant::now());
+                    let stitch_due = last_blob_probe
+                        .map_or(true, |t: std::time::Instant| t.elapsed() >= BLOB_PROBE_FALLBACK)
+                        || blob_sync_pending.load(Ordering::SeqCst)
+                        || !memory_scanner::has_cached_blob();
+                    let (outcome, sync_marker) = match last_pid {
+                        Some(pid) => memory_scanner::probe_tick(pid, blob_tx.clone(), stitch_due),
+                        None => (None, false),
+                    };
+                    if outcome.is_some() {
+                        last_blob_probe = Some(std::time::Instant::now());
+                    }
+                    // The memory probe reports each marker exactly once, so it
+                    // has to be folded into the held flag rather than read
+                    // beside it. Otherwise a marker arriving on a tick that
+                    // cannot act on it is lost.
+                    if sync_marker {
+                        blob_sync_pending.store(true, Ordering::SeqCst);
+                    }
+                    let sync_seen = blob_sync_pending.load(Ordering::SeqCst);
+                    let blob_known = memory_scanner::has_cached_blob();
+                    let since_walk = last_walk_time
+                        .map_or(std::time::Duration::MAX, |t: std::time::Instant| t.elapsed());
+                    // A tick that did not re-read the blob has no fresh evidence
+                    // to escalate on, and the marker that would justify a walk
+                    // is exactly what makes the probe run in the first place.
+                    should_capture = outcome
+                        .as_ref()
+                        .is_some_and(|outcome| walk_is_due(outcome, sync_seen, blob_known, since_walk));
+                    // A marker dropped while the rate limit says "not yet" is
+                    // never revisited, so it is only cleared once something has
+                    // acted on it.
+                    if should_capture || outcome == Some(memory_scanner::ScanOutcome::Updated) {
+                        blob_sync_pending.store(false, Ordering::SeqCst);
+                    }
+                    if should_capture {
+                        let since = match last_walk_time {
+                            Some(t) => format!("{:.1}s", t.elapsed().as_secs_f64()),
+                            None => "never".into(),
+                        };
+                        eprintln!("[monitor] escalating to full walk (outcome={:?} sync_marker={} blob_known={} since_last_walk={})",
+                            outcome, sync_seen, blob_known, since);
+                    }
+                }
+
+                if should_capture {
                     blob_scan_active.store(true, Ordering::SeqCst);
-                    last_blob_time = Some(std::time::Instant::now());
+                    last_walk_time = Some(std::time::Instant::now());
                     let ts     = chrono::Utc::now().format("%Y-%m-%dT%H-%M-%S").to_string();
                     let dir    = blob_log_dir.clone();
                     let tx     = blob_tx.clone();
@@ -8405,6 +8517,7 @@ pub fn run() {
             monitor_active: Arc::new(AtomicBool::new(false)),
             raw_scan_active: Arc::new(AtomicBool::new(false)),
             raw_scan_path,
+            blob_sync_pending: Arc::new(AtomicBool::new(false)),
             blob_log_enabled: Arc::new(AtomicBool::new(false)),
             blob_log_dir,
             api_log_enabled: Arc::new(AtomicBool::new(false)),
@@ -8535,7 +8648,6 @@ pub fn run() {
             log_api_changes,
             dump_memory_probe,
             toggle_raw_scan,
-            capture_inventory_blob,
             set_blob_log,
             set_api_log,
             get_app_version,
@@ -8837,3 +8949,70 @@ MR 11
         );
     }
 }
+
+#[cfg(test)]
+mod walk_policy_tests {
+    use super::{walk_is_due, WALK_COLD_INTERVAL, WALK_MAX_INTERVAL, WALK_MIN_INTERVAL};
+    use crate::memory_scanner::ScanOutcome;
+    use std::time::Duration;
+
+    /// At the login screen no blob has ever been found, and re-checking that
+    /// every WALK_MIN_INTERVAL reads gigabytes and costs the player frames for
+    /// seconds at a time.
+    #[test]
+    fn a_client_with_no_blob_yet_waits_for_the_backstop() {
+        let just_walked = WALK_MIN_INTERVAL + Duration::from_secs(1);
+        assert!(!walk_is_due(&ScanOutcome::CacheMiss, false, false, just_walked));
+        assert!(walk_is_due(&ScanOutcome::CacheMiss, false, false, WALK_COLD_INTERVAL));
+    }
+
+    /// A settled inventory answers "unchanged" every couple of seconds for as
+    /// long as the player stays docked, so walking gigabytes each minute to
+    /// check it again is wasted work.
+    #[test]
+    fn a_settled_inventory_does_not_walk_on_the_minute() {
+        assert!(!walk_is_due(&ScanOutcome::Unchanged, false, true, Duration::from_secs(60)));
+        assert!(!walk_is_due(&ScanOutcome::Unchanged, false, true, Duration::from_secs(300)));
+        assert!(walk_is_due(&ScanOutcome::Unchanged, false, true, WALK_MAX_INTERVAL));
+    }
+
+    /// The client announced a fetch and our copy did not move. Usually a sync
+    /// with no delta, but it is also what a stale address holding the old bytes
+    /// looks like, which the probe cannot distinguish.
+    #[test]
+    fn an_unchanged_probe_with_a_marker_still_walks() {
+        assert!(walk_is_due(&ScanOutcome::Unchanged, true, true, WALK_MIN_INTERVAL));
+        assert!(!walk_is_due(&ScanOutcome::Unchanged, true, true, Duration::from_secs(3)));
+    }
+
+    /// The probe already delivered the new inventory, so a walk would read
+    /// gigabytes to produce what the monitor already has.
+    #[test]
+    fn a_fresh_parse_never_escalates() {
+        assert!(!walk_is_due(&ScanOutcome::Updated, true, true, Duration::MAX));
+    }
+
+    /// Once a blob is known, a miss plausibly means the game reallocated it
+    /// because the inventory changed, which is worth checking at the old
+    /// cadence.
+    #[test]
+    fn a_miss_on_a_known_blob_keeps_the_old_cadence() {
+        assert!(walk_is_due(&ScanOutcome::CacheMiss, false, true, WALK_MIN_INTERVAL));
+        assert!(!walk_is_due(&ScanOutcome::CacheMiss, false, true, Duration::from_secs(4)));
+    }
+
+    /// The marker resolves the ambiguity, including at the login screen where
+    /// the first sync arrives.
+    #[test]
+    fn a_sync_marker_escalates_immediately() {
+        assert!(walk_is_due(&ScanOutcome::CacheMiss, true, false, Duration::ZERO));
+        assert!(walk_is_due(&ScanOutcome::CacheMiss, true, true, Duration::ZERO));
+    }
+
+    /// The first tick after the game appears has no previous walk to rate-limit
+    /// against, so the app still gets one immediately at startup.
+    #[test]
+    fn the_first_walk_is_never_delayed() {
+        assert!(walk_is_due(&ScanOutcome::CacheMiss, false, false, Duration::MAX));
+    }
+}