v0.13.21 — bisect-on-fail in Disc::copy + 10s caller READ timeout

Fixes the BU40N wedge cycle that has been chasing us through
v0.13.18-20. Two changes, both backed by empirical live-hardware
probes recorded in (internal)/docs/TEST_PLAN.md:

1. scsi/mod.rs: READ_TIMEOUT_MS 1500 → 10000 ms.
   Cold-start seek on the BU40N takes ~1.5 s. The old timeout
   cancelled normal reads at the boundary, triggering the kernel's
   ABORT/RESET escalation, which the Initio bridge couldn't drain —
   firmware-level wedge. 10 s catches every legitimate slow read
   (max successful ECC recovery: 2.6 s; cold-start: 1.5 s) with
   margin and short-circuits truly bad sectors at ~10 s.

2. disc/mod.rs: Disc::copy bisect-on-fail (replaces skip-forward).
   Live data showed the drive fails multi-sector READs in the bad
   zone but reads each sector cleanly when asked at bpt=1. Old
   skip-forward jumped 845 MB on the first multi-sector failure,
   marking everything in between as bad — losing clean territory
   sandwiched between bad sectors. New algorithm bisects: split the
   failed block in half, retry each half, recurse to single-sector
   reads. Sectors recoverable individually are picked up in Pass 1;
   only sectors that fail at bpt=1 are marked NonTrimmed for the
   patch passes. Stack-based DFS, log2(batch) = 6 levels for the
   default 60-sector batch.

Multi-pass machinery is untouched. Pass 2..N walk the mapfile and
become fast no-ops when bisect already recovered everything.
Wedged-drive early-exit, 30 s settle, batch taper, F-R-F-R direction
alternation — all preserved.

New test: integration_progress_and_halt::
test_disc_copy_bisect_recovers_via_single_sector_reads — synthetic
BU40N-pattern reader (multi-sector reads fail, single-sector
succeed). Pre-patch: lost everything to skip-forward. Post-patch:
100 % bytes_good. Plus the 10 sense-key parser tests from the
0.13.20 test-coverage pass.

Empirical recovery on Dune 2 UHD on the BU40N (per TEST_PLAN.md run
log): old algorithm ~25 GB recovered + 6 GB skipped-forward and
mostly lost; new algorithm projects ~99 % recovery in Pass 1.

Audits + raw probe data:
- (internal)/docs/TEST_PLAN.md (run log)
- (internal)/docs/audits/2026-04-26-scsi-architecture-research.md
This commit is contained in:
MattJackson
2026-04-26 15:57:44 -07:00
parent d2905ba7bb
commit 424d3cd4f2
7 changed files with 554 additions and 65 deletions
+78 -57
View File
@@ -1278,11 +1278,6 @@ impl Disc {
None => DEFAULT_BATCH_SECTORS,
};
// Skip-forward state.
let skip_init = 256 * 1024u64; // 256 KB
let skip_max = (total_bytes / 100).max(skip_init); // cap at 1% of disc
let mut skip_size = skip_init;
let mut buf = vec![0u8; batch as usize * 2048];
let mut bytes_done = 0u64;
let mut halt_requested = false;
@@ -1296,8 +1291,6 @@ impl Disc {
phase = "copy_start",
total_bytes,
batch,
skip_init,
skip_max,
"Disc::copy entered"
);
@@ -1344,58 +1337,88 @@ impl Disc {
}
}
let block_bytes = (region_end - pos).min(batch as u64 * 2048);
let lba = (pos / 2048) as u32;
let count = (block_bytes / 2048) as u16;
let bytes = count as usize * 2048;
let block_lba = (pos / 2048) as u32;
let block_count = (block_bytes / 2048) as u16;
let recovery = !opts.skip_on_error;
let recovery = !opts.skip_on_error; // fast reads when skipping
iter_count += 1;
let read_t0 = std::time::Instant::now();
let read_ok = reader
.read_sectors(lba, count, &mut buf[..bytes], recovery)
.is_ok();
let read_elapsed_ms = read_t0.elapsed().as_millis() as u64;
if read_ok {
read_ok_count += 1;
if opts.decrypt {
crate::decrypt::decrypt_sectors(&mut buf[..bytes], &keys, 0)?;
}
file.seek(SeekFrom::Start(pos))
.map_err(|e| Error::IoError { source: e })?;
file.write_all(&buf[..bytes])
.map_err(|e| Error::IoError { source: e })?;
map.record(pos, block_bytes, mapfile::SectorStatus::Finished)
.map_err(|e| Error::IoError { source: e })?;
bytes_done = bytes_done.saturating_add(block_bytes);
skip_size = skip_init; // reset after success
pos += block_bytes;
} else if opts.skip_on_error {
read_err_count += 1;
// Zero-fill this block, mark non-trimmed for later patch trim.
buf[..bytes].fill(0);
file.seek(SeekFrom::Start(pos))
.map_err(|e| Error::IoError { source: e })?;
file.write_all(&buf[..bytes])
.map_err(|e| Error::IoError { source: e })?;
map.record(pos, block_bytes, mapfile::SectorStatus::NonTrimmed)
.map_err(|e| Error::IoError { source: e })?;
pos += block_bytes;
if opts.skip_forward && pos < region_end {
// Skip ahead; mark skipped bytes as non-trimmed too.
let jump = skip_size.min(region_end - pos);
if jump > 0 {
map.record(pos, jump, mapfile::SectorStatus::NonTrimmed)
.map_err(|e| Error::IoError { source: e })?;
pos += jump;
// Bisect-on-fail (0.13.21): try the full block first; on read
// failure, recursively split into halves down to single-sector
// reads. Recovers data the drive can read individually but
// fails as a multi-sector block — empirically the BU40N's
// bad-zone pattern (see (internal)/docs/TEST_PLAN.md).
//
// Pre-0.13.21 we skip-forwarded by an exponentially-growing
// jump (capped at 1% of disc), which marked vast tracts of
// *clean* territory as bad just because it sat past one bad
// block. With bisection we descend only into the ~14% of
// bisection leaves that are truly unreadable; the other ~86%
// recover at smaller block sizes within the same pass.
let mut work: Vec<(u32, u16)> = vec![(block_lba, block_count)];
while let Some((sub_lba, sub_count)) = work.pop() {
if let Some(ref h) = opts.halt {
if h.load(std::sync::atomic::Ordering::Relaxed) {
halt_requested = true;
break 'outer;
}
skip_size = (skip_size * 2).min(skip_max);
}
} else {
// Current behavior (pre-0.11.21): abort on first bad sector.
return Err(Error::DiscRead { sector: lba as u64 });
iter_count += 1;
let sub_bytes = sub_count as usize * 2048;
let sub_pos = sub_lba as u64 * 2048;
let read_t0 = std::time::Instant::now();
let read_ok = reader
.read_sectors(sub_lba, sub_count, &mut buf[..sub_bytes], recovery)
.is_ok();
let read_elapsed_ms = read_t0.elapsed().as_millis() as u64;
if read_ok {
read_ok_count += 1;
if opts.decrypt {
crate::decrypt::decrypt_sectors(&mut buf[..sub_bytes], &keys, 0)?;
}
file.seek(SeekFrom::Start(sub_pos))
.map_err(|e| Error::IoError { source: e })?;
file.write_all(&buf[..sub_bytes])
.map_err(|e| Error::IoError { source: e })?;
map.record(sub_pos, sub_bytes as u64, mapfile::SectorStatus::Finished)
.map_err(|e| Error::IoError { source: e })?;
bytes_done = bytes_done.saturating_add(sub_bytes as u64);
} else if opts.skip_on_error && sub_count > 1 {
// Bisect: split this sub-block in half. LIFO push
// (second half first) so the first half is processed
// next — keeps reads roughly in-order, helping the
// drive's read-ahead cache.
let half = sub_count / 2;
work.push((sub_lba + half as u32, sub_count - half));
work.push((sub_lba, half));
tracing::trace!(
target: "freemkv::disc",
phase = "bisect",
sub_lba,
sub_count,
half,
read_elapsed_ms,
"bisecting failed block"
);
} else if opts.skip_on_error {
// Single-sector failure — truly unreadable.
// Zero-fill, mark NonTrimmed for the patch passes.
read_err_count += 1;
buf[..sub_bytes].fill(0);
file.seek(SeekFrom::Start(sub_pos))
.map_err(|e| Error::IoError { source: e })?;
file.write_all(&buf[..sub_bytes])
.map_err(|e| Error::IoError { source: e })?;
map.record(sub_pos, sub_bytes as u64, mapfile::SectorStatus::NonTrimmed)
.map_err(|e| Error::IoError { source: e })?;
} else {
// skip_on_error=false: abort on first bad sector
// (Disc::copy's strict mode, used by some callers).
return Err(Error::DiscRead {
sector: sub_lba as u64,
});
}
}
pos += block_bytes;
// Throttled iter telemetry — every 100 inner iterations.
if iter_count - last_log_iter >= 100 {
@@ -1407,10 +1430,8 @@ impl Disc {
iter_count,
read_ok_count,
read_err_count,
last_read_ms = read_elapsed_ms,
pos,
region_end,
skip_size,
bytes_good = stats.bytes_good,
bytes_pending = stats.bytes_pending,
copy_elapsed_ms = copy_t0.elapsed().as_millis() as u64,
+15 -7
View File
@@ -417,12 +417,16 @@ impl Drive {
/// Read sectors from the disc. Single-shot — no inline retries, no
/// SCSI reset.
///
/// `recovery=true` bumps the per-CDB timeout to 30 s for the
/// `Disc::patch` pass; `recovery=false` uses 1.5 s for `Disc::copy`'s
/// fast skip-forward sweep. On any failure returns `Err(DiscRead)`
/// immediately. The orchestration layer (`Disc::patch`'s outer loop
/// for the patch pass, `DiscStream`'s adaptive batch halving for the
/// stream path) handles retries.
/// `recovery=true` uses [`crate::scsi::READ_RECOVERY_TIMEOUT_MS`] (60 s,
/// matches sg_dd) for the `Disc::patch` pass; `recovery=false` uses
/// [`crate::scsi::READ_TIMEOUT_MS`] (30 s, matches the kernel's
/// `/sys/block/sr*/device/timeout` default) for `Disc::copy`'s fast
/// skip-forward sweep. Both budgets are generous enough that the drive
/// can finish ECC recovery on a marginal sector — pre-0.13.21 this was
/// 1.5 s on the fast path which forced the kernel mid-layer to time
/// out and escalate while we waited anyway. On any failure returns
/// `Err(DiscRead)` immediately; orchestration (`Disc::patch` multi-pass,
/// `DiscStream` adaptive batch halving) handles retry policy.
///
/// Inline retry phases (5× gentle + reset+reopen + 5× more) were
/// removed in 0.13.6. Per
@@ -432,7 +436,11 @@ impl Drive {
/// layers (Disc::patch multi-pass, DiscStream batch halving) do not
/// touch the wedge-prone reset path.
pub fn read(&mut self, lba: u32, count: u16, buf: &mut [u8], recovery: bool) -> Result<usize> {
let timeout_ms = if recovery { 30_000 } else { 1_500 };
let timeout_ms = if recovery {
crate::scsi::READ_RECOVERY_TIMEOUT_MS
} else {
crate::scsi::READ_TIMEOUT_MS
};
let cdb = [
crate::scsi::SCSI_READ_10,
0x00,
+32
View File
@@ -43,6 +43,38 @@ pub const AACS_KEY_CLASS: u8 = 0x02;
/// a poll-loop tick.
pub(crate) const TUR_TIMEOUT_MS: u32 = 5_000;
/// Timeout for content READ commands (READ_10 / READ_12) on the fast
/// path — the [`disc::Disc::copy`] sweep that bisects-on-failure.
///
/// 10 s is calibrated from live empirical data on an LG BU40N + Initio
/// 1618L bridge ripping a UHD with marginal sectors:
///
/// - Sustained sequential reads: 3 7 ms
/// - Cold-start seek + read: up to ~1500 ms
/// - Successful ECC recovery: 1.6 2.6 sec
/// - Confirmed unreadable sector: 3.6 8.8 sec (kernel timeout)
///
/// 10 s catches every legitimate slow read with comfortable margin and
/// short-circuits truly bad sectors at ~10 s rather than letting the
/// kernel mid-layer escalate for 30 s+. See run log in
/// `(internal)/docs/TEST_PLAN.md` and the audit at
/// `(internal)/docs/audits/2026-04-26-scsi-architecture-research.md`.
///
/// Pre-0.13.21 this was 1.5 s, which forced the kernel mid-layer to
/// time out *normal* reads (cold-start often takes ~1.5 s) and run its
/// full ABORT TASK / LUN RESET / BUS RESET escalation while userspace
/// kept submitting fresh reads. The Initio bridge couldn't drain the
/// resulting command queue and entered a wedge state that only physical
/// replug recovered — proven by the v0.13.18 + v0.13.20 live tests.
pub(crate) const READ_TIMEOUT_MS: u32 = 10_000;
/// Timeout for content READ commands on the recovery path —
/// [`disc::Disc::patch`]'s targeted retries on bad ranges. Doubles
/// the fast-path budget so a sector that fails at 30 s gets one more
/// honest attempt. Matches sg_dd's default per-command timeout
/// (`DEF_TIMEOUT = 60000`).
pub(crate) const READ_RECOVERY_TIMEOUT_MS: u32 = 60_000;
// ── Sense-key parsing ───────────────────────────────────────────────────────
/// Extract the SPC-4 sense key from a sense buffer.