diff --git a/crates/pdfs-cli/src/main.rs b/crates/pdfs-cli/src/main.rs index b7425ab..3c4c59b 100644 --- a/crates/pdfs-cli/src/main.rs +++ b/crates/pdfs-cli/src/main.rs @@ -2520,7 +2520,10 @@ fn mount_once(mountpoint: Option) -> Result { // An explicit `--mountpoint` wins; otherwise honor the Settings-page choice // (config), falling back to the default location. let mountpoint = mountpoint.unwrap_or_else(|| dirs.resolved_mountpoint(&config)); - std::fs::create_dir_all(&mountpoint) + // Hydrating a large account and remounting its folders can outlast the + // unit's watchdog before the supervisor sends its first ping (B279). + pdfs_fuse::stretch_watchdog_for_startup(); + pdfs_fuse::prepare_mountpoint(&mountpoint) .with_context(|| format!("create mountpoint {}", mountpoint.display()))?; let username = auth::load().map(|s| s.username).unwrap_or_default(); diff --git a/crates/pdfs-fuse/src/lib.rs b/crates/pdfs-fuse/src/lib.rs index af1a731..c10e354 100644 --- a/crates/pdfs-fuse/src/lib.rs +++ b/crates/pdfs-fuse/src/lib.rs @@ -119,13 +119,14 @@ mod workers; use background::{forget_and_notify, run_event_sync, run_local_index, run_photos_event_sync}; use link::BATCH_CALL_TIMEOUT; pub(crate) use mount::is_stale_mount; +pub use mount::prepare_mountpoint; pub use mount::{MountOptions, MountOutcome, mount}; use mount::{ SecondaryInsertRejection, SecondaryMount, clear_stale_mount, fuse_connection_id, spawn_session, }; use reads::{BlockFlight, BlockRing, PREFETCH_BUDGET, Prefetch, ReaderSlot, STREAM_BYPASS_MIN}; use state::{Entry, Intervals, PendingRevision, State, StateGuard, WriteHandle}; -pub use systemd::{idle_sleep, status as notify_status}; +pub use systemd::{idle_sleep, status as notify_status, stretch_watchdog_for_startup}; use tracing::{debug, error, info, warn}; use transfers::{CountingWriter, JobGuard, OwnedCountingReader, TransferRegistry}; use r#virtual::{ diff --git a/crates/pdfs-fuse/src/mount.rs b/crates/pdfs-fuse/src/mount.rs index 4d133f4..001f0df 100644 --- a/crates/pdfs-fuse/src/mount.rs +++ b/crates/pdfs-fuse/src/mount.rs @@ -196,6 +196,20 @@ pub(super) fn clear_stale_mount(mountpoint: &Path) { } } +/// Make sure `mountpoint` is a directory a mount can go on, clearing a dead +/// mount a killed daemon left there first. +/// +/// A dead mount answers `ENOTCONN`, which `create_dir_all` takes for "absent"; +/// it then tries `mkdir` and fails with `EEXIST`. The daemon retried that error +/// forever and never got as far as [`check_mountpoint`], which would have +/// cleared the mount (`docs/BUGS.md` B279). +pub fn prepare_mountpoint(mountpoint: &Path) -> std::io::Result<()> { + if is_stale_mount(mountpoint) { + clear_stale_mount(mountpoint); + } + std::fs::create_dir_all(mountpoint) +} + /// Refuse to mount My files over a folder that already has files in it: FUSE /// would hide them, unsent and out of sight, until the service stops /// (`docs/BUGS.md` B277). Runs before the root fetch and before any worker diff --git a/crates/pdfs-fuse/src/supervisor.rs b/crates/pdfs-fuse/src/supervisor.rs index 6e54f87..c15e5da 100644 --- a/crates/pdfs-fuse/src/supervisor.rs +++ b/crates/pdfs-fuse/src/supervisor.rs @@ -57,7 +57,10 @@ pub(crate) fn run(core: Core, control_socket: PathBuf) { } let mut last_rss = Instant::now(); - let mut last_ping = Instant::now(); + // `None` until the first probe, which runs on the first tick: startup has + // already used up much of the watchdog's time (`docs/BUGS.md` B279). + let mut last_ping: Option = None; + let mut restored = false; // Per-lane completion counts from the previous tick, to tell a queue that is // being worked through from one that is not moving at all. let mut last_completed = (0_u64, 0_u64); @@ -84,16 +87,22 @@ pub(crate) fn run(core: Core, control_socket: PathBuf) { // throw away in-flight uploads. The probe decides that; a stall only // gets said out loud. if let Some(period) = watchdog - && last_ping.elapsed() >= period + && ping_due(last_ping, period) { if probe(&control_socket) { + if !restored { + // Startup ran on the longer timeout the daemon asked for. + // The socket answers now, so the unit's own one applies. + systemd::restore_watchdog(); + restored = true; + } systemd::watchdog_ping(); } else { warn!( "daemon did not answer its own control socket; withholding the watchdog ping" ); } - last_ping = Instant::now(); + last_ping = Some(Instant::now()); } } } @@ -165,6 +174,11 @@ fn report_stalls(report: &pdfs_core::control::Diagnostics, last_completed: (u64, stalled } +/// Whether the watchdog wants its next ping. The first one is due at once. +fn ping_due(last_ping: Option, period: Duration) -> bool { + last_ping.is_none_or(|at| at.elapsed() >= period) +} + /// One round trip over the control socket: connect, ask for the cheapest /// request there is, read the answer. /// @@ -205,6 +219,18 @@ mod tests { } } + /// The first ping goes out on the first tick, not a full period after the + /// supervisor starts: startup has already spent most of the watchdog's time + /// (`docs/BUGS.md` B279). + #[test] + fn first_watchdog_ping_is_due_at_once() { + let period = Duration::from_secs(60); + assert!(ping_due(None, period)); + assert!(!ping_due(Some(Instant::now()), period)); + let long_ago = Instant::now().checked_sub(period).expect("uptime"); + assert!(ping_due(Some(long_ago), period)); + } + /// A worker doing normal work must not be reported: a WARN every tick is a /// WARN nobody reads. #[test] diff --git a/crates/pdfs-fuse/src/systemd.rs b/crates/pdfs-fuse/src/systemd.rs index f54091e..809f305 100644 --- a/crates/pdfs-fuse/src/systemd.rs +++ b/crates/pdfs-fuse/src/systemd.rs @@ -102,6 +102,37 @@ pub fn idle_sleep(duration: Duration) { } } +/// How long a mount may take to start before the watchdog counts it as hung. +/// +/// Startup has no control socket to probe yet, and on a large account it is +/// long: hydrating 48 000 nodes took 70 s on 2026-11-12, and the secondary +/// mounts followed. Under the 2-minute `WatchdogSec` that run was aborted just +/// before its first ping, and left six dead mounts behind (`docs/BUGS.md` B279). +const STARTUP_WATCHDOG: Duration = Duration::from_secs(600); + +/// Give the mount about to start [`STARTUP_WATCHDOG`] before the watchdog fires. +/// +/// Sends `WATCHDOG_USEC=`, which replaces the unit's timeout and restarts its +/// timer. The supervisor puts the configured timeout back with +/// [`restore_watchdog`] once it can prove the daemon answers. A startup that +/// wedges for good is still aborted, only later. +pub fn stretch_watchdog_for_startup() { + if watchdog_period().is_some() { + notify(&format!("WATCHDOG_USEC={}\n", STARTUP_WATCHDOG.as_micros())); + } +} + +/// Put back the timeout the unit configured, undoing +/// [`stretch_watchdog_for_startup`]. +pub(crate) fn restore_watchdog() { + if watchdog_period().is_none() { + return; + } + if let Ok(usec) = std::env::var("WATCHDOG_USEC") { + notify(&format!("WATCHDOG_USEC={usec}\n")); + } +} + /// Tell the manager the daemon is stopping, so a slow teardown is not mistaken /// for a hang by the watchdog it is racing. pub(crate) fn stopping() { diff --git a/docs/BUGS.md b/docs/BUGS.md index 4356d24..d8ed131 100644 --- a/docs/BUGS.md +++ b/docs/BUGS.md @@ -109,6 +109,7 @@ a live account since. | Entry | Title | |---|---| +| [B279](#b279--after-a-watchdog-kill-the-mount-never-comes-back) | After a watchdog kill the mount never comes back | | [B278](#b278--sync-list-and-devices-list-show-the-last-sync-as-epoch-seconds) | `sync list` and `devices list` show the last sync as epoch seconds | | [B277](#b277--my-files-mounted-over-a-folder-with-files-in-it-and-hid-them) | My files mounted over a folder with files in it, and hid them | | [B274](#b274--opening-a-file-for-writing-fails-with-eio-while-its-queued-revision-lands) | Opening a file for writing fails with EIO while its queued revision lands | @@ -381,6 +382,47 @@ a live account since. Newest first. +### B279 — After a watchdog kill the mount never comes back + +**Status:** Fixed, not verified live +**Found:** 2026-11-12, copying a folder of pictures into `~/ProtonDrive/Pictures`. The daemon +stopped answering, the watchdog aborted it after 4 h 39 min (2.5 GiB memory peak, 11.8 GiB swap +peak), and every restart then logged +`create mountpoint /home/narl/ProtonDrive: File exists (os error 17)`. After the dead mounts were +cleared by hand, the next start mounted all six folders and was aborted again, 120 s after it +began, leaving six dead mounts behind once more. +**Where:** `mount_once` in `crates/pdfs-cli/src/main.rs`; `prepare_mountpoint` in +`crates/pdfs-fuse/src/mount.rs`; `crates/pdfs-fuse/src/supervisor.rs`; +`crates/pdfs-fuse/src/systemd.rs` + +**Repro:** Kill the daemon with `SIGABRT` while it is mounted. Each restart fails with `EEXIST` +until `fusermount3 -uz` clears every mount. Then restart on an account where hydrating the +metadata cache takes about a minute: the watchdog aborts the new daemon before it pings. + +**Cause.** Two faults, one after the other. + +1. A dead FUSE mount answers `ENOTCONN`. `create_dir_all` in `mount_once` read that as "absent", + tried `mkdir`, and failed with `EEXIST`. The daemon retried that error forever and never + reached `check_mountpoint`, which clears a dead mount. +2. systemd arms the watchdog when the process starts, but the supervisor sent its first ping one + full period (60 s) after it started. The supervisor starts only once the mount is live: 74 s + in on this account (70 s of that is hydrating 47 958 nodes). 74 s + 60 s is past the 120 s + `WatchdogSec`, so the run was aborted just before its first ping. + +**Fix.** `mount_once` calls `prepare_mountpoint`, which clears a dead mount before it creates the +directory. Before startup, the daemon sends `WATCHDOG_USEC=` to allow 10 minutes. When the +supervisor first gets an answer from the control socket, it sends the unit's own timeout back. +The supervisor also probes and pings on its first tick, not one period later. A startup that +hangs for good is still aborted, only later. + +What is left: why the daemon stopped answering during the copy. Its swap use points at memory +growth during a large batch of new files (compare [B91](#b91--the-daemon-hung-overnight-and-nothing-could-say-what-it-was-waiting-on)). + +**Test:** `first_watchdog_ping_is_due_at_once` in `crates/pdfs-fuse/src/supervisor.rs`. The +stale-mount path and the watchdog handshake need a live systemd unit to check. + +--- + ### B278 — `sync list` and `devices list` show the last sync as epoch seconds **Status:** Fixed, not verified live