Merge remote-tracking branch 'origin/main' into fix/1933-port-holder

# Conflicts:
#	CHANGELOG.md
#	frontend/src-tauri/src/backend.rs

CHANGELOG.md

@@ -98,6 +98,7 @@ the frozen-backend fallback mirror it for their toolchains.
 
 - Windows contributors can run the test suite without Developer Mode: tests that create a symlink now skip instead of failing with `WinError 1314` (#1990)
 - The crash details dialog now says what the exit code means and what to try, instead of showing a raw number and a log (#1927)
+- A crash report now carries the backend's actual last words: the log tail is captured after the dying process's final output lands, not the instant it exits (#1850)
 - A port-3900 conflict now names who is actually holding it, and gives the command that ends an orphaned backend, instead of telling you to quit an app that has no window (#1933) — thanks @Chang-Jin-Lee!
 
 - Windows desktop launches no longer freeze at "Loading ML runtime (PyTorch)": the parent-liveness watchdog polls the stdin pipe instead of leaving a read pending, which deadlocked numpy's OpenBLAS initializer (#1952)

frontend/src-tauri/src/backend.rs

@@ -635,14 +635,53 @@ pub fn err_log_run_start() -> u64 {
 /// This is the reader every death path must use: it cannot see another run's
 /// output, so a crash marker carries the dying process's words or nothing.
 pub fn read_error_log_tail_for_run(max_lines: usize) -> String {
+    read_error_log_tail_range(err_log_run_start(), None, max_lines)
+}
+
+/// Last N lines of one run's slice, `[start, end)`.
+///
+/// A death path pins `start` BEFORE it settles the drainers (#1850, Greptile):
+/// settling can take up to two seconds, and a Retry arriving in that window
+/// installs a new run and moves `ERR_LOG_RUN_START` past the dying run's
+/// output. Reading "the current run" afterwards would hand the dead process's
+/// crash marker the REPLACEMENT's healthy startup — the cross-run attribution
+/// #1510 exists to prevent, reintroduced through the wait that fixed the tail.
+///
+/// `end` closes the other side (CodeRabbit). A start offset with an unbounded
+/// end still does not identify ONE run: the replacement writes below the dying
+/// run's lines, and a tail reads the last N of the file, so the newer run's
+/// startup is exactly what a caller would get. `end` is where the next run's
+/// slice begins, or `None` when no run started in the meantime.
+pub fn read_error_log_tail_range(start: u64, end: Option<u64>, max_lines: usize) -> String {
     let err_path = backend_log_path().with_file_name("backend_err.log");
-    read_error_log_tail_at(&err_path, err_log_run_start(), max_lines)
+    read_error_log_slice(&err_path, start, end, max_lines)
+}
+
+/// The run that has just died, read as a closed range.
+///
+/// Call AFTER settling: the end is taken from wherever the current run now
+/// begins, which is either still `start` (nothing replaced it) or the
+/// replacement's offset (which is exactly where this run's slice ends).
+pub fn read_dead_run_tail(start: u64, max_lines: usize) -> String {
+    let now = err_log_run_start();
+    let end = if now > start { Some(now) } else { None };
+    read_error_log_tail_range(start, end, max_lines)
 }
 
 /// Tail of `path` starting at byte `start` (whole file when `start` is 0 or
 /// no longer valid — an externally replaced/shrunk file must degrade to the
 /// old whole-file behaviour, never to a silent empty capture).
 fn read_error_log_tail_at(path: &Path, start: u64, max_lines: usize) -> String {
+    read_error_log_slice(path, start, None, max_lines)
+}
+
+/// `read_error_log_tail_at` with the far end closed too.
+fn read_error_log_slice(
+    path: &Path,
+    start: u64,
+    end: Option<u64>,
+    max_lines: usize,
+) -> String {
     let content = match fs::read_to_string(path) {
         Ok(c) => c,
         Err(_) => return String::new(),
@@ -653,36 +692,107 @@ fn read_error_log_tail_at(path: &Path, start: u64, max_lines: usize) -> String {
     } else {
         &content[..]
     };
+    // An end that is not a usable boundary degrades to "the rest of the file",
+    // matching how an unusable start degrades to the whole file: evidence
+    // beats precision, and a silent empty capture is the one outcome that
+    // helps nobody.
+    let slice = match end.and_then(|e| usize::try_from(e).ok()) {
+        Some(e) if e >= start && e <= content.len() && content.is_char_boundary(e) => {
+            &content[..e - start]
+        }
+        _ => slice,
+    };
     let lines: Vec<&str> = slice.lines().collect();
     let from = lines.len().saturating_sub(max_lines);
     lines[from..].join("\n")
 }
 
-/// The previous run's stderr-drainer thread. Joined (bounded) before a new
-/// spawn records its offset, so a dying run's still-buffered stderr cannot be
-/// appended AFTER the new run's start offset and get attributed to the new
-/// run. (Full per-child offset binding isn't needed: spawns are serialized by
-/// the #1223 spawn-once flow, so the only race left was this buffered tail.)
-static ERR_LOG_DRAINER: Mutex<Option<std::thread::JoinHandle<()>>> = Mutex::new(None);
+/// Stderr-drainer threads that have not finished writing yet.
+///
+/// A list, not a slot. Two callers wait on these — a respawn before it records
+/// its start offset (#1510) and a crash marker before it captures the tail
+/// (#1850) — and either can time out on a wedged drainer (a pipe held open by
+/// an orphaned grandchild) while a NEW run installs its own. A single slot
+/// loses the timed-out handle at that moment: dropping a JoinHandle detaches
+/// the thread, so nothing can ever wait for that run's output again and both
+/// guarantees quietly stop holding. Keeping every unfinished handle costs a
+/// Vec that is empty in the normal case, since a finished drainer is dropped
+/// on the next settle.
+static ERR_LOG_DRAINERS: Mutex<Vec<std::thread::JoinHandle<()>>> = Mutex::new(Vec::new());
 
-/// Wait briefly for the previous run's stderr drainer to flush. A wedged
-/// drainer (pipe held open by an orphaned grandchild) must not block a
-/// respawn forever — after the bound we proceed; the offset then simply
-/// includes whatever the old run still manages to write, which degrades to
-/// attributing too MUCH to the new run, never to destroying evidence.
-fn join_previous_err_drainer(bound: Duration) {
-    let handle = ERR_LOG_DRAINER.lock().ok().and_then(|mut g| g.take());
-    if let Some(handle) = handle {
-        let deadline = std::time::Instant::now() + bound;
-        while !handle.is_finished() && std::time::Instant::now() < deadline {
-            std::thread::sleep(Duration::from_millis(20));
-        }
+/// Register a run's stderr drainer so the settles below can wait for it.
+fn track_err_drainer(handle: std::thread::JoinHandle<()>) {
+    if let Ok(mut guard) = ERR_LOG_DRAINERS.lock() {
+        guard.push(handle);
+    }
+}
+
+/// Serializes a whole settlement. `settle_err_log` takes the handles out of
+/// the list and then waits without holding that lock, so two callers could
+/// otherwise interleave: the second finds an empty list, concludes there is
+/// nothing to wait for, and reads the log while the first is still waiting for
+/// exactly the drainer it needs (CodeRabbit). One settlement at a time makes a
+/// caller that returns a caller for whom the waiting is genuinely done.
+static ERR_LOG_SETTLE_LOCK: Mutex<()> = Mutex::new(());
+
+/// Wait briefly for every outstanding stderr drainer to finish writing.
+///
+/// Two callers, one guarantee: everything a run wrote is on disk before anyone
+/// reads it.
+///
+/// - Before a respawn takes its start offset, so a dying run's buffered tail
+///   cannot be appended past that offset and get attributed to the new run
+///   (#1510).
+/// - Before a crash marker captures `last_stderr` (#1850). `wait()` returns the
+///   moment the child exits, but the drainer is a separate thread reading a
+///   pipe: its last lines — the traceback naming the cause — can still be in
+///   flight. Reading the file at that instant captures a tail that stops BEFORE
+///   the death, which is how a crash report arrives with a log ending a minute
+///   early and nothing to diagnose.
+///
+/// A wedged drainer must not block forever. After the bound we proceed, and
+/// every handle still running is kept for the next caller to wait on. For a
+/// respawn that degrades to attributing too MUCH to the new run; for a marker,
+/// to a short tail. Never to destroyed evidence, and never to a detached
+/// thread nobody can wait for again.
+pub fn settle_err_log(bound: Duration) {
+    let _settling = ERR_LOG_SETTLE_LOCK
+        .lock()
+        .unwrap_or_else(|poisoned| poisoned.into_inner());
+    let pending: Vec<_> = match ERR_LOG_DRAINERS.lock() {
+        Ok(mut guard) => guard.drain(..).collect(),
+        Err(_) => return,
+    };
+    if pending.is_empty() {
+        return;
+    }
+    let deadline = std::time::Instant::now() + bound;
+    while std::time::Instant::now() < deadline && pending.iter().any(|h| !h.is_finished()) {
+        std::thread::sleep(Duration::from_millis(20));
+    }
+    let mut still_running = Vec::new();
+    for handle in pending {
         if handle.is_finished() {
             let _ = handle.join();
+        } else {
+            still_running.push(handle);
+        }
+    }
+    if !still_running.is_empty() {
+        if let Ok(mut guard) = ERR_LOG_DRAINERS.lock() {
+            // Put them back at the FRONT: they are older than anything a
+            // concurrent spawn pushed while this was waiting.
+            still_running.append(&mut guard);
+            *guard = still_running;
         }
     }
 }
 
+/// How long a death path waits for the dying run's final stderr. Bounded so a
+/// wedged pipe cannot stall crash recording, generous enough to cover a
+/// traceback already sitting in the drainer's buffer.
+pub const ERR_LOG_SETTLE: Duration = Duration::from_secs(2);
+
 /// Open backend_err.log for a new run: append-only (a respawn must not
 /// destroy the previous run's evidence), rotated when oversized, with the
 /// run's start offset returned for `ERR_LOG_RUN_START`.
@@ -866,7 +976,7 @@ pub(crate) fn spawn_backend<R: tauri::Runtime>(
     // Append + per-run offset, never truncate: the previous run's stderr is
     // crash evidence until someone reads it (#1510). Flush the previous
     // drainer first so old buffered lines land BEFORE this run's offset.
-    join_previous_err_drainer(Duration::from_secs(2));
+    settle_err_log(Duration::from_secs(2));
     let (err_log_file, err_log_start) = open_err_log_for_run(&err_path);
     ERR_LOG_RUN_START.store(err_log_start, std::sync::atomic::Ordering::SeqCst);
     if let Some(ref f) = err_log_file {
@@ -1050,9 +1160,7 @@ pub(crate) fn spawn_backend<R: tauri::Runtime>(
                 }
             }
         });
-        if let Ok(mut guard) = ERR_LOG_DRAINER.lock() {
-            *guard = Some(drainer);
-        }
+        track_err_drainer(drainer);
     }
 
     Some(contained)
@@ -1074,6 +1182,11 @@ mod tests {
     /// other's toes (cargo runs tests in threads by default).
     static ENV_LOCK: std::sync::Mutex<()> = std::sync::Mutex::new(());
 
+    /// `ERR_LOG_DRAINERS` is one process-global list, and several tests push
+    /// a handle onto it. Without this they race: one test's settle drains and
+    /// joins another's thread, and both assert on state they no longer own.
+    static DRAINER_LOCK: std::sync::Mutex<()> = std::sync::Mutex::new(());
+
     #[test]
     fn a_baked_token_reaches_the_spawned_backend() {
         let _g = ENV_LOCK.lock().unwrap_or_else(|e| e.into_inner());
@@ -1600,6 +1713,7 @@ mod tests {
 
     #[test]
     fn a_dying_runs_buffered_stderr_flushes_before_the_next_offset() {
+        let _g = DRAINER_LOCK.lock().unwrap_or_else(|e| e.into_inner());
         use std::io::Write;
         let dir = tempfile::tempdir().unwrap();
         let path = dir.path().join("backend_err.log");
@@ -1612,10 +1726,10 @@ mod tests {
             let mut f = fs::OpenOptions::new().append(true).open(&p).unwrap();
             writeln!(f, "run1: buffered last words").unwrap();
         });
-        *ERR_LOG_DRAINER.lock().unwrap() = Some(late);
+        track_err_drainer(late);
 
         // …must land BEFORE the next run records where its output begins.
-        join_previous_err_drainer(Duration::from_secs(2));
+        settle_err_log(Duration::from_secs(2));
         let (_file, start) = open_err_log_for_run(&path);
         let run2 = read_error_log_tail_at(&path, start, 10);
         assert!(
@@ -1812,4 +1926,155 @@ Content-Length: {}
         assert!(msg.contains("another application"), "{msg}");
         assert!(msg.ends_with("so the backend can't restart."), "{msg}");
     }
+
+    #[test]
+    fn a_crash_tail_waits_for_the_dying_runs_last_words() {
+        let _g = DRAINER_LOCK.lock().unwrap_or_else(|e| e.into_inner());
+        // #1850: `wait()` returns the moment the child exits, but the stderr
+        // drainer is a separate thread still reading the pipe. Capturing
+        // `last_stderr` at that instant produced a crash report whose log
+        // stopped a minute before the death — the traceback that named the
+        // cause never made it into the file in time.
+        use std::io::Write;
+        let dir = tempfile::tempdir().unwrap();
+        let path = dir.path().join("backend_err.log");
+        fs::write(&path, "steady state\n").unwrap();
+
+        let p = path.clone();
+        let dying = std::thread::spawn(move || {
+            std::thread::sleep(Duration::from_millis(120));
+            let mut f = fs::OpenOptions::new().append(true).open(&p).unwrap();
+            writeln!(f, "Traceback (most recent call last):").unwrap();
+            writeln!(f, "RuntimeError: the actual cause").unwrap();
+        });
+        track_err_drainer(dying);
+
+        // Without the settle this reads "steady state" and nothing else.
+        settle_err_log(ERR_LOG_SETTLE);
+        let tail = read_error_log_tail_at(&path, 0, 30);
+
+        assert!(
+            tail.contains("RuntimeError: the actual cause"),
+            "the crash marker captured a tail that predates the death: {tail:?}"
+        );
+    }
+
+    #[test]
+    fn a_pinned_offset_survives_a_respawn_during_the_settle() {
+        // Greptile on #1994: settling can take up to two seconds, and a Retry
+        // in that window installs a new run and moves ERR_LOG_RUN_START past
+        // the dying run's output. Reading "the current run" after the wait
+        // would hand the dead process's crash marker the REPLACEMENT's healthy
+        // startup — the cross-run attribution #1510 exists to prevent,
+        // reintroduced through the wait that fixes the tail. Death paths pin
+        // the offset first, so the slice is the dying run's either way.
+        let dir = tempfile::tempdir().unwrap();
+        let path = dir.path().join("backend_err.log");
+        fs::write(&path, "run1: RuntimeError: the actual cause
+").unwrap();
+        let pinned = 0u64;
+
+        // A respawn lands mid-settle and the new run starts after that line.
+        let moved_on = fs::metadata(&path).unwrap().len();
+        fs::write(
+            &path,
+            "run1: RuntimeError: the actual cause
+run2: healthy startup
+",
+        )
+        .unwrap();
+
+        assert!(
+            read_error_log_tail_at(&path, pinned, 30).contains("the actual cause"),
+            "the pinned offset must still name the dying run's slice"
+        );
+        assert!(
+            !read_error_log_tail_at(&path, moved_on, 30).contains("the actual cause"),
+            "sanity: reading from the new run's offset really does lose it"
+        );
+    }
+
+    #[test]
+    fn a_dead_runs_slice_stops_where_the_replacement_begins() {
+        // CodeRabbit: a start offset with an unbounded end does not identify
+        // ONE run. The replacement writes BELOW the dying run's lines, and a
+        // tail reads the last N of the file — so the newer run's healthy
+        // startup is exactly what the dead run's crash marker would get.
+        let dir = tempfile::tempdir().unwrap();
+        let path = dir.path().join("backend_err.log");
+        let run1 = "run1: RuntimeError: the actual cause
+";
+        fs::write(&path, run1).unwrap();
+        let boundary = run1.len() as u64;
+        fs::write(&path, format!("{run1}run2: healthy startup
+run2: listening
+")).unwrap();
+
+        let closed = read_error_log_slice(&path, 0, Some(boundary), 30);
+        assert!(closed.contains("the actual cause"), "{closed}");
+        assert!(!closed.contains("run2"), "the replacement's output leaked in: {closed}");
+
+        // Unbounded, the tail is the replacement — the bug this closes.
+        let open = read_error_log_slice(&path, 0, None, 2);
+        assert!(open.contains("run2"), "sanity: an open end really does read the newer run");
+    }
+
+    #[test]
+    fn an_unusable_end_degrades_to_the_rest_of_the_file() {
+        // Same principle as an unusable start: evidence beats precision, and a
+        // silent empty capture is the one outcome that helps nobody.
+        let dir = tempfile::tempdir().unwrap();
+        let path = dir.path().join("backend_err.log");
+        fs::write(&path, "only line
+").unwrap();
+
+        // Past EOF, and an end that sits before the start — both mean the
+        // caller cannot pin the far side, so the slice runs to the end of the
+        // file. The start is honoured independently either way.
+        assert_eq!(read_error_log_slice(&path, 0, Some(10_000), 10), "only line");
+        assert_eq!(read_error_log_slice(&path, 5, Some(1), 10), "line");
+    }
+
+    #[test]
+    fn a_wedged_drainer_is_handed_back_rather_than_detached() {
+        let _g = DRAINER_LOCK.lock().unwrap_or_else(|e| e.into_inner());
+        // The bound exists so an orphaned grandchild holding the pipe cannot
+        // stall crash recording. But giving up must not drop the handle:
+        // every later caller would then have nothing to wait on, and the
+        // respawn-offset guarantee (#1510) would quietly stop holding.
+        let (tx, rx) = std::sync::mpsc::channel::<()>();
+        let wedged = std::thread::spawn(move || {
+            let _ = rx.recv();
+        });
+        track_err_drainer(wedged);
+
+        settle_err_log(Duration::from_millis(60));
+
+        assert!(
+            !ERR_LOG_DRAINERS.lock().unwrap().is_empty(),
+            "a drainer that outlived the bound was detached instead of retained"
+        );
+
+        // CodeRabbit: a NEW run installing its own drainer while the wait was
+        // timing out must not evict the old one. A single slot dropped it here,
+        // which detaches the thread — nothing could wait for that run's output
+        // again, and both the #1510 and #1850 guarantees silently stopped
+        // holding.
+        let (tx2, rx2) = std::sync::mpsc::channel::<()>();
+        track_err_drainer(std::thread::spawn(move || {
+            let _ = rx2.recv();
+        }));
+        settle_err_log(Duration::from_millis(60));
+        assert_eq!(
+            ERR_LOG_DRAINERS.lock().unwrap().len(),
+            2,
+            "an unfinished drainer was dropped when another run installed one"
+        );
+
+        let _ = tx.send(());
+        let _ = tx2.send(());
+        for handle in ERR_LOG_DRAINERS.lock().unwrap().drain(..) {
+            let _ = handle.join();
+        }
+    }
 }

frontend/src-tauri/src/bootstrap.rs

@@ -828,7 +828,14 @@ fn spawn_backend_until_ready<R: tauri::Runtime>(
                     }
                 };
             if let Some((exit_info, real_exit)) = process_dead {
-                let err_tail = crate::backend::read_error_log_tail_for_run(30);
+                // Pin the dying run's slice BEFORE waiting for its drainer: a
+                // Retry arriving during the settle installs a new run and moves
+                // the current-run offset past this output (#1850, Greptile).
+                let run_start = crate::backend::err_log_run_start();
+                // The child is gone; its last stderr may still be in the
+                // drainer. Let it land before anything reads the tail (#1850).
+                crate::backend::settle_err_log(crate::backend::ERR_LOG_SETTLE);
+                let err_tail = crate::backend::read_dead_run_tail(run_start, 30);
                 // #941: persist the forensics for every true process death —
                 // startup crashes included — unless the app is shutting down
                 // or a retry flow deliberately killed the child.
@@ -840,7 +847,10 @@ fn spawn_backend_until_ready<R: tauri::Runtime>(
                         crate::crash::record_crash(crate::crash::marker_now(
                             exit,
                             backend_uptime_s(app),
-                            crate::backend::read_error_log_tail_for_run(CRASH_STDERR_TAIL_LINES),
+                            crate::backend::read_dead_run_tail(
+                                run_start,
+                                CRASH_STDERR_TAIL_LINES,
+                            ),
                         ));
                     }
                 }
@@ -1442,6 +1452,11 @@ fn supervise_backend<R: tauri::Runtime>(
             attachment_lifecycle = Some(lifecycle);
         }
         let exit_info = exit.description.clone();
+        // Same as the startup path: pin this run's slice, then wait for its
+        // drainer. `wait()` beat the drainer to the punch, and a Retry during
+        // the wait would otherwise move the offset onto the replacement run.
+        let run_start = crate::backend::err_log_run_start();
+        crate::backend::settle_err_log(crate::backend::ERR_LOG_SETTLE);
         // #941: make the death self-documenting BEFORE any restart attempt —
         // the marker (exit code/signal + stderr tail + uptime) is what turns
         // the next "Can't reach the backend" report into a diagnosable one.
@@ -1456,7 +1471,7 @@ fn supervise_backend<R: tauri::Runtime>(
                 crate::crash::record_crash(crate::crash::marker_now(
                     &exit,
                     uptime_s,
-                    crate::backend::read_error_log_tail_for_run(CRASH_STDERR_TAIL_LINES),
+                    crate::backend::read_dead_run_tail(run_start, CRASH_STDERR_TAIL_LINES),
                 ));
             } else {
                 log::info!(
@@ -1464,7 +1479,7 @@ fn supervise_backend<R: tauri::Runtime>(
                 );
             }
             if restart_budget_exhausted(&mut restart_times, Instant::now()) {
-                let tail = crate::backend::read_error_log_tail_for_run(30);
+                let tail = crate::backend::read_dead_run_tail(run_start, 30);
                 let msg = format!(
                     "The backend kept {} ({} times in {} min; last stop: {}) and couldn't \
                      be kept running. Use Clean & Retry, or check Settings → Logs → Backend.{}",