Merge pull request #65 from narrrl/fix/clean-stop-runtime

fix(cli): leave the runtime running on a stop so stragglers cannot panic

crates/pdfs-cli/src/main.rs

@@ -2527,14 +2527,30 @@ fn mount_once(mountpoint: Option<PathBuf>) -> Result<pdfs_fuse::MountOutcome> {
             "could not save the refreshed session tokens; the next start may need `pdfs login`"
         );
     }
-    // Dropping the runtime waits for every blocking task, however long; a call
-    // still stuck on Drive would hold the stop until systemd kills it (B165).
-    rt.shutdown_timeout(std::time::Duration::from_secs(2));
+    release_runtime(rt, matches!(result, Ok(pdfs_fuse::MountOutcome::Shutdown)));
 
     let outcome = result.context("mount failed")?;
     Ok(outcome)
 }
 
+/// Let go of a mount's runtime once the mount has ended.
+///
+/// On a stop the process exits right after, so the runtime is left running
+/// for it to end with. Shutting it down first broke every thread the mount
+/// does not join, such as a size lookup or a profile backup a request started
+/// during the stop: its next call to Drive panicked with "A Tokio 1.x context
+/// was found, but it is being shutdown" (`docs/BUGS.md` B276). A mount that
+/// is about to be tried again does shut it down, because a new runtime
+/// replaces it. Dropping it would wait for every blocking task, however long;
+/// a call still stuck on Drive would hold the retry (B165).
+fn release_runtime(rt: tokio::runtime::Runtime, exiting: bool) {
+    if exiting {
+        std::mem::forget(rt);
+    } else {
+        rt.shutdown_timeout(std::time::Duration::from_secs(2));
+    }
+}
+
 fn cmd_pin(path: PathBuf) -> Result<()> {
     match control_request(CtlRequest::Pin {
         path: path_arg(&path)?,
@@ -4146,6 +4162,47 @@ fn control_request(req: CtlRequest) -> Result<CtlResponse> {
         .with_context(|| format!("talk to mount daemon at {}", socket.display()))
 }
 
+#[cfg(test)]
+mod release_runtime_tests {
+    use super::*;
+    use std::time::Duration;
+
+    /// A thread the mount never joined still reaches Drive after a stop. It
+    /// used to panic on its first timer once the runtime was shut down.
+    #[test]
+    fn a_thread_left_running_at_a_stop_can_still_use_the_runtime() {
+        let rt = tokio::runtime::Runtime::new().unwrap();
+        let handle = rt.handle().clone();
+        let (released_tx, released_rx) = std::sync::mpsc::channel();
+        let straggler = std::thread::spawn(move || {
+            released_rx.recv().unwrap();
+            handle.block_on(async {
+                tokio::time::sleep(Duration::from_millis(1)).await;
+                7
+            })
+        });
+        release_runtime(rt, true);
+        released_tx.send(()).unwrap();
+        assert_eq!(straggler.join().expect("the thread must not panic"), 7);
+    }
+
+    #[test]
+    fn a_mount_tried_again_shuts_its_runtime_down() {
+        let rt = tokio::runtime::Runtime::new().unwrap();
+        let (done_tx, done_rx) = std::sync::mpsc::channel::<()>();
+        rt.spawn(async move {
+            let _done = done_tx;
+            std::future::pending::<()>().await;
+        });
+        release_runtime(rt, false);
+        // The task is dropped with the runtime, and its sender with it.
+        assert_eq!(
+            done_rx.recv_timeout(Duration::from_secs(5)),
+            Err(std::sync::mpsc::RecvTimeoutError::Disconnected)
+        );
+    }
+}
+
 #[cfg(test)]
 mod pause_tests {
     use super::*;

docs/BUGS.md

@@ -109,13 +109,14 @@ a live account since.
 
 | Entry | Title |
 |---|---|
-| [B265](#b265--address-keys-whose-token-is-for-an-inactive-account-key-never-open) | Address keys whose token is for an inactive account key never open |
+| [B276](#b276--a-stop-can-end-with-a-panic-in-a-thread-the-stop-never-waited-for) | A stop can end with a panic in a thread the stop never waited for |
 | [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 |
+| [B272](#b272--after-a-folder-is-removed-and-added-again-its-file-events-go-to-the-old-id) | After a folder is removed and added again, its file events go to the old id |
 | [B271](#b271--one-failed-listing-makes-a-large-first-sync-start-over-from-nothing) | One failed listing makes a large first sync start over from nothing |
 | [B266](#b266--pin-unpin-search-and-node-loads-report-a-database-error-as-offline) | Pin, unpin, search and node loads report a database error as "offline" |
+| [B265](#b265--address-keys-whose-token-is-for-an-inactive-account-key-never-open) | Address keys whose token is for an inactive account key never open |
 | [B264](#b264--a-mount-that-fails-after-starting-its-workers-leaves-them-running) | A mount that fails after starting its workers leaves them running |
 | [B261](#b261--a-folder-that-has-never-synced-reads-up-to-date) | A folder that has never synced reads "up to date" |
-| [B272](#b272--after-a-folder-is-removed-and-added-again-its-file-events-go-to-the-old-id) | After a folder is removed and added again, its file events go to the old id |
 | [B260](#b260--the-poll-pushes-a-new-folders-first-sync-behind-every-other-folder) | The poll pushes a new folder's first sync behind every other folder |
 | [B258](#b258--journalctl--p-warning-shows-nothing-whatever-the-daemon-logged) | `journalctl -p warning` shows nothing, whatever the daemon logged |
 | [B256](#b256--pdfs-copy-right-after-a-save-copies-the-old-version) | `pdfs copy` right after a save copies the old version |
@@ -377,6 +378,65 @@ a live account since.
 
 Newest first.
 
+### B276 — A stop can end with a panic in a thread the stop never waited for
+
+**Status:** Fixed, not verified live
+**Found:** 2026-10-31, by an account run of `scripts/fuse-acceptance.sh --journal-check
+--durability` against the audit branches. Every case passed, and the run still failed. During
+the restart in the durability case on My files, the journal had three
+`ERROR fuser::reply: Failed to send FUSE reply: No such file or directory (os error 2)` lines,
+and after them a panic that the check did not report:
+
+```
+thread '<unnamed>' (1536340) panicked at .../tokio-1.53.1/src/runtime/time/entry.rs:539:9:
+A Tokio 1.x context was found, but it is being shutdown.
+```
+
+The same panic is in the journal of a 3.6.0 stop on 2026-10-28, twice. B91 first saw it in a
+meta worker.
+
+**Where:** `mount_once` and `release_runtime` in `crates/pdfs-cli/src/main.rs`;
+`JournalWatch` and `journal_problems` in `scripts/fuse-acceptance.py`.
+
+**Cause.** A stop joins the drain workers, the sync engine and the FUSE worker pool, and then
+`mount_once` shut the tokio runtime down. Other threads also use the runtime and are never
+joined: a size lookup for a listing, a profile backup, a control request, a database vacuum.
+A request still in progress when the stop began can start one of them. The thread id here is
+nine below the next daemon's pid, so this thread started during the stop. Once the runtime is
+shut down, that thread's next timer panics. Every call to Drive has a timer, because each one is
+bounded.
+
+The three `fuser::reply` lines are part of a correct stop. The stop aborts each mount's FUSE
+connection so the unmount cannot hang. A request that was still running replies after that,
+and the kernel answers a reply on an aborted connection with `ENOENT`.
+
+The journal check matched only the `ERROR` token. A panic goes to stderr with no tracing level,
+so the check did not see it.
+
+**Fix.**
+
+- On a stop, `release_runtime` leaves the runtime running for the process to end with, instead
+  of shutting it down. The process exits right after, so a thread the stop did not wait for
+  can finish its call or be ended by the exit, but it cannot panic. A mount that is about to
+  be tried again still shuts its runtime down with the 2 s limit from B165, because a new
+  runtime replaces it.
+- The journal check counts `panicked at` lines.
+- The journal check ignores the `ENOENT` reply error between the connection abort and the end
+  of that stop ("daemon stopping", or "control socket listening" for a mount that comes back).
+  At any other time the error still counts.
+
+Making the bounded call helpers refuse new calls once the stop flag is set was rejected. The
+stop sets that flag before it waits up to 10 s for the drain workers, so the refusal would cut
+off the second half of an upload the stop is waiting for.
+
+**Test:** `a_thread_left_running_at_a_stop_can_still_use_the_runtime` and
+`a_mount_tried_again_shuts_its_runtime_down` in `crates/pdfs-cli/src/main.rs`. With the old
+shutdown, the first one fails with the same panic at `entry.rs:539`. The new journal
+filter was run on the journal of the run that found this: the three reply errors are no longer
+counted, and the panic is.
+
+---
+
 ### B275 — On a slow link, a file's last write can land only in a conflict copy
 
 **Status:** Open

docs/TESTING.md

@@ -246,7 +246,7 @@ remaining cases are skipped. Cases that make many round trips by design get twic
 | `--report-json PATH` | Every result and recorded observation. Attach it to a bug report |
 | `--report-junit PATH` | JUnit XML. `known` is reported as skipped |
 | `--budget SECONDS` | Flags cases that pass but take longer (`PDFS_ACCEPTANCE_BUDGET`) |
-| `--journal-check` | Fails the run if `proton-drive.service` logged an error during it, or the warnings "queued write conflicts; keeping a conflict copy" and "a fuse worker has held the same job for a long time" |
+| `--journal-check` | Fails the run if `proton-drive.service` logged an error or a panic during it, or the warnings "queued write conflicts; keeping a conflict copy" and "a fuse worker has held the same job for a long time". A `Failed to send FUSE reply: No such file or directory` during a stop does not count: it is a request answering after the stop aborted its connection |
 | `--durability` | Restarts the service mid-suite and checks the bytes written before it. Proves the queue survives a restart. `PDFS_ACCEPTANCE_UNIT` names another unit |
 | `--fail-fast` | Stops at the first failure |
 | `--list` | Prints every case and its targets |

scripts/fuse-acceptance.py

@@ -3561,8 +3561,36 @@ JOURNAL_WARNINGS = (
     "queued write conflicts; keeping a conflict copy",
     "a fuse worker has held the same job for a long time",
     "re-interned an authority missing from the local tree",
+    # A Rust panic goes to stderr without a tracing level, so the ERROR match
+    # does not see it (`docs/BUGS.md` B276).
+    "panicked at",
 )
 
+# A stop aborts each mount's FUSE connection so the unmount cannot hang. A
+# request still running then replies into a connection the kernel has
+# closed, and the kernel refuses that reply with ENOENT. While a stop is in
+# progress that error is expected (`docs/BUGS.md` B276); at any other time it
+# still counts.
+STOP_STARTED = "aborted FUSE connection to unblock unmount"
+STOP_ENDED = ("daemon stopping", "control socket listening")
+LATE_REPLY = "Failed to send FUSE reply: No such file or directory"
+
+
+def journal_problems(lines: list[str]) -> list[str]:
+    """The lines of `lines` that count as problems."""
+    problems = []
+    stopping = False
+    for line in lines:
+        if STOP_STARTED in line:
+            stopping = True
+        elif any(marker in line for marker in STOP_ENDED):
+            stopping = False
+        if stopping and LATE_REPLY in line:
+            continue
+        if ERROR_LEVEL.search(line) or any(warning in line for warning in JOURNAL_WARNINGS):
+            problems.append(line)
+    return problems
+
 
 def read_journal(unit: str, since: float) -> list[str] | None:
     """The unit's journal lines since `since`, or None without journalctl.
@@ -3621,11 +3649,7 @@ class JournalWatch:
         # Filtering on syslog priority (`-p err`) finds nothing: the daemon writes
         # tracing levels as text on stdout, which journald files at the unit's
         # default priority. Match the level token instead.
-        return [
-            line
-            for line in lines
-            if ERROR_LEVEL.search(line) or any(warning in line for warning in JOURNAL_WARNINGS)
-        ]
+        return journal_problems(lines)
 
 
 # --------------------------------------------------------------------------