mirror of
https://github.com/narrrl/proton-drive-linux.git
synced 2026-11-04 00:47:00 +01:00
fix(core,fuse): un-park abandoned creates, retire orphan staged bytes, serialise refreshes
Four faults found by reading the journal for issues that were never fixed, tracked as B94-B97 in docs/BUGS.md. A create parked behind a temp-file rename (B70) had no exit but that rename, so 43 uploads sat in the queue for weeks holding their staged bytes. The primary drain worker now sweeps parked creates while the queue is idle: one whose node is gone is discarded, and one older than PARK_EXPIRY_MS that nobody holds open is un-parked rather than dropped, since staged bytes are the only copy of the write. An open node stays parked however old it is. .tmp and .temp leave TRANSIENT_SUFFIXES. The list served two mechanisms with different consequences: ignoring a name during mirror reconcile is reversible, parking a create is not, and a Takeout index.tmp is a final name that nothing will ever rename. Staged blobs that match no queued op and name no node were kept forever and warned about once per blob per mount (95 blobs, ~445 MiB, oldest two months). Blobs past STAGING_ORPHAN_RETAIN are retired; the rest are one aggregated warning. Refresh control requests now run one per scope. Every scope is individually cheap, but duplicates contend for the database lock the running refresh holds, which left five in flight for twenty-three minutes. request_kind names the scope so the report says which view wedged. The photo metadata pass also stops at shutdown instead of running into the cancelled runtime and logging one "skipping undecryptable photo" per node.
This commit is contained in:
1 parent
6cc8f72bab
commit
860d29cfe8
14 files changed
+712
-68
No files matched your search
@@ -56,8 +56,8 @@ pub use local::LocalFileHit;
|
||||
pub use maintenance::{DbStats, VacuumOutcome};
|
||||
pub use nodes::{PublishedSharedRoot, SearchHit, StoredNode};
|
||||
pub use ops::{
|
||||
AttachedBlob, LOCAL_VOLUME, OP_CREATE, OP_MKDIR, OP_RENAME, OP_REVISION, OP_TRASH, PARK_UNTIL,
|
||||
PendingCounts, PendingOp, RenameMeta, op_supersedes,
|
||||
AttachedBlob, LOCAL_VOLUME, OP_CREATE, OP_MKDIR, OP_RENAME, OP_REVISION, OP_TRASH,
|
||||
PARK_EXPIRY_MS, PARK_UNTIL, PendingCounts, PendingOp, RenameMeta, op_supersedes,
|
||||
};
|
||||
pub use photos::{StoredPhoto, THUMB_HAVE, THUMB_NONE, THUMB_UNKNOWN, TimelineRow};
|
||||
pub use pins::PinRow;
|
||||
|
||||
@@ -84,6 +84,25 @@ pub const LOCAL_VOLUME: &str = "local";
|
||||
/// stall+resume, fork a `(sync-conflict)` copy (docs/BUGS.md B70).
|
||||
pub const PARK_UNTIL: i64 = 8_000_000_000_000;
|
||||
|
||||
/// How long a create may stay parked before the park is treated as permanent
|
||||
/// and the bytes are let through anyway (ms).
|
||||
///
|
||||
/// The park has exactly one exit: a rename from the transient name to the
|
||||
/// finished one. Every writer that reaches that rename does so in seconds — an
|
||||
/// atomic-write scratch file immediately, a download when it completes. A park
|
||||
/// still standing an hour later belongs to a writer that will never perform
|
||||
/// that rename: an editor that deletes its swap file instead, a download the
|
||||
/// user abandoned, or a file that simply *is* named `report.tmp` and is never
|
||||
/// going to be called anything else.
|
||||
///
|
||||
/// Before this existed such a row sat at [`PARK_UNTIL`] for the life of the
|
||||
/// database, holding the only copy of the file's bytes in `staging/` and
|
||||
/// counting against the queue while promising progress that could not come. The
|
||||
/// sweep un-parks it instead of dropping it: bytes the user can see in the mount
|
||||
/// are bytes the user expects on Drive, and invariant 1 of the drain (a staged
|
||||
/// blob is dropped only once its op has landed) admits no other answer.
|
||||
pub const PARK_EXPIRY_MS: i64 = 60 * 60 * 1000;
|
||||
|
||||
/// A mutation that has been accepted locally but not yet performed against the
|
||||
/// API — the durable half of the write-back queue (offline.md Phase 3).
|
||||
///
|
||||
@@ -661,6 +680,40 @@ impl Db {
|
||||
Ok(rows)
|
||||
}
|
||||
|
||||
/// Every parked create/mkdir, oldest first, for the park sweep.
|
||||
///
|
||||
/// Parked rows are invisible to [`next_due_op`](Self::next_due_op) by
|
||||
/// construction, so nothing else in the drain ever looks at them. This is
|
||||
/// the one query that does.
|
||||
pub fn parked_create_ops(&self) -> Result<Vec<PendingOp>> {
|
||||
let conn = self.read();
|
||||
let mut stmt = conn.prepare(
|
||||
"SELECT id, kind, uid, parent_uid, name, blob_path, meta_json, created_at,
|
||||
attempts, last_error, next_attempt_at
|
||||
FROM pending_op
|
||||
WHERE next_attempt_at >= ?1 AND kind IN (?2, ?3)
|
||||
ORDER BY created_at",
|
||||
)?;
|
||||
let rows = stmt
|
||||
.query_map(params![PARK_UNTIL, OP_CREATE, OP_MKDIR], |r| {
|
||||
Ok(PendingOp {
|
||||
id: r.get(0)?,
|
||||
kind: r.get(1)?,
|
||||
uid: r.get(2)?,
|
||||
parent_uid: r.get(3)?,
|
||||
name: r.get(4)?,
|
||||
blob_path: r.get(5)?,
|
||||
meta_json: r.get(6)?,
|
||||
created_at: r.get(7)?,
|
||||
attempts: r.get(8)?,
|
||||
last_error: r.get(9)?,
|
||||
next_attempt_at: r.get(10)?,
|
||||
})
|
||||
})?
|
||||
.collect::<std::result::Result<Vec<_>, _>>()?;
|
||||
Ok(rows)
|
||||
}
|
||||
|
||||
/// How many queued ops there are of each kind, for `Response::Status`.
|
||||
///
|
||||
/// Split because "3 uploads queued" has to mean three files whose bytes are
|
||||
|
||||
@@ -3049,6 +3049,57 @@ fn a_parked_transient_create_stays_off_the_drain_until_finalized() {
|
||||
assert_eq!(due.blob_path.as_deref(), Some("/staging/blob1"));
|
||||
}
|
||||
|
||||
/// The park sweep's query: parked creates are the rows nothing else in the drain
|
||||
/// can see, so it has to find them by the sentinel and report how long each has
|
||||
/// been parked. Ordinary queued work is not its business.
|
||||
#[test]
|
||||
fn parked_creates_are_listed_with_the_age_the_sweep_judges_them_by() {
|
||||
let db = Db::open_in_memory().unwrap();
|
||||
let parent = uid("root").to_string();
|
||||
let parked = uid("swap").to_string();
|
||||
let due = uid("ordinary").to_string();
|
||||
for (node, name, next_attempt_at, created_at) in [
|
||||
(&parked, ".notes.txt.swp", PARK_UNTIL, 1_000),
|
||||
(&due, "notes.txt", 0, 2_000),
|
||||
] {
|
||||
db.enqueue_op(&PendingOp {
|
||||
id: 0,
|
||||
kind: OP_CREATE.to_string(),
|
||||
uid: node.clone(),
|
||||
parent_uid: Some(parent.clone()),
|
||||
name: Some(name.to_string()),
|
||||
blob_path: Some(format!("/staging/{name}")),
|
||||
meta_json: None,
|
||||
created_at,
|
||||
attempts: 0,
|
||||
last_error: None,
|
||||
next_attempt_at,
|
||||
})
|
||||
.unwrap();
|
||||
}
|
||||
|
||||
let rows = db.parked_create_ops().unwrap();
|
||||
assert_eq!(rows.len(), 1, "only the parked create is swept");
|
||||
assert_eq!(rows[0].uid, parked);
|
||||
assert_eq!(rows[0].created_at, 1_000, "the park's age is readable");
|
||||
assert_eq!(
|
||||
rows[0].blob_path.as_deref(),
|
||||
Some("/staging/.notes.txt.swp")
|
||||
);
|
||||
|
||||
// What the sweep does with an expired park: un-park it, and it drains like
|
||||
// any other create rather than waiting for a rename that is not coming.
|
||||
assert!(db.set_create_hold(&parked, false).unwrap());
|
||||
assert!(
|
||||
db.parked_create_ops().unwrap().is_empty(),
|
||||
"an un-parked create is no longer the sweep's business"
|
||||
);
|
||||
assert_eq!(
|
||||
db.next_due_op(1_000 + PARK_EXPIRY_MS).unwrap().unwrap().uid,
|
||||
parked
|
||||
);
|
||||
}
|
||||
|
||||
/// Backoff still gates: nothing is returned before an op is due.
|
||||
#[test]
|
||||
fn next_due_op_respects_backoff() {
|
||||
|
||||
@@ -45,18 +45,30 @@ pub const DEFAULT_IGNORE_PATTERNS: &[&str] = &[
|
||||
"Thumbs.db",
|
||||
];
|
||||
|
||||
/// Suffixes of files that are, by convention, incomplete or throwaway while they
|
||||
/// wear the name: a download in flight, an editor's swap or backup, an atomic
|
||||
/// write's scratch copy. On an on-demand mount these should never seal a remote
|
||||
/// revision — the app renames the finished file to its real name, and only that
|
||||
/// belongs on Drive. See [`is_transient_name`] and docs/BUGS.md B70.
|
||||
/// Suffixes that mean a file is incomplete *by construction*: only the program
|
||||
/// writing it gives it this name, only while the write is in flight, and the
|
||||
/// finished article always arrives under a different one. On an on-demand mount
|
||||
/// these should never seal a remote revision — the app renames the finished file
|
||||
/// to its real name, and only that belongs on Drive. See [`is_transient_name`]
|
||||
/// and docs/BUGS.md B70.
|
||||
///
|
||||
/// `.tmp`/`.temp` are deliberately **not** here, though they are in
|
||||
/// [`DEFAULT_IGNORE_PATTERNS`]. The two lists answer different questions. Skipping
|
||||
/// a `report.tmp` during a mirror reconcile costs nothing — the file stays on
|
||||
/// disk, and a later pass picks it up if the rules change. Parking one on the
|
||||
/// on-demand mount is irreversible in practice: the only exit is a rename to a
|
||||
/// finished name, and a file that is simply *called* `index.tmp` — a static-site
|
||||
/// template, a tool's output — never gets one. It then never reaches Drive at
|
||||
/// all, silently, while its bytes pin `staging/`. That is what a real Takeout
|
||||
/// tree of `index.tmp`/`preview.tmp` gallery templates did: 43 creates parked
|
||||
/// forever. The generic-scratch case they were added for renames within
|
||||
/// milliseconds, so it never needed the park; the download suffixes below, which
|
||||
/// stay in flight for minutes, are what B70 was actually about.
|
||||
const TRANSIENT_SUFFIXES: &[&str] = &[
|
||||
".crdownload", // Chromium/Brave/Edge
|
||||
".part", // Firefox, wget, aria2c
|
||||
".partial", // some downloaders / older IE
|
||||
".download", // Safari / macOS
|
||||
".tmp", // generic scratch
|
||||
".temp", // generic scratch
|
||||
".swp", // vim swap
|
||||
".swx", // vim swap (secondary)
|
||||
];
|
||||
@@ -319,8 +331,6 @@ mod tests {
|
||||
"movie.mkv.part",
|
||||
"big.iso.partial",
|
||||
"photo.jpg.download",
|
||||
"export.xml.tmp",
|
||||
"notes.TEMP",
|
||||
".notes.txt.swp",
|
||||
"doc.txt~",
|
||||
".~lock.report.odt#",
|
||||
@@ -340,6 +350,10 @@ mod tests {
|
||||
"archive.partly.zip", // ".partly" is not ".part"
|
||||
"template.dotx",
|
||||
"readme",
|
||||
// A file that is *named* `.tmp` and never renamed: parking it would
|
||||
// keep it off Drive for good.
|
||||
"index.tmp",
|
||||
"notes.TEMP",
|
||||
] {
|
||||
assert!(!is_transient_name(name), "{name} should not be transient");
|
||||
}
|
||||
|
||||
+131
-38
@@ -22,7 +22,7 @@ use pdfs_core::control::{
|
||||
};
|
||||
use pdfs_core::{CoreError, CoreResult};
|
||||
use proton_drive_rs::proton_sdk::ids::NodeUid;
|
||||
use tracing::{info, warn};
|
||||
use tracing::{debug, info, warn};
|
||||
|
||||
use super::transfers::CountingReader;
|
||||
use super::{Core, count_noun, human_bytes, human_duration, parse_uid};
|
||||
@@ -164,6 +164,50 @@ fn rel_to_mount(mountpoint: &Path, path: &str) -> CoreResult<PathBuf> {
|
||||
|
||||
/// Handle one control-socket connection: read a single JSON request line,
|
||||
/// dispatch it against `core`, and write back a JSON response line.
|
||||
/// Refresh scopes being served right now, one entry per running refresh.
|
||||
///
|
||||
/// A `Vec` because there are three scopes and at most `MAX_CONTROL_HANDLERS`
|
||||
/// handlers, so a set would buy nothing.
|
||||
static REFRESHING: std::sync::Mutex<Vec<String>> = std::sync::Mutex::new(Vec::new());
|
||||
|
||||
/// What makes two refreshes the same work: the scope, and for a directory the
|
||||
/// folder, since refreshing one folder says nothing about another. A full
|
||||
/// photos refresh is not the same work as an ordinary one — it forgets what the
|
||||
/// daemon knows first — so it keys apart.
|
||||
fn scope_key(scope: &RefreshScope) -> String {
|
||||
match scope {
|
||||
RefreshScope::Dir { path } => format!("dir:{path}"),
|
||||
RefreshScope::Trash => "trash".to_string(),
|
||||
RefreshScope::Photos { full: true } => "photos:full".to_string(),
|
||||
RefreshScope::Photos { full: false } => "photos".to_string(),
|
||||
}
|
||||
}
|
||||
|
||||
/// Holds one refresh scope for as long as it is being served. `acquire`
|
||||
/// returns `None` when that scope is already in flight.
|
||||
struct RefreshGuard(String);
|
||||
|
||||
impl RefreshGuard {
|
||||
fn acquire(scope: &RefreshScope) -> Option<Self> {
|
||||
let key = scope_key(scope);
|
||||
let mut running = REFRESHING.lock().unwrap_or_else(|e| e.into_inner());
|
||||
if running.contains(&key) {
|
||||
return None;
|
||||
}
|
||||
running.push(key.clone());
|
||||
Some(Self(key))
|
||||
}
|
||||
}
|
||||
|
||||
impl Drop for RefreshGuard {
|
||||
fn drop(&mut self) {
|
||||
let mut running = REFRESHING.lock().unwrap_or_else(|e| e.into_inner());
|
||||
if let Some(at) = running.iter().position(|key| *key == self.0) {
|
||||
running.swap_remove(at);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
fn handle_control_conn(core: &Core, username: &str, mountpoint: &Path, stream: UnixStream) {
|
||||
if let Err(e) = stream.set_read_timeout(Some(CONTROL_READ_TIMEOUT)) {
|
||||
warn!(error = %e, "control: could not set request timeout");
|
||||
@@ -247,45 +291,69 @@ fn handle_control_conn(core: &Core, username: &str, mountpoint: &Path, stream: U
|
||||
},
|
||||
Err(e) => CtlResponse::error(e),
|
||||
},
|
||||
Ok(CtlRequest::Refresh { scope }) => {
|
||||
let result = match &scope {
|
||||
RefreshScope::Dir { path } => route_to_mount(core, mountpoint, path)
|
||||
.and_then(|(core, rel)| core.refresh_dir(&rel)),
|
||||
RefreshScope::Trash => {
|
||||
core.invalidate_trash();
|
||||
Ok(())
|
||||
Ok(CtlRequest::Refresh { scope }) => match RefreshGuard::acquire(&scope) {
|
||||
// The same scope is already being refreshed by another handler.
|
||||
// Running it again cannot make the answer newer, and the duplicate
|
||||
// would spend its whole run contending for the state and database
|
||||
// locks the first one holds — which is how five stacked photo
|
||||
// refreshes sat in flight for twenty-three minutes at mount time.
|
||||
None => {
|
||||
debug!(scope = %scope_key(&scope), "a refresh of this scope is already running");
|
||||
CtlResponse::Ok {
|
||||
message: "refreshing".to_string(),
|
||||
}
|
||||
RefreshScope::Photos { full } => {
|
||||
core.invalidate_photos();
|
||||
// A full refresh is "forget what you know", not a second code
|
||||
// path: the ordinary refresh then finds every photo stale.
|
||||
if let Some(Err(e)) = full.then(|| core.db.photos_mark_all_unresolved()) {
|
||||
warn!(error = %e, "marking the whole timeline unresolved failed");
|
||||
}
|
||||
// Whatever changed the timeline can just as easily have
|
||||
// changed an album; one scope covers the whole photos view.
|
||||
core.invalidate_albums();
|
||||
// The refresh is started here, not awaited. A library of
|
||||
// twelve thousand photos is re-read in chunks of
|
||||
// `TIMELINE_ENRICH_CHUNK` nodes, which takes minutes —
|
||||
// longer than the client's read bound, so awaiting it
|
||||
// returned `Resource temporarily unavailable` to a caller
|
||||
// whose refresh was in fact running fine (B92). The front
|
||||
// end follows it with `PhotosRefreshStatus`.
|
||||
core.spawn_timeline_refresh();
|
||||
Ok(())
|
||||
}
|
||||
};
|
||||
match result {
|
||||
Ok(()) => CtlResponse::Ok {
|
||||
message: match scope {
|
||||
RefreshScope::Photos { .. } => "refreshing".to_string(),
|
||||
_ => "refreshed".to_string(),
|
||||
},
|
||||
},
|
||||
Err(e) => CtlResponse::error(e),
|
||||
}
|
||||
}
|
||||
Some(_refreshing) => {
|
||||
let result = match &scope {
|
||||
RefreshScope::Dir { path } => route_to_mount(core, mountpoint, path)
|
||||
.and_then(|(core, rel)| core.refresh_dir(&rel)),
|
||||
RefreshScope::Trash => {
|
||||
core.invalidate_trash();
|
||||
Ok(())
|
||||
}
|
||||
RefreshScope::Photos { full } if !full && core.timeline_refreshing() => {
|
||||
// A refresh is already running and will publish exactly the
|
||||
// timeline this request asks for. Doing the work again
|
||||
// cannot make it newer, and the invalidation plus the
|
||||
// album read contend with the running refresh for the
|
||||
// database lock — which is how a handful of stacked photo
|
||||
// refreshes at mount time left five control requests
|
||||
// in flight for twenty-three minutes.
|
||||
debug!("a photos refresh is already running; joining it");
|
||||
Ok(())
|
||||
}
|
||||
RefreshScope::Photos { full } => {
|
||||
core.invalidate_photos();
|
||||
// A full refresh is "forget what you know", not a second code
|
||||
// path: the ordinary refresh then finds every photo stale.
|
||||
if let Some(Err(e)) = full.then(|| core.db.photos_mark_all_unresolved()) {
|
||||
warn!(error = %e, "marking the whole timeline unresolved failed");
|
||||
}
|
||||
// Whatever changed the timeline can just as easily have
|
||||
// changed an album; one scope covers the whole photos view.
|
||||
core.invalidate_albums();
|
||||
// The refresh is started here, not awaited. A library of
|
||||
// twelve thousand photos is re-read in chunks of
|
||||
// `TIMELINE_ENRICH_CHUNK` nodes, which takes minutes —
|
||||
// longer than the client's read bound, so awaiting it
|
||||
// returned `Resource temporarily unavailable` to a caller
|
||||
// whose refresh was in fact running fine (B92). The front
|
||||
// end follows it with `PhotosRefreshStatus`.
|
||||
core.spawn_timeline_refresh();
|
||||
Ok(())
|
||||
}
|
||||
};
|
||||
match result {
|
||||
Ok(()) => CtlResponse::Ok {
|
||||
message: match scope {
|
||||
RefreshScope::Photos { .. } => "refreshing".to_string(),
|
||||
_ => "refreshed".to_string(),
|
||||
},
|
||||
},
|
||||
Err(e) => CtlResponse::error(e),
|
||||
}
|
||||
}
|
||||
},
|
||||
Ok(CtlRequest::PhotosTimeline {
|
||||
offset,
|
||||
limit,
|
||||
@@ -1370,3 +1438,28 @@ mod request_limit_tests {
|
||||
assert!(rel_to_mount(mountpoint, "/mnt/elsewhere").is_err());
|
||||
}
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
|
||||
/// Two refreshes of the same scope are one piece of work; two refreshes of
|
||||
/// different scopes are not.
|
||||
#[test]
|
||||
fn a_scope_refreshes_once_at_a_time() {
|
||||
let photos = RefreshScope::Photos { full: false };
|
||||
let held = RefreshGuard::acquire(&photos).expect("first refresh runs");
|
||||
assert!(RefreshGuard::acquire(&photos).is_none());
|
||||
// A full refresh forgets what the daemon knows, so it is other work.
|
||||
assert!(RefreshGuard::acquire(&RefreshScope::Photos { full: true }).is_some());
|
||||
assert!(
|
||||
RefreshGuard::acquire(&RefreshScope::Dir {
|
||||
path: "a".to_string()
|
||||
})
|
||||
.is_some()
|
||||
);
|
||||
|
||||
drop(held);
|
||||
assert!(RefreshGuard::acquire(&photos).is_some());
|
||||
}
|
||||
}
|
||||
@@ -73,7 +73,29 @@ pub(crate) fn request_kind(line: &str) -> String {
|
||||
line.strip_prefix('"')
|
||||
.and_then(|rest| rest.split('"').next())
|
||||
};
|
||||
name.unwrap_or("unknown").to_string()
|
||||
let name = name.unwrap_or("unknown");
|
||||
// A bare `Refresh` says nothing about which view wedged, and the three
|
||||
// scopes cost wildly different amounts of work: a directory refresh is two
|
||||
// cheap calls, a photos refresh can pull a whole library. The scope is one
|
||||
// more peek into the same line.
|
||||
if name == "Refresh"
|
||||
&& let Some(scope) = tagged_name_after(line, "\"scope\"")
|
||||
{
|
||||
return format!("Refresh({scope})");
|
||||
}
|
||||
name.to_string()
|
||||
}
|
||||
|
||||
/// The variant name serde wrote for the value of `key`, whether that value is a
|
||||
/// bare string (a unit variant) or an object whose single key is the name.
|
||||
fn tagged_name_after(line: &str, key: &str) -> Option<String> {
|
||||
let rest = line.split_once(key)?.1.trim_start();
|
||||
let rest = rest.strip_prefix(':')?.trim_start();
|
||||
let rest = rest.strip_prefix('{').map_or(rest, str::trim_start);
|
||||
rest.strip_prefix('"')?
|
||||
.split('"')
|
||||
.next()
|
||||
.map(str::to_string)
|
||||
}
|
||||
|
||||
/// Resident set size in bytes, or `0` when `/proc` did not answer.
|
||||
@@ -181,6 +203,26 @@ mod tests {
|
||||
assert_eq!(request_kind("garbage"), "unknown");
|
||||
}
|
||||
|
||||
/// A stuck `Refresh` is only actionable if the report says which view it
|
||||
/// was refreshing, so the scope rides along with the name.
|
||||
#[test]
|
||||
fn a_refresh_reports_its_scope() {
|
||||
assert_eq!(
|
||||
request_kind("{\"Refresh\":{\"scope\":{\"Photos\":{\"full\":true}}}}"),
|
||||
"Refresh(Photos)"
|
||||
);
|
||||
assert_eq!(
|
||||
request_kind("{\"Refresh\":{\"scope\":{\"Dir\":{\"path\":\"a\"}}}}"),
|
||||
"Refresh(Dir)"
|
||||
);
|
||||
assert_eq!(
|
||||
request_kind("{\"Refresh\":{\"scope\":\"Trash\"}}"),
|
||||
"Refresh(Trash)"
|
||||
);
|
||||
// A shape this does not recognise still names the request.
|
||||
assert_eq!(request_kind("{\"Refresh\":{}}"), "Refresh");
|
||||
}
|
||||
|
||||
/// A guard registers for its lifetime and nothing longer: a handler that
|
||||
/// returns must not leave a permanent "in flight" entry behind.
|
||||
#[test]
|
||||
|
||||
@@ -33,7 +33,9 @@ use futures::StreamExt;
|
||||
use pdfs_core::batch;
|
||||
use pdfs_core::cache::{Baseline, StagedWrite};
|
||||
use pdfs_core::control::{ActivityKind, TransferDirection};
|
||||
use pdfs_core::db::{OP_CREATE, OP_MKDIR, OP_RENAME, OP_REVISION, OP_TRASH, PendingOp, RenameMeta};
|
||||
use pdfs_core::db::{
|
||||
OP_CREATE, OP_MKDIR, OP_RENAME, OP_REVISION, OP_TRASH, PARK_EXPIRY_MS, PendingOp, RenameMeta,
|
||||
};
|
||||
use proton_drive_rs::proton_sdk::error::ProtonError;
|
||||
use proton_drive_rs::proton_sdk::ids::NodeUid;
|
||||
use proton_drive_rs::{Node, NodeMoveItem};
|
||||
@@ -299,6 +301,10 @@ impl Core {
|
||||
// Cheap and a no-op when empty.
|
||||
self.cache.flush_touches();
|
||||
self.recover_fsynced_writes();
|
||||
// Parked rows are invisible to `claim_next_due_op`, so
|
||||
// an idle queue is exactly when a park that has outlived
|
||||
// its writer has to be noticed.
|
||||
self.sweep_parked_creates();
|
||||
}
|
||||
// A debounced or backed-off op may be waiting: sleep only
|
||||
// until it becomes due rather than the full idle-poll.
|
||||
@@ -1201,6 +1207,101 @@ impl Core {
|
||||
Ok(())
|
||||
}
|
||||
|
||||
/// Whether any mount still holds an open handle on `uid`.
|
||||
///
|
||||
/// A transient file that is still open is still being written, however long
|
||||
/// it has been parked, and the rename that finishes it has not happened yet.
|
||||
fn uid_is_open(&self, uid: &NodeUid) -> bool {
|
||||
let mut open = false;
|
||||
self.for_each_state(|st| {
|
||||
if open {
|
||||
return;
|
||||
}
|
||||
open = st
|
||||
.by_uid
|
||||
.get(uid)
|
||||
.and_then(|ino| st.entries.get(ino))
|
||||
.is_some_and(|entry| entry.open_count > 0);
|
||||
});
|
||||
open
|
||||
}
|
||||
|
||||
/// Retire parks that are never going to end (docs/BUGS.md B70).
|
||||
///
|
||||
/// A parked create waits for one event: the rename from the transient name
|
||||
/// to the finished one. Nothing else ever un-parks it, and plenty of writers
|
||||
/// never perform it — an editor unlinks its swap file, a download is
|
||||
/// abandoned, or the file was always going to be called `index.tmp`. Such a
|
||||
/// row stayed at [`PARK_UNTIL`] for the life of the database, pinning the
|
||||
/// only copy of its bytes in `staging/` and counting against the queue.
|
||||
///
|
||||
/// Two outcomes, and neither deletes bytes a user can still see:
|
||||
///
|
||||
/// * The node is gone from the tree — the file was deleted while its create
|
||||
/// was parked, so the create is no longer wanted. The op and its blob go,
|
||||
/// which is what [`Core::discard_queued_ops`] would have done had the
|
||||
/// delete path reached it.
|
||||
/// * The node is still there and has been parked past
|
||||
/// [`PARK_EXPIRY_MS`] with nothing holding it open — the park has outlived
|
||||
/// the writer it was protecting. Un-park it, and the ordinary drain
|
||||
/// uploads it like any other create.
|
||||
///
|
||||
/// An open node is left alone whatever its age: it is still being written.
|
||||
fn sweep_parked_creates(&self) {
|
||||
let parked = match self.db.parked_create_ops() {
|
||||
Ok(parked) if !parked.is_empty() => parked,
|
||||
Ok(_) => return,
|
||||
Err(error) => {
|
||||
warn!(%error, "reading parked creates failed; skipping the park sweep");
|
||||
return;
|
||||
}
|
||||
};
|
||||
let now = now_millis();
|
||||
let (mut released, mut dropped) = (0usize, 0usize);
|
||||
for op in &parked {
|
||||
let Some(uid) = parse_node_uid(&op.uid) else {
|
||||
continue;
|
||||
};
|
||||
let name = op.name.as_deref().unwrap_or("?");
|
||||
let known = match self.db.node_by_uid(&op.uid) {
|
||||
Ok(known) => known.is_some(),
|
||||
// Never infer "deleted" from a failed read: that would discard
|
||||
// the bytes over a transient database error.
|
||||
Err(error) => {
|
||||
debug!(%uid, %error, "cannot tell whether a parked node still exists");
|
||||
continue;
|
||||
}
|
||||
};
|
||||
if !known {
|
||||
if let Err(error) = self.discard_queued_ops(&uid) {
|
||||
warn!(%uid, name, ?error, "dropping a deleted transient's parked create failed");
|
||||
continue;
|
||||
}
|
||||
dropped += 1;
|
||||
debug!(%uid, name, "dropped a parked create whose file was deleted");
|
||||
continue;
|
||||
}
|
||||
if park_verdict(op.created_at, now, self.uid_is_open(&uid)) != ParkVerdict::Release {
|
||||
continue;
|
||||
}
|
||||
match self.db.set_create_hold(&op.uid, false) {
|
||||
Ok(true) => {
|
||||
released += 1;
|
||||
info!(%uid, name, parked_ms = now - op.created_at,
|
||||
"un-parked a transient create that was never renamed; uploading it");
|
||||
}
|
||||
Ok(false) => {}
|
||||
Err(error) => warn!(%uid, name, %error, "un-parking an expired park failed"),
|
||||
}
|
||||
}
|
||||
if released > 0 || dropped > 0 {
|
||||
info!(released, dropped, "swept parked creates");
|
||||
}
|
||||
if released > 0 {
|
||||
self.wake_drain();
|
||||
}
|
||||
}
|
||||
|
||||
/// Drop `uid`'s pending entry, but only while it still names `blob`.
|
||||
///
|
||||
/// A supersede can replace the entry while the op that owned it is in
|
||||
@@ -1573,6 +1674,24 @@ fn is_own_self_supersede(complete: bool, remote_rev: Option<&str>, own_rev: Opti
|
||||
complete && remote_rev.is_some() && remote_rev == own_rev
|
||||
}
|
||||
|
||||
/// What the park sweep does with one parked create whose node still exists.
|
||||
#[derive(Debug, PartialEq, Eq)]
|
||||
enum ParkVerdict {
|
||||
/// Leave it parked: the rename it waits for can still come.
|
||||
Keep,
|
||||
/// Un-park it: nothing will rename it now, so the bytes go up as they are.
|
||||
Release,
|
||||
}
|
||||
|
||||
/// Judge one parked create by age alone. An open node is kept whatever its age
|
||||
/// — it is still being written, and the rename is the writer's last step.
|
||||
fn park_verdict(created_at: i64, now: i64, open: bool) -> ParkVerdict {
|
||||
if open || now - created_at < PARK_EXPIRY_MS {
|
||||
return ParkVerdict::Keep;
|
||||
}
|
||||
ParkVerdict::Release
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
@@ -1598,6 +1717,28 @@ mod tests {
|
||||
}
|
||||
}
|
||||
|
||||
/// The park's only ordinary exit is the transient-to-final rename. The
|
||||
/// sweep is what happens when that rename never comes.
|
||||
#[test]
|
||||
fn a_park_expires_only_once_it_is_old_and_nobody_holds_the_file() {
|
||||
let now = PARK_EXPIRY_MS * 10;
|
||||
// Fresh: the writer may still rename it.
|
||||
assert_eq!(
|
||||
park_verdict(now - PARK_EXPIRY_MS + 1, now, false),
|
||||
ParkVerdict::Keep
|
||||
);
|
||||
// Old, but still open: a slow write is not an abandoned one.
|
||||
assert_eq!(
|
||||
park_verdict(now - PARK_EXPIRY_MS, now, true),
|
||||
ParkVerdict::Keep
|
||||
);
|
||||
// Old and closed: no rename is coming.
|
||||
assert_eq!(
|
||||
park_verdict(now - PARK_EXPIRY_MS, now, false),
|
||||
ParkVerdict::Release
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn drain_authorities_match_each_operation_kind() {
|
||||
for kind in [OP_REVISION, OP_TRASH] {
|
||||
|
||||
+109
-10
@@ -197,6 +197,22 @@ const UPLOAD_TIME_MEMORY: usize = 512;
|
||||
/// for the SDK's own per-request concurrency.
|
||||
const DRAIN_WORKERS: usize = 3;
|
||||
|
||||
/// How long a staged blob that names no node is kept before it is retired.
|
||||
///
|
||||
/// Staging is exempt from the cache budget because it holds the only copy of
|
||||
/// writes that have not been uploaded, so nothing there is ever evicted to
|
||||
/// reclaim space. That is right for a blob that still describes something. It is
|
||||
/// wrong for one whose sidecar is missing or names a `local~` placeholder whose
|
||||
/// create is gone: no future run can address it, no UI accounts for it, and it
|
||||
/// occupies disk for the life of the machine. Real instance: 95 such blobs,
|
||||
/// ~445 MiB, the oldest two months old, re-announced on every mount.
|
||||
///
|
||||
/// A month is far longer than any transfer or any plausible "I will look at that
|
||||
/// later", and the retirement is announced per blob with its size, so the one
|
||||
/// case that matters — bytes a human still wants — has a month of warnings and a
|
||||
/// path to go and fetch them from.
|
||||
const STAGING_ORPHAN_RETAIN: Duration = Duration::from_secs(30 * 24 * 60 * 60);
|
||||
|
||||
const ONLINE_PROBE_MIN: Duration = Duration::from_secs(5);
|
||||
const ONLINE_PROBE_MAX: Duration = Duration::from_secs(300);
|
||||
/// How long the persisted photos timeline stays good before a page request
|
||||
@@ -1394,6 +1410,15 @@ fn release_must_retain_queued_trash(db: &Db, uid: &NodeUid) -> pdfs_core::Result
|
||||
db.has_pending_op(&uid.to_string(), OP_TRASH)
|
||||
}
|
||||
|
||||
/// The size of a staged blob that has outlived [`STAGING_ORPHAN_RETAIN`], or
|
||||
/// `None` while it is younger than that — or while its age cannot be read at
|
||||
/// all, which is never grounds for deleting bytes.
|
||||
fn orphan_past_retention(blob: &Path) -> Option<u64> {
|
||||
let meta = std::fs::metadata(blob).ok()?;
|
||||
let age = meta.modified().ok()?.elapsed().ok()?;
|
||||
(age >= STAGING_ORPHAN_RETAIN).then_some(meta.len())
|
||||
}
|
||||
|
||||
fn release_can_discard_unlinked(db: &Db, uid: &NodeUid) -> bool {
|
||||
match release_must_retain_queued_trash(db, uid) {
|
||||
Ok(retain) => !retain,
|
||||
@@ -1718,6 +1743,9 @@ impl Core {
|
||||
};
|
||||
let mut queued = 0usize;
|
||||
let mut stranded = 0usize;
|
||||
let mut retired = 0usize;
|
||||
let mut retired_bytes = 0u64;
|
||||
let mut example: Option<PathBuf> = None;
|
||||
for (blob, meta) in staged {
|
||||
if claimed.contains(&blob.to_string_lossy().into_owned()) {
|
||||
continue;
|
||||
@@ -1725,9 +1753,17 @@ impl Core {
|
||||
let addressable = meta.as_ref().and_then(|m| parse_node_uid(&m.uid));
|
||||
let Some((meta, uid)) = meta.zip(addressable).filter(|(_, uid)| !is_local_uid(uid))
|
||||
else {
|
||||
if let Some(bytes) = orphan_past_retention(&blob) {
|
||||
retired += 1;
|
||||
retired_bytes += bytes;
|
||||
warn!(blob = %blob.display(), bytes,
|
||||
age_days = STAGING_ORPHAN_RETAIN.as_secs() / 86_400,
|
||||
"retiring staged bytes that name no node and have outlived retention");
|
||||
self.cache.discard_staged(&blob);
|
||||
continue;
|
||||
}
|
||||
stranded += 1;
|
||||
warn!(blob = %blob.display(),
|
||||
"staged bytes belong to no queued upload and name no node; kept for recovery");
|
||||
example.get_or_insert_with(|| blob.clone());
|
||||
continue;
|
||||
};
|
||||
if self.pending.lock().contains_key(&uid) {
|
||||
@@ -1773,8 +1809,21 @@ impl Core {
|
||||
}
|
||||
}
|
||||
}
|
||||
if queued > 0 || stranded > 0 {
|
||||
info!(queued, stranded, "reconciled orphaned staged writes");
|
||||
if stranded > 0 {
|
||||
// One line, not one per blob. A tree of them says exactly as much as
|
||||
// a single count and an example does, and said it on every mount:
|
||||
// 86 identical warnings for the same 86 files, boot after boot.
|
||||
warn!(
|
||||
count = stranded,
|
||||
example = %example.map(|b| b.display().to_string()).unwrap_or_default(),
|
||||
"staged bytes belong to no queued upload and name no node; kept for recovery"
|
||||
);
|
||||
}
|
||||
if queued > 0 || stranded > 0 || retired > 0 {
|
||||
info!(
|
||||
queued,
|
||||
stranded, retired, retired_bytes, "reconciled orphaned staged writes"
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -6124,14 +6173,64 @@ mod tests {
|
||||
Access, AccessFlags, Errno, HashMap, Intervals, PendingRevision, RootListingSnapshot,
|
||||
SELF_CHANGE_TTL_MS, ShareId, SharedWithMeItem, StateRegistry, VirtualRootPlan,
|
||||
accepted_share_provenance, conflict_name, copy_pending_for_truncate, expand_restore,
|
||||
fuse_name, is_stale_mount, node_visible, note_self_change, parse_node_uid,
|
||||
prepare_shared_roots, preserve_on_access_denied, publish_virtual_root_in_listing,
|
||||
reconcile_virtual_root_in_listing, release_can_discard_unlinked,
|
||||
release_must_retain_queued_trash, release_unlinked_entry, rename_needs_queue,
|
||||
require_node_parent_access, require_rename_access, resolve_anywhere_with,
|
||||
shared_with_me_uid, take_self_change, uid_write_authority, virtual_node,
|
||||
fuse_name, is_stale_mount, node_visible, note_self_change, orphan_past_retention,
|
||||
parse_node_uid, prepare_shared_roots, preserve_on_access_denied,
|
||||
publish_virtual_root_in_listing, reconcile_virtual_root_in_listing,
|
||||
release_can_discard_unlinked, release_must_retain_queued_trash, release_unlinked_entry,
|
||||
rename_needs_queue, require_node_parent_access, require_rename_access,
|
||||
resolve_anywhere_with, shared_with_me_uid, take_self_change, uid_write_authority,
|
||||
virtual_node,
|
||||
};
|
||||
use super::{Db, WriteAuthority};
|
||||
use std::time::Duration;
|
||||
|
||||
/// Staged bytes that name no node are kept for a month, because the only
|
||||
/// copy of a write must outlive the bug that stranded it. Past that, one
|
||||
/// boot retires them instead of re-announcing them every boot forever.
|
||||
#[test]
|
||||
fn a_stranded_blob_is_retired_only_once_it_outlives_retention() {
|
||||
let dir = std::env::temp_dir().join(format!("pdfs-orphan-{}", std::process::id()));
|
||||
std::fs::create_dir_all(&dir).unwrap();
|
||||
let blob = dir.join("blob");
|
||||
std::fs::write(&blob, b"twelve bytes").unwrap();
|
||||
|
||||
// Written just now: still recoverable, still kept.
|
||||
assert_eq!(orphan_past_retention(&blob), None);
|
||||
|
||||
set_mtime_ago(
|
||||
&blob,
|
||||
super::STAGING_ORPHAN_RETAIN + Duration::from_secs(60),
|
||||
);
|
||||
assert_eq!(orphan_past_retention(&blob), Some(12));
|
||||
|
||||
// A blob that is not there is not a blob to retire.
|
||||
std::fs::remove_file(&blob).unwrap();
|
||||
assert_eq!(orphan_past_retention(&blob), None);
|
||||
let _ = std::fs::remove_dir_all(&dir);
|
||||
}
|
||||
|
||||
/// Backdate a file's mtime, which is what the retention check reads.
|
||||
fn set_mtime_ago(path: &std::path::Path, ago: Duration) {
|
||||
let when = std::time::SystemTime::now() - ago;
|
||||
let secs = when
|
||||
.duration_since(std::time::UNIX_EPOCH)
|
||||
.unwrap()
|
||||
.as_secs() as libc::time_t;
|
||||
let times = [
|
||||
libc::timeval {
|
||||
tv_sec: secs,
|
||||
tv_usec: 0,
|
||||
},
|
||||
libc::timeval {
|
||||
tv_sec: secs,
|
||||
tv_usec: 0,
|
||||
},
|
||||
];
|
||||
let c_path = std::ffi::CString::new(path.as_os_str().as_encoded_bytes()).unwrap();
|
||||
// SAFETY: both pointers are valid for the call and nothing keeps them.
|
||||
let rc = unsafe { libc::utimes(c_path.as_ptr(), times.as_ptr()) };
|
||||
assert_eq!(rc, 0, "utimes: {}", std::io::Error::last_os_error());
|
||||
}
|
||||
|
||||
/// `(uid, parent)` pairs in the shape [`Db::trash_parents`] returns.
|
||||
fn relations(pairs: &[(&str, Option<&str>)]) -> Vec<(String, Option<String>)> {
|
||||
|
||||
@@ -1450,7 +1450,18 @@ impl Core {
|
||||
// so the relation is recorded from whichever end resolves — the two ends
|
||||
// can land in different chunks, and one of them may not resolve at all.
|
||||
let mut main_of: HashMap<String, String> = HashMap::new();
|
||||
let mut stopped = false;
|
||||
for chunk in uids.chunks(TIMELINE_ENRICH_CHUNK) {
|
||||
// Teardown cancels the runtime under this loop, and every chunk
|
||||
// still in flight then fails its decrypt task — a burst of
|
||||
// "skipping undecryptable photo ... task was cancelled" warnings
|
||||
// that read like corruption and are only a shutdown. Stop asking
|
||||
// for chunks instead. What resolved so far is kept below; the rest
|
||||
// stay unresolved and are read by the next refresh.
|
||||
if self.shutdown.is_stopping() {
|
||||
stopped = true;
|
||||
break;
|
||||
}
|
||||
match photos.enumerate_nodes(chunk).await {
|
||||
Ok(nodes) => {
|
||||
for node in nodes {
|
||||
@@ -1521,10 +1532,14 @@ impl Core {
|
||||
// like it never happened, and the chunk count is what it scales with.
|
||||
info!(
|
||||
photos = rows.len(),
|
||||
resolved = uids.len(),
|
||||
// `resolved` is what came back, which is short of `wanted` when
|
||||
// shutdown cut the pass off or a chunk failed.
|
||||
resolved = meta.len(),
|
||||
wanted = uids.len(),
|
||||
skipped = rows.len().saturating_sub(uids.len()),
|
||||
chunks = uids.len().div_ceil(TIMELINE_ENRICH_CHUNK),
|
||||
elapsed_ms = started.elapsed().as_millis() as u64,
|
||||
stopped,
|
||||
"photos timeline refreshed"
|
||||
);
|
||||
Ok(true)
|
||||
|
||||
Reference in new issue
Block a user