fix(cli,core,fuse,gui): say why the mount keeps failing, and back off

A mount that failed on every try retried every 5 s forever, and the
reason was only in the journal: the app and the tray said Connecting...
for days (B263, issue #40). The retry now doubles to a 2-minute ceiling,
and the last failure is kept in mount-failure.json for the app, the
tray, pdfs diagnose and systemctl status.

The early returns in mount left the workers they had started running
beside the next attempt (B264). They are now stopped on every error
path, without telling systemd the daemon is stopping.
This commit is contained in:
nvrl committed 2026-10-31 10:49:01 +01:00
1 parent 9460c93b50
commit e9577f953f
18 files changed
+714 -311

No files matched your search

+76 -4
View File
@@ -2375,12 +2375,21 @@ where
/// an external unmount triggers a remount; errors back off and retry. This is
/// the entry point for the systemd user service.
fn cmd_daemon(mountpoint: Option<PathBuf>) -> Result<()> {
let state_dir = AppDirs::new()?.state_dir();
// A failure an earlier daemon recorded is not this one's.
pdfs_core::mountfail::clear(&state_dir);
let mut failure: Option<pdfs_core::mountfail::MountFailure> = None;
loop {
// Wait until a session is stored. The GUI enables this service on login,
// but the service may also start at boot before the user has logged in.
wait_for_session(auth::ready, pdfs_fuse::idle_sleep)?;
match mount_once(mountpoint.clone()) {
let outcome = mount_once(mountpoint.clone());
if outcome.is_ok() {
// The mount came up, so the next failure starts a new run of them.
failure = None;
}
match outcome {
Ok(pdfs_fuse::MountOutcome::Shutdown) => {
tracing::info!("daemon stopping");
return Ok(());
@@ -2395,13 +2404,51 @@ fn cmd_daemon(mountpoint: Option<PathBuf>) -> Result<()> {
Err(e) => {
// `{:#}` so the whole anyhow chain lands in the log — the top
// context alone ("mount failed") never says *why*.
tracing::error!(error = format!("{e:#}"), "mount failed; retrying in 5s");
pdfs_fuse::idle_sleep(std::time::Duration::from_secs(5));
let error = format!("{e:#}");
let now = unix_now();
let attempts = failure.as_ref().map_or(1, |f| f.attempts.saturating_add(1));
let delay = mount_retry_delay(attempts);
tracing::error!(
error,
attempts,
retry_secs = delay.as_secs(),
"mount failed; retrying"
);
let record = pdfs_core::mountfail::MountFailure {
error: error.clone(),
since: failure.as_ref().map_or(now, |f| f.since),
attempts,
next_attempt: now + delay.as_secs() as i64,
};
if let Err(e) = pdfs_core::mountfail::record(&state_dir, &record) {
tracing::warn!(error = %e, "could not record the mount failure");
}
pdfs_fuse::notify_status(&format!("Mount failing: {error}"));
failure = Some(record);
pdfs_fuse::idle_sleep(delay);
}
}
}
}
/// How long to wait before mount attempt `attempts + 1`, after `attempts`
/// failures in a row.
///
/// Doubles from 5 s to a 2-minute ceiling. A flat 5 s retry sent about four
/// requests to Proton per attempt, tens of thousands a day from an account
/// whose mount fails on a key, which no retry fixes (`docs/BUGS.md` B263). The
/// ceiling stays at minutes because a cold start without a network fails the
/// same way, and must mount soon after the network returns.
fn mount_retry_delay(attempts: u32) -> std::time::Duration {
const BASE_SECS: u64 = 5;
const MAX_SECS: u64 = 120;
let factor = 1u64
.checked_shl(attempts.saturating_sub(1))
.unwrap_or(u64::MAX);
std::time::Duration::from_secs(BASE_SECS.saturating_mul(factor).min(MAX_SECS))
}
/// One mount run: resume the session, mount, and block until the mount ends
/// (clean shutdown or external unmount). Returns the [`MountOutcome`] so the
/// daemon loop can decide whether to exit or remount.
@@ -3857,7 +3904,23 @@ fn cmd_diagnose() -> Result<()> {
" daemon responding",
format!("stopped or unreachable: {e:#}"),
);
println!(" (start it with `systemctl --user start proton-drive.service`)");
match pdfs_core::mountfail::read(&dirs.state_dir()) {
// A daemon whose mount keeps failing never opens the socket,
// so this is the only place its reason shows (B263).
Some(failure) => report.finding(
DiagnoseLevel::Fail,
" mount",
format!(
"failing for {}, {} attempt(s): {}",
human_secs(unix_now().saturating_sub(failure.since).max(0) as u64),
failure.attempts,
failure.error
),
),
None => println!(
" (start it with `systemctl --user start proton-drive.service`)"
),
}
}
}
@@ -4017,6 +4080,15 @@ mod diagnose_tests {
#[cfg(test)]
mod login_wait_tests {
use super::*;
/// The mount retry backs off from 5 s to a ceiling of minutes, rather than
/// asking Proton every 5 s forever (`docs/BUGS.md` B263).
#[test]
fn a_failing_mount_backs_off_to_a_ceiling() {
let secs: Vec<u64> = (1..=8).map(|n| mount_retry_delay(n).as_secs()).collect();
assert_eq!(secs, [5, 10, 20, 40, 80, 120, 120, 120]);
assert_eq!(mount_retry_delay(u32::MAX).as_secs(), 120);
}
use std::time::Duration;
#[test]
+1
View File
@@ -15,6 +15,7 @@ pub mod kernelkey;
pub mod keycheck;
pub mod localindex;
pub mod menu;
pub mod mountfail;
pub mod mounts;
pub mod opener;
pub mod places;
+75
View File
@@ -0,0 +1,75 @@
//! Why the daemon's mount keeps failing, for the front ends to read.
//!
//! The control socket opens only once a mount has succeeded, so a daemon whose
//! mount fails on every try had no way to say why. The app and the tray showed
//! "Connecting…" for days while the reason sat in the journal (`docs/BUGS.md`
//! B263). The daemon now writes its last failure to a small file in the state
//! directory, next to the control socket, and removes it once a mount is up.
use std::path::{Path, PathBuf};
use serde::{Deserialize, Serialize};
/// The file's name inside the state directory.
const FILE_NAME: &str = "mount-failure.json";
/// The last failed mount attempt.
#[derive(Serialize, Deserialize, Debug, Clone, PartialEq, Eq)]
pub struct MountFailure {
/// The error, in English, as the journal has it.
pub error: String,
/// Unix seconds of the first failure in this run of failures.
pub since: i64,
/// Failed attempts in a row.
pub attempts: u32,
/// Unix seconds of the next attempt.
pub next_attempt: i64,
}
/// Where the failure is kept for the state directory `state_dir`.
pub fn path(state_dir: &Path) -> PathBuf {
state_dir.join(FILE_NAME)
}
/// Record `failure`, replacing the one before it. Written to a temporary file
/// and renamed, so a reader never sees half of it.
pub fn record(state_dir: &Path, failure: &MountFailure) -> std::io::Result<()> {
let json = serde_json::to_vec(failure).map_err(std::io::Error::other)?;
let tmp = state_dir.join(format!("{FILE_NAME}.tmp"));
std::fs::write(&tmp, json)?;
std::fs::rename(&tmp, path(state_dir))
}
/// Forget the failure: a mount is up, or a new daemon has started.
pub fn clear(state_dir: &Path) {
let _ = std::fs::remove_file(path(state_dir));
}
/// The recorded failure, if there is one and it can be read.
pub fn read(state_dir: &Path) -> Option<MountFailure> {
let bytes = std::fs::read(path(state_dir)).ok()?;
serde_json::from_slice(&bytes).ok()
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn a_recorded_failure_reads_back_until_cleared() {
let dir = std::env::temp_dir().join(format!("pdfs-mountfail-{}", std::process::id()));
std::fs::create_dir_all(&dir).unwrap();
assert_eq!(read(&dir), None);
let failure = MountFailure {
error: "fetch My Files root: missing key".into(),
since: 1_700_000_000,
attempts: 3,
next_attempt: 1_700_000_040,
};
record(&dir, &failure).unwrap();
assert_eq!(read(&dir), Some(failure));
clear(&dir);
assert_eq!(read(&dir), None);
let _ = std::fs::remove_dir_all(&dir);
}
}
+1 -1
View File
@@ -124,7 +124,7 @@ use mount::{
};
use reads::{BlockFlight, BlockRing, PREFETCH_BUDGET, Prefetch, ReaderSlot, STREAM_BYPASS_MIN};
use state::{Entry, Intervals, PendingRevision, State, StateGuard, WriteHandle};
pub use systemd::idle_sleep;
pub use systemd::{idle_sleep, status as notify_status};
use tracing::{debug, error, info, warn};
use transfers::{CountingWriter, JobGuard, OwnedCountingReader, TransferRegistry};
use r#virtual::{
+71 -28
View File
@@ -540,12 +540,11 @@ pub(crate) fn mount_with(
// and sweeps all operating on a mount that no longer exists (`docs/BUGS.md` B44).
let mut workers: Vec<std::thread::JoinHandle<()>> = Vec::new();
for worker in 0..DRAIN_WORKERS {
let core = core.clone();
workers.push(
std::thread::Builder::new()
.name(format!("pdfs-drain-{worker}"))
.spawn(move || core.run_pending_drain(worker == 0))?,
);
let drain_core = core.clone();
let spawned = std::thread::Builder::new()
.name(format!("pdfs-drain-{worker}"))
.spawn(move || drain_core.run_pending_drain(worker == 0));
keep_or_abandon(&core, control_socket, &mut workers, spawned)?;
}
// Start the folder-sync engine. It watches every mirror folder, polls the
@@ -565,24 +564,22 @@ pub(crate) fn mount_with(
info!("conflict sweep disabled by configuration");
} else {
info!(mode = ?sweep_mode, "conflict sweep enabled");
let core = core.clone();
workers.push(
std::thread::Builder::new()
.name("pdfs-conflict-sweep".into())
.spawn(move || core.run_conflict_sweep_loop())?,
);
let sweep_core = core.clone();
let spawned = std::thread::Builder::new()
.name("pdfs-conflict-sweep".into())
.spawn(move || sweep_core.run_conflict_sweep_loop());
keep_or_abandon(&core, control_socket, &mut workers, spawned)?;
}
// Watch the link for the life of the mount: a mount from the cache waits for
// the network to come back, and an online one can lose it at any moment and
// must notice it coming back just the same.
{
let core = core.clone();
workers.push(
std::thread::Builder::new()
.name("pdfs-online-probe".into())
.spawn(move || core.run_online_probe())?,
);
let probe_core = core.clone();
let spawned = std::thread::Builder::new()
.name("pdfs-online-probe".into())
.spawn(move || probe_core.run_online_probe());
keep_or_abandon(&core, control_socket, &mut workers, spawned)?;
}
// Keep the launcher prompt's "This computer" index fresh. Its own thread:
@@ -593,11 +590,10 @@ pub(crate) fn mount_with(
let transfers = core.transfers.clone();
let mountpoint = mountpoint.to_path_buf();
let shutdown = core.shutdown.clone();
workers.push(
std::thread::Builder::new()
.name("pdfs-localindex".into())
.spawn(move || run_local_index(db, indexing, transfers, mountpoint, shutdown))?,
);
let spawned = std::thread::Builder::new()
.name("pdfs-localindex".into())
.spawn(move || run_local_index(db, indexing, transfers, mountpoint, shutdown));
keep_or_abandon(&core, control_socket, &mut workers, spawned)?;
}
// Bind the control socket before the FUSE session takes over the thread. A
@@ -606,12 +602,18 @@ pub(crate) fn mount_with(
let old_umask = unsafe { libc::umask(0o77) };
let listener_res = UnixListener::bind(control_socket);
unsafe { libc::umask(old_umask) };
let listener = listener_res?;
let listener = match listener_res {
Ok(listener) => listener,
Err(error) => {
abandon_workers(&core, control_socket, workers);
return Err(error);
}
};
// Owner-only before anything can connect: a peer on this socket commands the
// daemon's authenticated session without a credential of its own (B6).
if let Err(e) = pdfs_core::config::restrict_socket(control_socket) {
error!(error = %e, "cannot restrict control socket permissions; refusing to serve");
let _ = std::fs::remove_file(control_socket);
abandon_workers(&core, control_socket, workers);
return Err(std::io::Error::other(format!(
"control socket permissions: {e}"
)));
@@ -622,7 +624,7 @@ pub(crate) fn mount_with(
let bg = match spawn_session(&core, mountpoint, root) {
Ok(session) => session,
Err(error) => {
let _ = std::fs::remove_file(control_socket);
abandon_workers(&core, control_socket, workers);
return Err(error);
}
};
@@ -642,7 +644,7 @@ pub(crate) fn mount_with(
Err(error) => {
// A failure here abandons the mount, so the background threads
// started above have to be told to stop with it.
stop_workers(&core, control_socket, workers);
abandon_workers(&core, control_socket, workers);
let secondaries = core.mounts.lock().close_and_drain();
for (id, mount) in secondaries {
if let Err(unmount_error) = mount.teardown() {
@@ -692,8 +694,12 @@ pub(crate) fn mount_with(
}
}
// The mount is live and the control socket answers: this is the moment the
// unit is actually usable, which is what `Type=notify` reports.
// unit is actually usable, which is what `Type=notify` reports. Whatever
// failure an earlier attempt recorded for the front ends is over.
systemd::ready();
if let Some(state_dir) = control_socket.parent() {
pdfs_core::mountfail::clear(state_dir);
}
// Re-establish on-demand mounts only after the primary session is live.
// Keep the worker so shutdown can close publication, wait for any in-flight
@@ -859,6 +865,43 @@ fn stop_workers(core: &Core, control_socket: &Path, workers: Vec<std::thread::Jo
// Say so before the joins: a teardown that takes a while must not be read as
// a missed watchdog ping and turned into a kill.
systemd::stopping();
halt_workers(core, control_socket, workers);
}
/// Stop the threads a mount attempt started before it failed.
///
/// The early returns used to leave them running: every retry started another
/// set beside the last one's, and their `Core` kept the database open, so the
/// next attempt could fail on its lock instead of the real error
/// (`docs/BUGS.md` B264). Unlike [`stop_workers`] this does not tell systemd
/// the daemon is stopping, because it is about to try again, and a manager
/// told so would wait for the process to exit and then kill it.
fn abandon_workers(core: &Core, control_socket: &Path, workers: Vec<std::thread::JoinHandle<()>>) {
halt_workers(core, control_socket, workers);
}
/// Keep a worker the mount just spawned, or, if the spawn failed, stop the
/// ones already running and hand the error back.
fn keep_or_abandon(
core: &Core,
control_socket: &Path,
workers: &mut Vec<std::thread::JoinHandle<()>>,
spawned: std::io::Result<std::thread::JoinHandle<()>>,
) -> std::io::Result<()> {
match spawned {
Ok(handle) => {
workers.push(handle);
Ok(())
}
Err(error) => {
abandon_workers(core, control_socket, std::mem::take(workers));
Err(error)
}
}
}
/// Signal every worker to stop, then join them up to [`WORKER_JOIN_DEADLINE`].
fn halt_workers(core: &Core, control_socket: &Path, workers: Vec<std::thread::JoinHandle<()>>) {
core.shutdown.stop();
core.wake_drain();
let _ = core.sync_tx.send(sync::SyncMsg::Stop);
+9 -1
View File
@@ -64,11 +64,19 @@ fn send_abstract(socket: &UnixDatagram, name: &str, message: &str) -> bool {
/// so `systemctl --user start` returns when the mount actually works rather than
/// when the process exists.
pub(crate) fn ready() {
if notify("READY=1\n") {
if notify("READY=1\nSTATUS=Mounted\n") {
debug!("notified systemd: ready");
}
}
/// Set the one-line status `systemctl --user status` shows for the unit, such
/// as why the mount keeps failing (`docs/BUGS.md` B263).
pub fn status(text: &str) {
// A newline would end the `STATUS=` line and start another variable.
let line = text.replace('\n', " ");
notify(&format!("STATUS={line}\n"));
}
/// Tell the manager the daemon is still healthy.
pub(crate) fn watchdog_ping() {
let _ = notify("WATCHDOG=1\n");
+29 -7
View File
@@ -1797,13 +1797,35 @@ pub(crate) fn service_unreachable(
);
return;
}
status(
&ui,
"network-idle-symbolic",
&gettext("Connecting…"),
&gettext("Waiting for the Proton Drive service to start."),
false,
);
// Running but not answering may be a mount that fails on every try,
// which never opens the socket. Its reason is in a file the daemon
// keeps for this (B263); "Connecting…" alone looked like a slow start
// for as long as it lasted.
let state_dir = ui.dirs.state_dir();
let failure = gio::spawn_blocking(move || pdfs_core::mountfail::read(&state_dir))
.await
.ok()
.flatten();
match failure {
Some(failure) => status(
&ui,
"dialog-warning-symbolic",
&gettext("Can't open your Drive"),
// Translators: {error} is an error message, in English.
&gettext_f(
"The Proton Drive service keeps failing to start and tries again on its own. The last error was: {error}",
&[("error", &failure.error)],
),
true,
),
None => status(
&ui,
"network-idle-symbolic",
&gettext("Connecting…"),
&gettext("Waiting for the Proton Drive service to start."),
false,
),
}
glib::timeout_add_local_once(CONNECT_RETRY_INTERVAL, move || {
if ui.stack.visible_child_name().as_deref() == Some(page) {
reload(&ui);
+18
View File
@@ -194,6 +194,24 @@ fn poll_state(socket: &Path, default_mountpoint: &Path) -> DriveState {
),
Phase::Attention,
),
// A daemon whose mount fails on every try never opens the
// socket; the app says why (B263).
Ok(s)
if socket
.parent()
.and_then(pdfs_core::mountfail::read)
.is_some() =>
{
(
// Translators: {username} is the Proton account name. The
// service keeps failing to start; the app shows the error.
gettext_f(
"Signed in as {username} — can't open your Drive",
&[("username", &s.username)],
),
Phase::Attention,
)
}
Ok(s) => (
// Translators: {username} is the Proton account name.
gettext_f(