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.