From 51d114a8da0c663a6e0633a67d178f3f02bebd7a Mon Sep 17 00:00:00 2001 From: Nils Pukropp Date: Fri, 9 Oct 2026 11:05:12 +0200 Subject: [PATCH] fix(fuse,core): idle drain workers no longer spin while offline Offline or paused, a drain worker claims nothing and then slept until the earliest queued op fell due. Every queued op was already due and nothing attempted it, so the wait was zero and all 16 workers spun on the queue for the whole outage (issue #35: 17 min of CPU in 2 min 16 s). A worker that claims nothing now sleeps the full idle poll; a reconnect or resume wakes it. earliest_due_at also uses the claim's exclusions, so an op held behind a claimed op on the same node no longer counts as due. docs/BUGS.md B200. --- crates/pdfs-core/src/db/ops.rs | 43 +++++++++++++--------- crates/pdfs-core/src/db/tests.rs | 30 ++++++++++++++++ crates/pdfs-fuse/src/drain.rs | 62 ++++++++++++++++++++++---------- docs/BUGS.md | 28 +++++++++++++++ 4 files changed, 129 insertions(+), 34 deletions(-) diff --git a/crates/pdfs-core/src/db/ops.rs b/crates/pdfs-core/src/db/ops.rs index 25f5e85..9edabc3 100644 --- a/crates/pdfs-core/src/db/ops.rs +++ b/crates/pdfs-core/src/db/ops.rs @@ -252,6 +252,25 @@ const UID_NOW: &str = "COALESCE((SELECT uid FROM nodes WHERE lid = pending_op.li const PARENT_NOW: &str = "COALESCE((SELECT uid FROM nodes WHERE lid = pending_op.parent_lid), parent_uid)"; +/// The `WHERE` terms for a row a drain worker may claim once it falls due: not +/// claimed already, no other claimed op on the same node, and not under a +/// folder that has yet to land. +/// +/// One fragment for [`Db::claim_next_due_op`] and [`Db::earliest_due_at`]. A +/// row the claim skips but the wait counts is due "now" for as long as it is +/// held, and every idle worker spun on it (`docs/BUGS.md` B200). +fn claimable() -> String { + format!( + "claimed_at = 0 + AND (parent_uid IS NULL OR substr({PARENT_NOW}, 1, {n}) <> '{v}~') + AND uid NOT IN (SELECT uid FROM pending_op WHERE claimed_at <> 0) + AND (lid IS NULL OR lid NOT IN ( + SELECT lid FROM pending_op WHERE claimed_at <> 0 AND lid IS NOT NULL))", + v = LOCAL_VOLUME, + n = LOCAL_VOLUME.len() + 1, + ) +} + /// The volume id given to a node that exists only on this machine, so far. A /// real [`NodeUid`] is `{volume}~{link}`, so a placeholder is `local~` and /// round-trips through the same `Display`/parse path as any other uid. @@ -1127,15 +1146,9 @@ impl Db { "SELECT id, kind, {UID_NOW}, {PARENT_NOW}, name, blob_path, meta_json, created_at, attempts, last_error, next_attempt_at FROM pending_op - WHERE next_attempt_at <= ?1 - AND claimed_at = 0 - AND (parent_uid IS NULL OR substr({PARENT_NOW}, 1, {n}) <> '{v}~') - AND uid NOT IN (SELECT uid FROM pending_op WHERE claimed_at <> 0) - AND (lid IS NULL OR lid NOT IN ( - SELECT lid FROM pending_op WHERE claimed_at <> 0 AND lid IS NOT NULL)) + WHERE next_attempt_at <= ?1 AND {claimable} ORDER BY id LIMIT 1", - v = LOCAL_VOLUME, - n = LOCAL_VOLUME.len() + 1, + claimable = claimable(), ))?; stmt.query_row(params![now], |r| { Ok(PendingOp { @@ -1208,19 +1221,17 @@ impl Db { /// debounced or backed-off op becomes eligible rather than waiting the full /// idle-poll interval. /// - /// Claimed ops are excluded: another worker is already on them, so they are - /// not work this one is waiting for, and counting them would have an idle - /// worker spin on a row it cannot have. + /// Only rows [`claim_next_due_op`](Self::claim_next_due_op) could take + /// count. A claimed op, or one held behind a claimed op on the same node, + /// is not work this worker is waiting for, and counting it would have an + /// idle worker spin on a row it cannot have. pub fn earliest_due_at(&self) -> Result> { let conn = self.read(); let ts: Option = conn .query_row( &format!( - "SELECT MIN(next_attempt_at) FROM pending_op \ - WHERE claimed_at = 0 \ - AND (parent_uid IS NULL OR substr({PARENT_NOW}, 1, {n}) <> '{v}~')", - v = LOCAL_VOLUME, - n = LOCAL_VOLUME.len() + 1, + "SELECT MIN(next_attempt_at) FROM pending_op WHERE {claimable}", + claimable = claimable(), ), [], |r| r.get(0), diff --git a/crates/pdfs-core/src/db/tests.rs b/crates/pdfs-core/src/db/tests.rs index 6991ba5..1131104 100644 --- a/crates/pdfs-core/src/db/tests.rs +++ b/crates/pdfs-core/src/db/tests.rs @@ -6547,6 +6547,36 @@ fn an_idle_worker_does_not_wait_on_an_op_another_worker_has() { ); } +/// B200: a rename queued behind a long upload of the same node is due, but no +/// worker may claim it until the upload retires. Counted as due, it had every +/// idle worker wake at once, find nothing, and go round again. +#[test] +fn earliest_due_at_skips_an_op_held_behind_a_claimed_one() { + let db = Db::open_in_memory().unwrap(); + let root = uid("root").to_string(); + let mut revision = bulk_op(0, &root); + revision.parent_uid = None; + db.enqueue_op(&revision).unwrap(); + db.enqueue_op(&PendingOp { + kind: OP_RENAME.to_string(), + parent_uid: Some(root.clone()), + blob_path: None, + meta_json: None, + ..bulk_op(0, &root) + }) + .unwrap(); + + db.claim_next_due_op(10) + .unwrap() + .expect("the revision is due"); + assert!(db.claim_next_due_op(10).unwrap().is_none()); + assert_eq!( + db.earliest_due_at().unwrap(), + None, + "a row no worker can claim is not work an idle worker is waiting for" + ); +} + /// Trashing a photo from the gallery must not leave it behind on an album page: /// the row goes, its album membership goes with it, and nothing else moves. #[test] diff --git a/crates/pdfs-fuse/src/drain.rs b/crates/pdfs-fuse/src/drain.rs index 57861ce..7992bd3 100644 --- a/crates/pdfs-fuse/src/drain.rs +++ b/crates/pdfs-fuse/src/drain.rs @@ -347,17 +347,7 @@ impl Core { // its writer has to be noticed. self.sweep_parked_creates(); } - // Paused, nothing due changes that: sleep until a resume - // wakes the worker (or the idle poll notices a timed pause - // ran out), not until the next op falls due — that is - // "now" for everything already queued. - if paused { - self.wait_for_drain_work(); - continue; - } - // A debounced or backed-off op may be waiting: sleep only - // until it becomes due rather than the full idle-poll. - self.wait_for_drain_work_or_due(); + self.wait_for_drain_work_or_due(online && !paused); continue; } }; @@ -732,14 +722,16 @@ impl Core { /// Like [`wait_for_drain_work`](Self::wait_for_drain_work), but first /// checks whether a debounced or backed-off op is due before the idle-poll /// ceiling. A 2-second debounce must not sleep 30 seconds. - fn wait_for_drain_work_or_due(&self) { - let timeout = match self.db.earliest_due_at() { - Ok(Some(ts)) => { - let remaining = (ts - now_millis()).max(0) as u64; - Duration::from_millis(remaining).min(DRAIN_IDLE_POLL) - } - _ => DRAIN_IDLE_POLL, + /// + /// `claiming` is false while the worker claims nothing (offline or + /// paused); see [`idle_wait`]. + fn wait_for_drain_work_or_due(&self, claiming: bool) { + let earliest = if claiming { + self.db.earliest_due_at().ok().flatten() + } else { + None }; + let timeout = idle_wait(claiming, earliest, now_millis()); sleep_for_drain_work(&self.drain_wake, || self.shutdown.is_stopping(), timeout); } @@ -2833,6 +2825,23 @@ fn sleep_for_drain_work( *woken = false; } +/// How long an idle drain worker sleeps: until the earliest queued op falls +/// due, at most the idle poll. +/// +/// A worker that claims nothing — offline or paused — sleeps the full idle +/// poll whatever is due. Every op already queued is due "now" for it, so +/// sleeping until then was a zero wait, and all the workers spun on the queue +/// for as long as the outage lasted (`docs/BUGS.md` B200). A reconnect or a +/// resume wakes the drain, so nothing waits the full poll for it. +fn idle_wait(claiming: bool, earliest_due: Option, now: i64) -> Duration { + match earliest_due { + Some(ts) if claiming => { + Duration::from_millis((ts - now).max(0) as u64).min(DRAIN_IDLE_POLL) + } + _ => DRAIN_IDLE_POLL, + } +} + fn placed_in(st: &crate::state::State, uid: &NodeUid) -> Option<(String, Option)> { let entry = st.by_uid.get(uid).and_then(|ino| st.entries.get(ino))?; Some((entry.node.name.clone(), entry.node.parent_uid.clone())) @@ -2858,6 +2867,23 @@ mod tests { assert!(started.elapsed() < Duration::from_secs(1)); } + #[test] + fn an_offline_worker_waits_the_idle_poll_for_a_past_due_op() { + // The op fell due long ago, and offline nobody attempts it, so it + // stays due: waiting for it was a zero wait, forever (B200). + assert_eq!(idle_wait(false, Some(0), 10_000), DRAIN_IDLE_POLL); + } + + #[test] + fn a_claiming_worker_waits_only_until_the_next_op_falls_due() { + assert_eq!( + idle_wait(true, Some(12_000), 10_000), + Duration::from_secs(2) + ); + assert_eq!(idle_wait(true, Some(0), 10_000), Duration::ZERO); + assert_eq!(idle_wait(true, None, 10_000), DRAIN_IDLE_POLL); + } + fn pending(kind: &str) -> PendingOp { PendingOp { id: 0, diff --git a/docs/BUGS.md b/docs/BUGS.md index 93cca81..4451403 100644 --- a/docs/BUGS.md +++ b/docs/BUGS.md @@ -101,6 +101,7 @@ a live account since. | Entry | Title | |---|---| +| [B200](#b200--offline-with-changes-queued-the-daemon-keeps-several-cores-busy) | Offline with changes queued, the daemon keeps several cores busy | | [B198](#b198--switching-to-online-only-deletes-local-files-that-never-reached-drive) | Switching to online-only deletes local files that never reached Drive | | [B197](#b197--switching-to-online-only-trashes-synced-files-that-became-ignored) | Switching to online-only trashes synced files that became ignored | | [B196](#b196--one-unreadable-folder-stops-the-whole-synced-folder-from-syncing) | One unreadable folder stops the whole synced folder from syncing | @@ -302,6 +303,33 @@ a live account since. Newest first. +### B200 — Offline with changes queued, the daemon keeps several cores busy + +**Status:** Fixed, not verified live +**Found:** 2026-10-09, issue #35: "offline, 3 queued", and systemd counted 17 minutes of CPU in +2 m 16 s of wall time, 10 hours over a longer run. +**Where:** `crates/pdfs-fuse/src/drain.rs`, `Core::run_pending_drain` and `idle_wait`; +`crates/pdfs-core/src/db/ops.rs`, `Db::earliest_due_at` + +**Repro:** Queue a write, then cut the link (`nmcli networking off`). `pidstat -t -p $(pgrep -x +pdfs) 5` shows the drain threads using most of several cores for as long as the outage lasts. + +**Cause.** Offline, a drain worker claims nothing, and then sleeps until the earliest queued op +falls due. Every queued op was due already, and with no attempts nothing moves its +`next_attempt_at`, so the sleep was zero. All 16 workers ran a query on every pass, the primary +one its idle chores as well. The same spin happened online when a due op sat behind a claimed op +on the same node, such as a rename queued behind a long upload: `earliest_due_at` counted it, +`claim_next_due_op` skipped it. + +**Fix.** A worker that claims nothing, offline or paused, sleeps the full idle poll; a reconnect +or a resume wakes it. `earliest_due_at` now uses the claim's own exclusions, one SQL fragment for +both. + +**Test:** `drain::tests::an_offline_worker_waits_the_idle_poll_for_a_past_due_op`, +`db::tests::earliest_due_at_skips_an_op_held_behind_a_claimed_one`. + +--- + ### B199 — A stopped share stays on the Shared by me page for minutes **Status:** Partly fixed. The share itself is still not deleted.