fix(credentials): recover from leaked auth-profile lock on Windows (Sentry OPENHUMAN-TAURI-H1) (#2085)

Co-authored-by: Steven Enamakel <enamakel@tinyhumans.ai>

src/openhuman/app_state/ops.rs

@@ -14,11 +14,13 @@ use serde_json::Value;
 use tempfile::NamedTempFile;
 
 use crate::api::config::effective_backend_api_url;
-use crate::api::jwt::{bearer_authorization_value, get_session_token};
+use crate::api::jwt::bearer_authorization_value;
 use crate::openhuman::autocomplete::AutocompleteStatus;
 use crate::openhuman::config::rpc as config_rpc;
 use crate::openhuman::config::Config;
-use crate::openhuman::credentials::session_support::build_session_state;
+use crate::openhuman::credentials::session_support::{
+    load_app_session_profile, session_state_from_profile, session_token_from_profile,
+};
 use crate::openhuman::inference::LocalAiStatus;
 use crate::openhuman::screen_intelligence::AccessibilityStatus;
 use crate::openhuman::service::{ServiceState, ServiceStatus};
@@ -446,8 +448,16 @@ async fn build_runtime_snapshot(config: &Config) -> RuntimeSnapshot {
 
 pub async fn snapshot() -> Result<RpcOutcome<AppStateSnapshot>, String> {
     let config = config_rpc::load_config_with_timeout().await?;
-    let mut auth = build_session_state(&config)?;
-    let session_token = get_session_token(&config)?;
+    // Load the `app-session` auth profile exactly once and derive both
+    // the session-state view and the raw token from it. The previous
+    // implementation called `build_session_state` + `get_session_token`
+    // separately, which acquired the auth-profile file lock twice per
+    // snapshot. On Windows this doubled the surface area for the
+    // "Timed out waiting for auth profile lock" failure reported in
+    // Sentry against `openhuman.app_state_snapshot`.
+    let session_profile = load_app_session_profile(&config)?;
+    let mut auth = session_state_from_profile(session_profile.as_ref());
+    let session_token = session_token_from_profile(session_profile.as_ref());
     let stored_user = sanitize_snapshot_user(auth.user.clone());
     let current_user = if let Some(token) = session_token.clone().filter(|t| !t.trim().is_empty()) {
         match fetch_current_user_cached(&config, &token).await {

src/openhuman/credentials/profiles.rs

@@ -7,13 +7,22 @@ use std::fs::{self, OpenOptions};
 use std::io::Write;
 use std::path::{Path, PathBuf};
 use std::thread;
-use std::time::Duration;
+use std::time::{Duration, Instant};
 
 const CURRENT_SCHEMA_VERSION: u32 = 1;
 const PROFILES_FILENAME: &str = "auth-profiles.json";
 const LOCK_FILENAME: &str = "auth-profiles.lock";
 const LOCK_WAIT_MS: u64 = 50;
 const LOCK_TIMEOUT_MS: u64 = 10_000;
+/// A lock file that has existed for longer than this is treated as leaked
+/// (its owner crashed without unlinking it, or `fs::remove_file` in the
+/// guard's `Drop` was rejected by Windows AV/indexer and the file got
+/// orphaned with the still-alive owner's pid in it). No legitimate
+/// auth-profile operation holds the lock for anywhere near this long —
+/// load+save is a tiny JSON read followed by an atomic rename. The
+/// threshold is intentionally well above any realistic operation time
+/// so we never reclaim under a slow-but-legitimate holder.
+const STALE_LOCK_AGE_MS: u64 = 30_000;
 
 #[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
 #[serde(rename_all = "kebab-case")]
@@ -529,8 +538,21 @@ impl AuthProfilesStore {
                 .with_context(|| "Failed to create auth profile lock directory".to_string())?;
         }
 
-        let mut waited = 0_u64;
+        // Drive timeout + stale-recheck off wall-clock elapsed time, not the
+        // sum of explicit `thread::sleep(LOCK_WAIT_MS)` calls. The earlier
+        // counter-based approach excluded time spent inside
+        // `retry_with_backoff` (which can sleep up to ~30s on its own
+        // schedule before returning AlreadyExists) and the lock-file I/O
+        // syscalls. Under Windows AV contention that drift could push
+        // both `LOCK_TIMEOUT_MS` and `next_stale_recheck_ms` significantly
+        // later than intended.
+        let started_at = Instant::now();
         let mut cleared_stale = false;
+        // Periodically re-probe for stale locks during the busy-wait. A
+        // lock that started fresh (live pid, recent mtime) can age past
+        // STALE_LOCK_AGE_MS while we wait, and we want to recover from
+        // that without bailing at the LOCK_TIMEOUT_MS boundary.
+        let mut next_stale_recheck_ms: u64 = 1_000;
         loop {
             let open_result = crate::openhuman::util::retry_with_backoff(
                 "create auth profile lock",
@@ -586,12 +608,25 @@ impl AuthProfilesStore {
                             if self.clear_lock_if_stale() {
                                 continue;
                             }
+                        } else {
+                            let elapsed_ms = started_at.elapsed().as_millis() as u64;
+                            if elapsed_ms >= next_stale_recheck_ms {
+                                // The age-based reclaim check is cheap (one
+                                // `fs::metadata` call in the common case) and
+                                // safely no-ops on fresh, legitimate locks.
+                                // Re-probing periodically lets us recover from
+                                // a leaked-mid-wait lock without bailing at
+                                // the 10s timeout.
+                                next_stale_recheck_ms = next_stale_recheck_ms.saturating_add(1_000);
+                                if self.clear_lock_if_stale() {
+                                    continue;
+                                }
+                            }
                         }
-                        if waited >= LOCK_TIMEOUT_MS {
+                        if started_at.elapsed().as_millis() as u64 >= LOCK_TIMEOUT_MS {
                             anyhow::bail!("Timed out waiting for auth profile lock");
                         }
                         thread::sleep(Duration::from_millis(LOCK_WAIT_MS));
-                        waited = waited.saturating_add(LOCK_WAIT_MS);
                     } else {
                         // Sentry OPENHUMAN-TAURI-H8 collapses every
                         // non-AlreadyExists, non-transient `create_new`
@@ -609,12 +644,46 @@ impl AuthProfilesStore {
         }
     }
 
-    /// Returns `true` if an existing lock file was detected as stale (its
-    /// recorded PID is no longer running) and successfully removed.
-    /// Malformed locks (no `pid=` line) and locks whose PID is still alive
-    /// are left in place so the caller falls back to the normal busy-wait
-    /// and timeout path.
+    /// Returns `true` if an existing lock file was detected as stale and
+    /// successfully removed. Two cases reclaim:
+    ///
+    /// 1. The recorded `pid=` line points at a process that is no longer
+    ///    running — classic crashed-owner recovery (Issue #1612).
+    /// 2. The lock file's mtime is older than [`STALE_LOCK_AGE_MS`]. This
+    ///    catches the Windows case where the previous owner's
+    ///    `AuthProfileLockGuard::drop` could not unlink the file (AV /
+    ///    indexer briefly held a handle) and orphaned the lock with its
+    ///    still-alive pid inside — every subsequent acquirer would
+    ///    otherwise spin the full 10s `LOCK_TIMEOUT_MS` and bail. No
+    ///    legitimate auth-profile op holds the lock long enough to be
+    ///    affected, so a too-old lock is unambiguously a leak.
+    ///
+    /// Malformed locks (no `pid=` line) are reclaimed only when they are
+    /// also too old, since a fresh malformed lock might still indicate an
+    /// in-flight writer that crashed between `create_new` and the `pid=`
+    /// write.
     fn clear_lock_if_stale(&self) -> bool {
+        let metadata = match fs::metadata(&self.lock_path) {
+            Ok(m) => m,
+            Err(e) if e.kind() == std::io::ErrorKind::NotFound => return false,
+            Err(e) => {
+                tracing::warn!(
+                    target: "auth-profiles",
+                    "[credentials] failed to stat lock file at {} for stale check: {e}",
+                    self.lock_path.display()
+                );
+                return false;
+            }
+        };
+
+        let too_old = match metadata.modified() {
+            Ok(mtime) => std::time::SystemTime::now()
+                .duration_since(mtime)
+                .map(|age| age >= Duration::from_millis(STALE_LOCK_AGE_MS))
+                .unwrap_or(false),
+            Err(_) => false,
+        };
+
         let content = match fs::read_to_string(&self.lock_path) {
             Ok(s) => s,
             Err(e) if e.kind() == std::io::ErrorKind::NotFound => return false,
@@ -632,24 +701,34 @@ impl AuthProfilesStore {
             .lines()
             .find_map(|line| line.trim().strip_prefix("pid=")?.trim().parse::<u32>().ok());
 
-        let Some(pid) = pid else {
-            tracing::warn!(
-                target: "auth-profiles",
-                "[credentials] lock at {} has no parseable pid line; leaving in place",
-                self.lock_path.display()
-            );
-            return false;
+        let reclaim_reason: Option<String> = match pid {
+            Some(pid) if !is_pid_alive(pid) => Some(format!("pid {pid} not alive")),
+            Some(pid) if too_old => Some(format!(
+                "lock file older than {STALE_LOCK_AGE_MS}ms (recorded pid {pid}, presumed leaked)"
+            )),
+            None if too_old => Some(format!(
+                "lock file older than {STALE_LOCK_AGE_MS}ms with no parseable pid"
+            )),
+            Some(_) => return false,
+            None => {
+                tracing::warn!(
+                    target: "auth-profiles",
+                    "[credentials] lock at {} has no parseable pid line; leaving in place",
+                    self.lock_path.display()
+                );
+                return false;
+            }
         };
 
-        if is_pid_alive(pid) {
+        let Some(reason) = reclaim_reason else {
             return false;
-        }
+        };
 
         match fs::remove_file(&self.lock_path) {
             Ok(()) => {
                 tracing::info!(
                     target: "auth-profiles",
-                    "[credentials] removed stale auth profile lock at {} (pid {pid} not alive)",
+                    "[credentials] removed stale auth profile lock at {} ({reason})",
                     self.lock_path.display()
                 );
                 true
@@ -658,7 +737,7 @@ impl AuthProfilesStore {
             Err(e) => {
                 tracing::warn!(
                     target: "auth-profiles",
-                    "[credentials] failed to remove stale lock at {}: {e}",
+                    "[credentials] failed to remove stale lock at {} ({reason}): {e}",
                     self.lock_path.display()
                 );
                 false
@@ -706,7 +785,35 @@ struct AuthProfileLockGuard {
 
 impl Drop for AuthProfileLockGuard {
     fn drop(&mut self) {
-        let _ = fs::remove_file(&self.lock_path);
+        // Best-effort unlink with retries. On Windows, antivirus and the
+        // search indexer routinely hold a transient handle on a file just
+        // after it is written, which makes `fs::remove_file` fail with
+        // `PermissionDenied`. A failed unlink here leaks the lock file
+        // with the still-alive owner pid inside, which would cause every
+        // subsequent acquirer to spin the full `LOCK_TIMEOUT_MS` and bail
+        // with "Timed out waiting for auth profile lock". The age-based
+        // reclaim in `clear_lock_if_stale` is the safety net; this retry
+        // loop is the first line of defence so we don't rely on it.
+        for attempt in 0..5u32 {
+            match fs::remove_file(&self.lock_path) {
+                Ok(()) => return,
+                Err(e) if e.kind() == std::io::ErrorKind::NotFound => return,
+                Err(e) => {
+                    if attempt + 1 == 5 {
+                        tracing::warn!(
+                            target: "auth-profiles",
+                            "[credentials] failed to remove auth profile lock at {} after {} attempts: {e}. \
+                             The age-based stale-lock reclaim will recover within {}ms.",
+                            self.lock_path.display(),
+                            attempt + 1,
+                            STALE_LOCK_AGE_MS,
+                        );
+                        return;
+                    }
+                    thread::sleep(Duration::from_millis(50u64.saturating_mul(1u64 << attempt)));
+                }
+            }
+        }
     }
 }
 

src/openhuman/credentials/profiles_tests.rs

@@ -442,6 +442,59 @@ fn acquire_lock_writes_pid_so_future_callers_can_recover() {
     assert!(!lock_path.exists(), "guard must remove lock on drop");
 }
 
+/// Sentry "Timed out waiting for auth profile lock" recovery: a lock
+/// file that has been around for longer than `STALE_LOCK_AGE_MS` is
+/// treated as leaked even if its recorded pid is still alive. This
+/// covers the Windows AV / indexer case where `Drop::drop` on the
+/// previous guard could not unlink the file and orphaned it with the
+/// still-alive owner pid inside.
+#[test]
+fn clear_lock_if_stale_reclaims_lock_older_than_threshold_even_with_live_pid() {
+    let tmp = TempDir::new().unwrap();
+    let store = AuthProfilesStore::new(tmp.path(), false);
+
+    let lock_path = tmp.path().join(LOCK_FILENAME);
+    std::fs::write(&lock_path, format!("pid={}\n", std::process::id())).unwrap();
+    // Backdate the lock-file mtime well past STALE_LOCK_AGE_MS.
+    let aged =
+        std::time::SystemTime::now() - std::time::Duration::from_millis(STALE_LOCK_AGE_MS + 5_000);
+    std::fs::OpenOptions::new()
+        .write(true)
+        .open(&lock_path)
+        .expect("reopen lock for set_modified")
+        .set_modified(aged)
+        .expect("backdate lock mtime");
+
+    assert!(
+        store.clear_lock_if_stale(),
+        "an aged lock with a live pid must be reclaimed (leaked-by-failed-unlink case)"
+    );
+    assert!(!lock_path.exists(), "stale lock should have been removed");
+}
+
+#[test]
+fn clear_lock_if_stale_reclaims_aged_malformed_lock() {
+    let tmp = TempDir::new().unwrap();
+    let store = AuthProfilesStore::new(tmp.path(), false);
+
+    let lock_path = tmp.path().join(LOCK_FILENAME);
+    std::fs::write(&lock_path, "garbage without a pid line\n").unwrap();
+    let aged =
+        std::time::SystemTime::now() - std::time::Duration::from_millis(STALE_LOCK_AGE_MS + 5_000);
+    std::fs::OpenOptions::new()
+        .write(true)
+        .open(&lock_path)
+        .expect("reopen lock for set_modified")
+        .set_modified(aged)
+        .expect("backdate lock mtime");
+
+    assert!(
+        store.clear_lock_if_stale(),
+        "an aged malformed lock should be reclaimed"
+    );
+    assert!(!lock_path.exists());
+}
+
 /// Sentry OPENHUMAN-TAURI-H8: when `OpenOptions::create_new` fails with
 /// anything other than `AlreadyExists`, the error surfaced to Sentry
 /// must embed the underlying `io::ErrorKind` and `raw_os_error()` so we

src/openhuman/credentials/session_support.rs

@@ -2,7 +2,7 @@
 
 use crate::openhuman::config::Config;
 
-use super::profiles::{AuthProfileKind, TokenSet};
+use super::profiles::{AuthProfile, AuthProfileKind, TokenSet};
 use super::responses::{AuthProfileSummary, AuthStateResponse};
 use super::AuthService;
 
@@ -87,18 +87,37 @@ fn session_user_value(
 }
 
 pub fn build_session_state(config: &Config) -> Result<AuthStateResponse, String> {
-    let auth_service = AuthService::from_config(config);
-    let profile = auth_service
-        .get_profile(APP_SESSION_PROVIDER, None)
-        .map_err(|e| e.to_string())?;
+    let profile = load_app_session_profile(config)?;
+    Ok(session_state_from_profile(profile.as_ref()))
+}
 
+pub fn get_session_token(config: &Config) -> Result<Option<String>, String> {
+    let profile = load_app_session_profile(config)?;
+    Ok(session_token_from_profile(profile.as_ref()))
+}
+
+/// Load the `app-session` profile once. Callers that need both the
+/// session-state view (`session_state_from_profile`) AND the raw token
+/// (`session_token_from_profile`) should call this once and pass the
+/// result to both helpers — every load takes the auth-profile store
+/// lock, and on Windows the `app_state_snapshot` hot path used to take
+/// it twice per call which materially increased lock contention
+/// (Sentry: "Timed out waiting for auth profile lock").
+pub fn load_app_session_profile(config: &Config) -> Result<Option<AuthProfile>, String> {
+    let auth_service = AuthService::from_config(config);
+    auth_service
+        .get_profile(APP_SESSION_PROVIDER, None)
+        .map_err(|e| e.to_string())
+}
+
+pub fn session_state_from_profile(profile: Option<&AuthProfile>) -> AuthStateResponse {
     let Some(profile) = profile else {
-        return Ok(AuthStateResponse {
+        return AuthStateResponse {
             is_authenticated: false,
             user_id: None,
             user: None,
             profile_id: None,
-        });
+        };
     };
 
     let is_authenticated = profile
@@ -107,20 +126,24 @@ pub fn build_session_state(config: &Config) -> Result<AuthStateResponse, String>
         .map(|token| !token.trim().is_empty())
         .unwrap_or(false);
 
-    Ok(AuthStateResponse {
+    AuthStateResponse {
         is_authenticated,
         user_id: profile.metadata.get("user_id").cloned(),
-        user: session_user_value(&profile),
-        profile_id: Some(profile.id),
-    })
+        user: session_user_value(profile),
+        profile_id: Some(profile.id.clone()),
+    }
 }
 
-pub fn get_session_token(config: &Config) -> Result<Option<String>, String> {
-    let auth_service = AuthService::from_config(config);
-    let profile = auth_service
-        .get_profile(APP_SESSION_PROVIDER, None)
-        .map_err(|e| e.to_string())?;
-    Ok(profile.and_then(|entry| entry.token))
+pub fn session_token_from_profile(profile: Option<&AuthProfile>) -> Option<String> {
+    // Mirror the `is_authenticated` check in `session_state_from_profile`
+    // (trim + non-empty) so the two views of the same profile never
+    // disagree — i.e. we never return `Some("   ")` while reporting
+    // `is_authenticated = false`.
+    profile
+        .and_then(|entry| entry.token.as_deref())
+        .map(str::trim)
+        .filter(|token| !token.is_empty())
+        .map(str::to_string)
 }
 
 #[cfg(test)]
@@ -316,6 +339,29 @@ mod tests {
         assert!(get_session_token(&config).unwrap().is_none());
     }
 
+    /// Regression for CodeRabbit feedback on PR #2085: a profile whose
+    /// token is whitespace-only must come back as `None`, matching the
+    /// `is_authenticated` view (which trims + filters empty).
+    #[test]
+    fn session_token_from_profile_normalises_blank_tokens_to_none() {
+        let p_blank = profile_fixture(AuthProfileKind::Token, Some("   "));
+        assert!(session_token_from_profile(Some(&p_blank)).is_none());
+
+        let p_empty = profile_fixture(AuthProfileKind::Token, Some(""));
+        assert!(session_token_from_profile(Some(&p_empty)).is_none());
+
+        let p_none = profile_fixture(AuthProfileKind::Token, None);
+        assert!(session_token_from_profile(Some(&p_none)).is_none());
+
+        let p_real = profile_fixture(AuthProfileKind::Token, Some("  tok  "));
+        // Trim leaks into the returned value — this matches the
+        // `is_authenticated` semantic that "  tok  " is a real token.
+        assert_eq!(
+            session_token_from_profile(Some(&p_real)).as_deref(),
+            Some("tok")
+        );
+    }
+
     #[test]
     fn get_session_token_returns_stored_token_when_present() {
         let tmp = TempDir::new().unwrap();