Skip to content

Commit f951cde

Browse files
pmaxhoganclaude
andauthored
fix(app): never freeze on tray quit during a backup; quitting tray state; honest recovery status (#312)
Closes #299 Closes #300 Closes #301 PR1 of the v2.12.0 wave. ## Diagnosis ### #299 - tray quit freezes the app (and trips WER) during a backup Root cause: **the graceful drain ran on the platform event-loop thread.** `tray.rs` `menu_id::QUIT` -> `app.exit(0)` -> `RunEvent::ExitRequested` -> `shutdown_orchestrators()`, which drove the whole drain inline via `tauri::async_runtime::block_on`. `block_on` blocks the *calling* thread, and the `RunEvent` callback runs on the main thread that owns the Win32 message pump. So the pump stalls for the entire drain budget: `RUN_LOOP_DRAIN_TIMEOUT` is 20s and graceful orchestrator shutdown is only observed *between* cycles, so quitting mid-backup reliably parks there. Windows ghosts a window that has not pumped for ~5s, paints "Not Responding", and Windows Error Reporting kills the process. Evidence, from the owner's machine (maxbook, Windows 11 26200): - Event Log, `Application Hang` provider: - `8/16/2026 10:49:23 AM` - "The program driven-app.exe version 2.11.2.0 stopped interacting with Windows and was closed." - plus two more for 2.10.1.0 / 2.10.0.0 on 8/14. `AppHangB1` is the blocked-message-pump signature, not a crash. - `driven-diagnostics-hung-on-starting-backup.zip`, `logs/driven.2026-08-16.log`: ``` 15:49:09.170Z INFO driven::app: explicit quit; draining orchestrators 15:49:09.170Z INFO driven::app: signalling graceful shutdown on quit account_id=... 15:49:29.415Z INFO driven::logging: rolling file logs active <- a NEW process ``` The hang event lands 14s into that gap (10:49:23 local == 15:49:23Z). The quitting process never wrote `all per-account tasks shut down (no orphans)` - it was killed mid-drain. Same shape on the second quit: `15:52:59.576Z` quit -> new process at `15:53:12.858Z`. So the freeze did not even buy the graceful semantics it was blocking for: the drain is killed before it finishes and the run loop dies hard anyway. ### #301 - ~1 minute of opaque "Starting backup" Two independent defects, both visible in the same log: ``` 15:53:34.330Z cycle start tick=Manual 15:53:34.330Z state transition state="power_check" 15:53:34.735Z reconcile: recovering pending ops pending_ops=18 15:54:39.929Z state transition state="scanning" <- 65.2s later ``` 1. **Serial round trips.** `reconcile_inner` walks pending ops strictly one at a time, and every op costs at least one Drive metadata round trip (`metadata` by id for the update path, `find_by_op_uuid` under a re-derived parent for the create path). 65.2s / 18 ops == ~3.6s per op, which is a normal Drive `files.list` latency. An earlier run in the same log shows the same 60.0s shape. 2. **No status at all.** `OrchestratorState::Recovering` was emitted *only* from the byte-level resume branch, via the `on_recover` sink. The 18 plain adopt-or-requeue ops move no bytes, so they emitted nothing and the orchestrator stayed on `PowerCheck` for the whole pass - which is the generic "Starting backup..." the user saw. (In the 15:49 run, where one op *did* carry a resumable session, `Recovering` did appear - for 2 of the 32 seconds - which is why the bug looked intermittent.) ## What changed ### #299 quit never blocks the event loop - `lib.rs`: `shutdown_orchestrators` is split into `take_shutdown_handles` (synchronous, cheap - every call is a mutex-take or a watch-send, no await, no I/O) and `async fn drain_shutdown_handles` (the unchanged drain body). - `begin_graceful_quit` hides the window and repaints the tray synchronously (single fast platform calls - the window disappearing is the whole point of clicking Quit), then **spawns** the drain on the Tauri async runtime and returns. The event loop keeps pumping for the entire drain, so the app can never be declared hung. - `RunEvent::ExitRequested` becomes a three-phase machine on a process-global `QUIT_PHASE`: - `IDLE` -> `prevent_exit()`, start the drain, return at once; - `DRAINING` -> a second explicit quit (repeat `--quit`, OS session end) is prevented and ignored; "Force quit now" is the deliberate escape hatch; - `READY` -> not prevented, so the process exits. The drain sets `READY` and calls `app.exit(0)` itself when it is genuinely done. - The cancellation-safety invariants documented at the old `lib.rs:228-238` and `app_state.rs:209-215` are preserved verbatim: still no outer `tokio::time::timeout` around the cancellation-UNSAFE `AccountHandle::shutdown` sweep, still `join_all` for concurrency, still `drain_or_abort`'s self-bounding await-then-abort-and-await per handle. The VSS/APFS broker shutdowns still run *after* the orchestrator drain, now at the tail of the spawned task. ### #300 quitting tray state - New `TrayIcon::Quitting`: slate (`#71717a`) badge with a white **stop square** glyph. The approved mockup used amber; amber is already spent on `Paused` and `NetworkAttention`, and "quitting" must not read as "paused, still running". Slate is the only desaturated badge in the set, and the stop square is what carries the state on the macOS template path where hue is discarded entirely. - Tooltip `tray.tooltip.quitting`: "Driven - quitting (finishing backup, right-click to force quit)". - `tray::enter_quitting` swaps the menu for a two-item one: a **disabled** status line "Quitting - finishing current backup..." and a single enabled "Force quit now". Every normal action is deliberately gone - they would all queue work against orchestrators that are already winding down. - `crate::force_quit` marks the phase `READY` and exits immediately. This is safe to do hard: the streaming resumable uploader persists `resumable.acked_offset` into the pending op's payload after **every** acked wire chunk (`executor.rs` `push_one`), so the next launch's reconcile resumes from the last acked byte and at most one wire chunk is re-sent. Restore jobs stage into a temp that is never promoted, so a kill cannot publish a partial file. - `apply_state` returns before touching the tray while quitting (the run loop is still finishing its cycle and keeps emitting transitions, which would otherwise repaint the spinner over the quitting icon), and skips the OS notification too - a "first sync complete" toast while the app is closing is noise. The aggregate per-account map is still updated. - The macOS menu bar title engine clears its title once and stops ticking while quitting, so a live "12.3 MB/s, 4 min left" cannot contradict the icon. ### #301 faster recovery + honest status - `RECONCILE_LOOKUP_CONCURRENCY = 6`. `prefetch_reconcile_lookups` runs the adopt-or-requeue lookups through `buffer_unordered` ahead of the unchanged sequential decision pass. - Independence: `remote.metadata` and `find_by_op_uuid` are pure reads; the create path's parent walk (`ensure_parents_once`) is idempotent AND already single-flighted behind `parent_walk` with a per-source `parent_dirs` cache, built precisely so concurrent uploads into one new directory cannot race duplicate `ensure_folder` calls. **Nothing in the prefetch touches the state DB.** - Durability is unchanged: every `delete_pending_op` / `adopt_reconciled` / `clear_file_state_drive_file_id` still runs one at a time, in the original op order, in the sequential pass - no whole-batch buffering (the 2026-08-14 OOM incident was reconcile buffering too much, so this deliberately buffers only lookup *results*). - Pacing is unchanged: each lookup still takes `pacer.permit_request()` and reports its `ResponseClass`, so a rate limit or an open circuit breaker still gates the pass. The accounting simply moved into the two lookup helpers alongside the calls. - Fail-fast: the sequential pass aborts the source's reconcile on the first *retryable* lookup error, so prefetching could turn one failed request during a Drive outage into N. The first future to see one sets a halt flag; every not-yet-started future returns `None`, and the pass makes that one lookup inline and hits the same abort. - Excluded from the prefetch: ops carrying a live `resumable` session (they stream a whole file and own the byte ticks, so they stay strictly sequential; their fall-through lookup when a session is stale is done inline) and ops with no `client_op_uuid`. - `OrchestratorState::Recovering` gains `ops_done` / `ops_total`, fed by a new OP flavour of `RecoverProgress` emitted once before the first round trip and once per recovered op. `reconcile_inner` stamps the pass's live counters onto **every** tick, byte ticks included, so the deep resume call sites did not have to thread them down. The orchestrator's existing ~1/s throttle now treats "final" as both dimensions being complete. - UI: `progress.recoveringOps`, a determinate percent from the op counters when no bytes are moving, and the label "Recovering - resuming 7 of 18 uploads". ## Test results All run locally on the Mac unless noted. - `cargo test -p driven-core --lib` - **559 passed, 0 failed** - `cargo test -p driven-app` - **442 + 6 + 3 passed, 0 failed** - `cargo clippy --workspace --all-targets -- -D warnings` - clean - `cargo fmt --all --check` - clean - `pnpm -C ui run test:unit` - **793 passed** (59 files) - `pnpm -C ui run build` (vue-tsc + vite) - clean - `pnpm -C ui run lint` - 0 errors (35 pre-existing unused-i18n-key warnings) - `pnpm -C ui run format:check` - clean - **On real Windows** (maxbook, `x86_64-pc-windows-msvc`, worktree at `V:\driven-agents\wave1`): `cargo check -p driven-app --lib` and `cargo clippy -p driven-app -p driven-core --all-targets -- -D warnings` both exit 0. (Cross-compiling from macOS is not possible - `ring`/`aws-lc-sys` need a Windows C toolchain - so this was checked on the machine itself. Note: building this repo on maxbook now needs NASM for `aws-lc-sys` 0.43, pulled in by the dependabot bumps on main; I installed it via `winget install NASM.NASM`.) New tests: - `executor::reconcile_lookups_run_concurrently_and_report_op_progress` - 12 ops against a fake store with a fixed 120ms per-request delay. A serial pass has a hard floor of 1440ms; the assertion is `< 720ms`, and two concurrent rounds land near 240ms. **This fails if the prefetch is removed or silently serialised** - it is not a sleep-and-hope timing test. Also asserts the first tick announces `0 of 12` before any lookup, every tick carries the total, the final tick reports `12 of 12`, and `ops_done` is monotonic. - `executor::reconcile_with_no_pending_ops_emits_no_op_ticks` - a clean boot stays free (no transition churn). - `executor::reconcile_lookup_classifies_which_failures_halt_the_prefetch` - transient metadata/orphan failures and a parent-walk failure halt; a definitive not-found does not (it is per-op and the pass continues). - `executor::resume_emits_recover_progress_ticks` updated for the new tick stream (byte ticks are now those with a non-zero total; op counters asserted on every tick). - tray: `TrayIcon::Quitting` added to every exhaustive icon test - distinct colour, distinct glyph, badge actually painted, static across frames, brand dimensions, and the macOS template `STATES` set. - i18n: `tray.quitting_status`, `tray.force_quit`, `tray.tooltip.quitting` added to both the exact-label and the no-raw-key sweeps. - UI: op-counter percent, byte-over-op precedence, cross-account summing, and the new progress-bar label. ## README Updated in this PR (repo rule): - the resumable-upload bullet now covers the op-count readout and the concurrent startup recovery; - a new bullet documents that quit never freezes, the quitting tray icon, and "Force quit now". ## Remaining QA on maxbook (for the team lead, after a dev build exists) The unit + Windows-toolchain checks above cannot exercise the message pump, so these need the installed/dev app on maxbook: 1. **#299 primary repro.** Start a backup with real work in flight (the existing source has multi-GB files), then Quit from the tray. Expect: the window disappears immediately, the app stays responsive, the process lives until the drain finishes, and the log ends with `all per-account tasks shut down (no orphans)` -> `graceful quit drain complete; exiting`. Then confirm **no new** `Application Hang` event: `Get-WinEvent -FilterHashtable @{LogName='Application'; ProviderName='Application Hang'} -MaxEvents 5` 2. **#300 tray affordance.** During that drain, check the tray icon changed to the slate stop badge, hover for the tooltip, and right-click: the menu must be exactly the disabled "Quitting - finishing current backup..." plus "Force quit now". 3. **#300 force quit.** Repeat, then click "Force quit now" mid-drain. Expect an immediate exit, and on the next launch the log shows `reconcile: resuming persisted resumable upload (streaming re-read)` with a `resume_from` at or near where it was killed (not 0). 4. **#301 timing.** With a backlog of pending ops (the diag bundle showed 18-22), time from `reconcile: recovering pending ops` to the first `state transition state="scanning"`. Baseline was 65.2s; expect roughly a sixth of the round-trip time. During it, the app should read "Recovering - resuming N of M uploads" with a moving determinate bar, never a generic "Starting backup...". 5. Sanity: quit with **nothing** running still exits promptly. Not merged - the team lead babysits the merge. --- ## Follow-up commit: coverage The first push failed the `coverage` gate at Rust 84.43% vs main 84.56% (epsilon 0.1pp) - the new prefetch error branches had no tests behind them. `be55fe9` fixes that: - `ReconcileLookup` drops its `ParentFailed` variant in favour of a nested `Orphan(Result<Result<..>>)` (outer = the parent walk, inner = `find_by_op_uuid`). That removes the one defensive-but-unreachable arm the first shape needed - the create branch is selected by the *absence* of a recorded `drive_file_id`, so the "not prefetched" fallback covers it. - `reconcile_parent_walk_failure_aborts_the_pass_and_keeps_every_op` - 8 nested create ops against a store whose `ensure_folder` always fails. Covers the parent-walk propagation, the halt classifier's `Orphan(Err)` arm, and (with more ops than the concurrency bound) the prefetch's halt branch, and asserts every op is kept. - `reconcile_adopts_an_update_whose_object_already_carries_the_op_uuid` - the UPDATE path's *successful* metadata lookup, which had no test at all before. All 17 checks green on `be55fe9`; `mergeStateStatus: CLEAN`. Windows `cargo test + clippy` passes, so the concurrency timing assertion is not flaky on the slowest runner. --------- Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
1 parent e6427c7 commit f951cde

13 files changed

Lines changed: 1304 additions & 188 deletions

File tree

README.md

Lines changed: 10 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -142,8 +142,12 @@ These move: check each project's current docs before relying on a cell.
142142
rules are later edited. Genuinely overlapping sources are still rejected.
143143
- Concurrent, paced executor with retries and resumable uploads. An upload
144144
interrupted by a quit or crash resumes byte-for-byte across restarts, with
145-
the recovery shown live in the app ("Recovering interrupted upload - 8.2 GB
146-
of 88.6 GB") instead of an unlabeled startup phase.
145+
the recovery shown live in the app - both the per-file byte progress
146+
("Recovering interrupted upload - 8.2 GB of 88.6 GB") and, while the recovery
147+
works through the interrupted uploads themselves, the op counts
148+
("Recovering - resuming 7 of 18 uploads") - instead of an unlabeled startup
149+
phase. The startup recovery runs its remote lookups concurrently, so a large
150+
backlog of interrupted uploads no longer delays the first scan by a minute.
147151
- Configurable OS priority (`low` by default) for the scan, upload reads, and
148152
bundle builds, so backups yield CPU and disk to whatever is in the foreground.
149153
- Battery and network awareness: backups defer on battery and on metered or
@@ -155,6 +159,10 @@ These move: check each project's current docs before relying on a cell.
155159
- macOS menu bar live status: configurable metrics next to the tray icon while
156160
backing up (upload speed, percent, files, time remaining) and a configurable
157161
idle readout (last backup age or today's uploaded total).
162+
- Quit never freezes the app. Quitting mid-backup hides the window instantly and
163+
lets the current cycle finish in the background; the tray shows a distinct
164+
"quitting" icon, and its menu offers "Force quit now" if you would rather not
165+
wait (in-flight uploads resume from where they stopped on the next launch).
158166
- Settings organized as a sidebar of focused pages (General, Schedule & Power,
159167
Performance, a macOS/Windows platform page, Network, Privacy & Data,
160168
Advanced) with search; About is identity-only, reached from the sidebar

crates/driven-core/src/executor.rs

Lines changed: 702 additions & 54 deletions
Large diffs are not rendered by default.

crates/driven-core/src/orchestrator.rs

Lines changed: 19 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1358,8 +1358,19 @@ impl SyncOrchestrator {
13581358
let now = self.clock.now_ms();
13591359
{
13601360
let mut guard = last_emit.lock().await;
1361+
// Issue #301: the pass now emits an OP tick per
1362+
// recovered pending op as well as the BYTE ticks of
1363+
// a streaming resume, so "is this the final tick"
1364+
// has to consider BOTH dimensions - a byte tick that
1365+
// finished its file is not final if ops remain, and
1366+
// an op tick (which carries 0/0 bytes) is final only
1367+
// once every op is done. Anything else throttles to
1368+
// ~1/s on the INJECTED clock (the module's
1369+
// determinism rule - never tokio/Instant time).
1370+
let is_final =
1371+
p.bytes_done >= p.bytes_total && p.ops_done >= p.ops_total;
13611372
let throttled = matches!(*guard, Some(last) if now - last < RECOVER_EMIT_MIN_INTERVAL_MS)
1362-
&& p.bytes_done < p.bytes_total;
1373+
&& !is_final;
13631374
if throttled {
13641375
return;
13651376
}
@@ -1370,6 +1381,8 @@ impl SyncOrchestrator {
13701381
path: p.path,
13711382
bytes_done: p.bytes_done,
13721383
bytes_total: p.bytes_total,
1384+
ops_done: p.ops_done,
1385+
ops_total: p.ops_total,
13731386
})
13741387
.await;
13751388
})
@@ -3883,11 +3896,11 @@ mod tests {
38833896
if ticks > 1 {
38843897
let total = 1_000u64;
38853898
for i in 0..ticks {
3886-
on_recover(crate::executor::RecoverProgress {
3887-
path: "big/file.bin".to_string(),
3888-
bytes_done: i * total / (ticks - 1),
3889-
bytes_total: total,
3890-
})
3899+
on_recover(crate::executor::RecoverProgress::bytes(
3900+
"big/file.bin".to_string(),
3901+
i * total / (ticks - 1),
3902+
total,
3903+
))
38913904
.await;
38923905
}
38933906
}

crates/driven-core/src/types.rs

Lines changed: 22 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -480,22 +480,35 @@ pub enum OrchestratorState {
480480
/// Checking the power / network gates (DESIGN s5.7) before starting a
481481
/// batch. A failed gate transitions to [`OrchestratorState::Paused`].
482482
PowerCheck,
483-
/// The startup reconcile is recovering an interrupted upload by
484-
/// byte-level resume (2026-08-14 follow-up): re-reading the local file
485-
/// and pushing the unacked tail. Previously this ran invisibly inside
486-
/// [`OrchestratorState::PowerCheck`] - for the incident's 88 GB disk
487-
/// image that meant a multi-minute "Starting backup..." sweep while
488-
/// 140 Mbps of upload showed nowhere in the UI.
483+
/// The startup reconcile is recovering interrupted work (2026-08-14
484+
/// follow-up; issue #301): adopting or re-queuing each pending op, and
485+
/// byte-level resuming any op that carries a live upload session.
486+
/// Previously this ran invisibly inside [`OrchestratorState::PowerCheck`] -
487+
/// for the incident's 88 GB disk image that meant a multi-minute
488+
/// "Starting backup..." sweep while 140 Mbps of upload showed nowhere in
489+
/// the UI, and (issue #301) a 22-op reconcile meant a full minute of
490+
/// generic "Starting backup..." with nothing moving at all.
489491
Recovering {
490492
/// Source whose pending op is being recovered.
491493
source_id: SourceId,
492-
/// Source-relative path of the file being resumed (display only).
494+
/// Source-relative path of the op being recovered (display only).
495+
/// Empty when the tick reports whole-pass op progress rather than one
496+
/// file's byte progress.
493497
path: String,
494498
/// Bytes the destination has acked so far (the resume's progress
495-
/// numerator; starts at the previously-acked offset, not 0).
499+
/// numerator; starts at the previously-acked offset, not 0). Zero on
500+
/// an op-progress tick, which carries no byte dimension.
496501
bytes_done: u64,
497-
/// The session's total byte count.
502+
/// The session's total byte count. Zero on an op-progress tick.
498503
bytes_total: u64,
504+
/// Issue #301: pending ops of this source's pass recovered so far.
505+
/// The reconcile spends most of its wall clock on one remote
506+
/// round trip per op (a `metadata` read or a `find_by_op_uuid`
507+
/// lookup), which carries no bytes at all - so without this counter
508+
/// the UI has nothing to show for the majority of a recovery.
509+
ops_done: u64,
510+
/// Issue #301: total pending ops in this source's pass.
511+
ops_total: u64,
499512
},
500513
/// Walking + diffing one source's local tree (SPEC s6). `scanned` is a
501514
/// running count of files visited, for a live progress readout.

src-tauri/locales/en-US.yml

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,8 @@ tray:
2727
settings: "Settings"
2828
restore: "Restore"
2929
quit: "Quit Driven"
30+
quitting_status: "Quitting - finishing current backup..."
31+
force_quit: "Force quit now"
3032
menu_status:
3133
line1: "Backing up - %{percent}, %{eta} left"
3234
line1_no_eta: "Backing up - %{percent}"
@@ -58,6 +60,7 @@ tray:
5860
needs_reauth: "Driven needs to sign in again"
5961
error: "Driven - error, attention needed"
6062
suspending: "Suspending..."
63+
quitting: "Driven - quitting (finishing backup, right-click to force quit)"
6164

6265
notifications:
6366
first_sync_complete:

0 commit comments

Comments
 (0)