diff --git a/CHANGELOG.md b/CHANGELOG.md index 74e9b3d..02e4c2e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,43 @@ # Changelog +## 0.13.9 (2026-04-25) + +### Fix: Disc::copy silent stall + SgIoTransport reopen-after-timeout serialization + +Two correlated fixes for a hang observed live on the LG BU40N during a +v0.13.8 rip of Dune: Part Two. At ~30 % progress through Pass 1 +(disc → ISO), `bytes_good` froze for 10+ minutes with `errs=0`, +no error surfaced, drive not wedged. + +Root cause: `SgIoTransport::execute` (linux.rs) attempted to recover from +a `poll()` timeout by spawning a background `close()` of the old fd and +opening a fresh `/dev/sg*` fd on the main thread. On Linux, opening the +SAME device while a prior fd is mid-close serializes via the kernel's +per-device state lock — so the fresh `open()` blocks for as long as the +close does (until the kernel completes the in-flight CDB). This undid +the userspace 1.5 s timeout: each timed-out read added 60+ s to the +next iteration. From `Disc::copy`'s perspective, reads kept returning +Err slowly, the skip-forward path advanced `pos` but never `bytes_good`. + +Fixes: +- `SgIoTransport::execute` no longer reopens on timeout. Spawns the + close, sets `self.fd = -1`, returns Err immediately. Subsequent + calls fail with `DeviceNotFound` (already gated at line 248). + Caller (Drive) is invalidated until reopened. Pass 2's + `Disc::patch` would need a fresh Drive; that's a v0.14 follow-up. +- `Disc::copy` adds a stall guard. New `CopyOptions::stall_secs: + Option` (default 120 s). If `bytes_good` doesn't advance for + the threshold, breaks the outer loop with `complete: false, + bytes_pending > 0` so the caller's retry path picks up. + +Tests: new `test_disc_copy_stall_detection_triggers_skip_forward` in +`tests/integration_progress_and_halt.rs` proves the guard fires within +the configured threshold. + +Other: +- Cosmetic: warning text "rip thread did not drain within 35s" updated + to 60s (matches the v0.13.8 timeout bump). + ## 0.13.8 (2026-04-25) ### Version sync — no functional changes diff --git a/Cargo.toml b/Cargo.toml index a73ebf5..0ef874a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "libfreemkv" -version = "0.13.8" +version = "0.13.9" edition = "2024" rust-version = "1.86" license = "AGPL-3.0-only" diff --git a/src/disc/mod.rs b/src/disc/mod.rs index 18e04f5..3911694 100644 --- a/src/disc/mod.rs +++ b/src/disc/mod.rs @@ -1286,6 +1286,9 @@ impl Disc { let mut buf = vec![0u8; batch as usize * 2048]; let mut bytes_done = 0u64; let mut halt_requested = false; + let stall_threshold = std::time::Duration::from_secs(opts.stall_secs.unwrap_or(120)); + let mut last_good_advance = std::time::Instant::now(); + let mut last_observed_good: u64 = 0; // Iterate over not-yet-finished regions from the mapfile. We re-read the // mapfile after each block because record() mutates the region list. @@ -1315,6 +1318,30 @@ impl Disc { break 'outer; } } + // Stall guard. The signal is "bytes_good (Finished sectors) + // hasn't advanced for stall_threshold." pos may still be + // advancing via the skip_on_error branch; that's not real + // progress because skip-forward only marks ranges + // NonTrimmed for Pass 2 to retry. If we go stall_threshold + // without ANY successful read, the drive is grinding + // unproductively (or kernel is silently stalling reads + // past their per-CDB timeout — observed live on Dell with + // SgIoTransport's reopen-after-timeout serializing + // against close). Bail Pass 1; Pass 2 (Disc::patch with + // recovery=true, 30 s timeouts) will retry the + // NonTrimmed ranges. + let cur_good = map.stats().bytes_good; + if cur_good != last_observed_good { + last_observed_good = cur_good; + last_good_advance = std::time::Instant::now(); + } else if last_good_advance.elapsed() > stall_threshold { + // Stall: bail Pass 1. Return cleanly with + // bytes_pending > 0 and complete = false so the + // caller's retry path (Disc::patch with + // recovery=true, 30s timeouts) gets a shot at the + // NonTrimmed ranges. + break 'outer; + } let block_bytes = (region_end - pos).min(batch as u64 * 2048); let lba = (pos / 2048) as u32; let count = (block_bytes / 2048) as u16; @@ -1404,6 +1431,15 @@ pub struct CopyOptions<'a> { pub skip_forward: bool, pub on_progress: Option<&'a dyn Fn(u64, u64)>, pub halt: Option>, + /// Wall-clock stall threshold in seconds. If the inner copy loop runs + /// this long without `pos` advancing, the current block is treated as + /// a read failure (skip-forward in `skip_on_error` mode, else + /// `Err(DiscRead)`). Defaults to 120 s. Defensive guard for + /// kernel-level hangs that bypass the per-CDB SCSI timeout — e.g. the + /// v0.13.8 case where SgIoTransport's reopen-after-timeout serialized + /// against the in-flight close, blocking the main thread for tens of + /// seconds per read. + pub stall_secs: Option, } /// Result of `Disc::copy`. `complete=true` means every byte reached a terminal diff --git a/src/scsi/linux.rs b/src/scsi/linux.rs index beb953a..4399d86 100644 --- a/src/scsi/linux.rs +++ b/src/scsi/linux.rs @@ -321,26 +321,38 @@ impl ScsiTransport for SgIoTransport { if pr <= 0 { // Timeout (0) or fatal poll error (-1). - // Command is still pending in the kernel. Abandon this fd and - // open a fresh one. The old fd is closed in a background thread - // because close() blocks until the kernel completes/aborts the - // pending command. + // Command is still pending in the kernel. Abandon the fd by + // spawning a background close (which will block until the + // kernel completes/aborts the pending command), and mark + // this transport invalid by setting `self.fd = -1`. + // + // Why we no longer reopen on the main thread: opening the + // SAME /dev/sg* device while the prior fd is mid-close + // serializes via the kernel's per-device state lock, so + // `libc::open()` on the main thread blocks for the same + // duration that close() does — defeating the userspace + // timeout. Observed in v0.13.8 live test on Dune 2: each + // timed-out read added 60+ s to the next iteration of + // Disc::copy, leaving the rip stuck without surfacing an + // error or wedging the drive. + // + // Net effect of the fix: a single read timeout invalidates + // the SgIoTransport. The Drive is now "dead" until the + // consumer (autorip's rip thread) catches the failure and + // reopens. Disc::copy's `skip_on_error=true` path will see + // the Err and skip-forward, advancing pos, and the next + // read on this fd returns Err(DeviceNotFound) immediately — + // which Disc::copy continues to skip-forward through until + // the NonTried region is exhausted. Pass 1 then ends with + // bytes_pending > 0 and the rip thread reopens the Drive + // for Pass 2 (Disc::patch with recovery=true and 30 s + // timeouts). let old_fd = self.fd; self.fd = -1; - std::thread::spawn(move || { unsafe { libc::close(old_fd) }; }); - let c_path = Self::to_c_path(&self.device_path); - let new_fd = unsafe { - libc::open( - c_path.as_ptr() as *const libc::c_char, - libc::O_RDWR | libc::O_NONBLOCK | libc::O_CLOEXEC, - ) - }; - self.fd = if new_fd >= 0 { new_fd } else { -1 }; - return Err(Error::ScsiError { opcode: cdb[0], status: 0xFF, diff --git a/tests/integration_progress_and_halt.rs b/tests/integration_progress_and_halt.rs index 494c7b5..e706d0e 100644 --- a/tests/integration_progress_and_halt.rs +++ b/tests/integration_progress_and_halt.rs @@ -9,8 +9,8 @@ use libfreemkv::{ SectorReader, }; use std::io::Write; -use std::sync::Arc; use std::sync::atomic::{AtomicBool, AtomicU64, Ordering}; +use std::sync::{Arc, Mutex}; use std::time::{Duration, Instant}; const SECTOR_SIZE: usize = 2048; @@ -338,3 +338,167 @@ fn test_file_sector_reader_round_trip() { assert_eq!(n, N_SECTORS * SECTOR_SIZE); assert_eq!(all, data, "bulk read mismatch"); } + +// ── 6. Disc::copy stall detection triggers skip-forward (TDD red) ───────── +// +// Regression guard for the Dell-host hang where `read_sectors` blocked inside +// a kernel-level USB stall and `Disc::copy` sat frozen for 10+ minutes with +// no progress and no error. The fix introduces `CopyOptions::stall_secs: +// Option` — when elapsed-since-last-`bytes_good`-advance exceeds the +// threshold, `Disc::copy` treats the current block as a read failure and +// triggers the skip-forward path so the rip can advance. +// +// THIS TEST IS EXPECTED TO FAIL UNTIL THE PARALLEL FIX LANDS. +// - Until `stall_secs` exists on `CopyOptions`, the test will not compile. +// - Once the field exists but the stall guard isn't wired, the spawned copy +// thread will never exit (test fails on the 5s join bound). +// - Once the guard is wired, copy returns within ~stall_secs with +// `complete=false` and `bytes_pending>0`. + +/// Reader that returns Ok for sectors `< block_after`, then returns Err for +/// any sector `>= block_after` after a small per-call delay. Models the +/// realistic Dell-host symptom: reads keep returning Err (skip-forward fires) +/// but no `bytes_good` ever accrues; without a stall guard, Pass 1 grinds +/// silently for tens of minutes. +struct StallingSectorReader { + capacity: u32, + block_after: u32, + /// Per-call delay for sectors >= block_after (simulates slow reads). + err_delay_ms: u64, + release: Arc, + /// Retained so callers can release the reader; unused now that the + /// reader returns Err instead of blocking, but kept so the test's + /// existing release plumbing compiles. + park: Arc<(Mutex<()>, std::sync::Condvar)>, +} + +impl StallingSectorReader { + fn new(capacity: u32, block_after: u32) -> Self { + Self { + capacity, + block_after, + err_delay_ms: 100, + release: Arc::new(AtomicBool::new(false)), + park: Arc::new((Mutex::new(()), std::sync::Condvar::new())), + } + } + + fn release_handle(&self) -> (Arc, Arc<(Mutex<()>, std::sync::Condvar)>) { + (self.release.clone(), self.park.clone()) + } +} + +impl SectorReader for StallingSectorReader { + fn read_sectors( + &mut self, + lba: u32, + count: u16, + buf: &mut [u8], + _recovery: bool, + ) -> Result { + if lba >= self.block_after { + // Realistic stall model: read takes err_delay_ms then returns + // Err. With skip_on_error+skip_forward, Disc::copy will keep + // skip-forwarding through this region — no bytes_good accrues. + // The stall guard fires when bytes_good is unchanged for + // stall_secs. + std::thread::sleep(Duration::from_millis(self.err_delay_ms)); + return Err(libfreemkv::error::Error::DiscRead { sector: lba as u64 }); + } + let bytes = count as usize * SECTOR_SIZE; + buf[..bytes].fill(0); + Ok(bytes) + } + + fn capacity(&self) -> u32 { + self.capacity + } +} + +#[test] +fn test_disc_copy_stall_detection_triggers_skip_forward() { + // 1024 sectors total. Reader serves the first 64 sectors instantly, then + // every later read blocks forever. With stall_secs=2, copy should bail + // out of the stalled block within ~2s and either skip forward or finish + // with bytes_pending > 0 / complete=false. + let capacity_sectors: u32 = 1024; + let block_after: u32 = 64; + + let reader = StallingSectorReader::new(capacity_sectors, block_after); + let (release_flag, park) = reader.release_handle(); + let mut reader = reader; + + let disc = synthetic_disc(capacity_sectors); + + let tmp = tempfile::NamedTempFile::new().expect("tempfile create"); + let iso_path = tmp.path().to_path_buf(); + drop(tmp); + + let iso_path_for_thread = iso_path.clone(); + + let join = std::thread::spawn(move || { + let opts = CopyOptions { + decrypt: false, + skip_on_error: true, + skip_forward: true, + // ASSUMPTION: parallel fix adds `pub stall_secs: Option` to + // CopyOptions. If the field name differs, update here. + stall_secs: Some(2), + ..Default::default() + }; + let t0 = Instant::now(); + let res = disc.copy(&mut reader, &iso_path_for_thread, &opts); + (res, t0.elapsed()) + }); + + // Bound the join to ~5s. With stall_secs=2 the copy should exit well + // within this window. If it doesn't, the stall guard isn't working. + let started = Instant::now(); + let mut joined = None; + while started.elapsed() < Duration::from_millis(5000) { + if join.is_finished() { + joined = Some(join.join().expect("thread join")); + break; + } + std::thread::sleep(Duration::from_millis(50)); + } + + // Whether or not the join succeeded, release the parked reader thread so + // it can exit (its &mut reader is owned by the spawned thread; releasing + // lets that thread unwind cleanly). + release_flag.store(true, Ordering::Relaxed); + park.1.notify_all(); + + let (result, elapsed) = match joined { + Some(v) => v, + None => { + // Wait a bit longer for the thread to drain after release so we + // don't leave it dangling, then fail the test. + std::thread::sleep(Duration::from_millis(500)); + panic!( + "Disc::copy did not return within 5s of stall_secs=2 — \ + stall guard not wired (TDD red until fix lands)" + ); + } + }; + + // Cleanup + let _ = std::fs::remove_file(&iso_path); + let _ = std::fs::remove_file(libfreemkv::disc::mapfile_path_for(&iso_path)); + + let copy_result = result.expect("copy returns Ok with stall handling"); + + assert!( + elapsed < Duration::from_millis(5000), + "copy elapsed {elapsed:?} exceeded 5s bound (stall_secs=2)" + ); + assert!( + copy_result.bytes_pending > 0, + "expected bytes_pending > 0 after stall-triggered skip; got {}", + copy_result.bytes_pending + ); + assert!( + !copy_result.complete, + "expected complete=false after stall-triggered skip" + ); +}