Compare commits

...
16 Commits
9 changed files with 268 additions and 70 deletions
+1 -1
View File
@@ -1,6 +1,6 @@
[package]
name = "libfreemkv"
version = "0.18.15"
version = "0.18.23"
edition = "2024"
rust-version = "1.86"
license = "AGPL-3.0-only"
+57
View File
@@ -247,6 +247,7 @@ fn validate_processing_key(
/// Find Verify Media Key Record (type 0x10) in MKB.
fn mkb_find_mk_dv(mkb: &[u8]) -> Option<[u8; 16]> {
let mut pos = 0;
let mut type10_seen: Vec<(usize, usize)> = Vec::new();
while pos + 4 <= mkb.len() {
let rec_type = mkb[pos];
let rec_len = u32::from_be_bytes([0, mkb[pos + 1], mkb[pos + 2], mkb[pos + 3]]) as usize;
@@ -254,14 +255,32 @@ fn mkb_find_mk_dv(mkb: &[u8]) -> Option<[u8; 16]> {
break;
}
if rec_type == 0x10 {
type10_seen.push((pos, rec_len));
}
if rec_type == 0x10 && rec_len >= 20 {
// mk_dv is at offset 4 (after record header)
let mut dv = [0u8; 16];
dv.copy_from_slice(&mkb[pos + 4..pos + 20]);
tracing::warn!(
target: "freemkv::disc",
phase = "mkb_mk_dv_found",
pos,
rec_len,
"mk_dv extracted from MKB"
);
return Some(dv);
}
pos += rec_len;
}
tracing::warn!(
target: "freemkv::disc",
phase = "mkb_mk_dv_not_found",
type10_seen = ?type10_seen,
scanned_bytes = pos,
"no 0x10 record with rec_len>=20 found"
);
None
}
@@ -628,32 +647,70 @@ pub fn resolve_keys(
}
};
tracing::warn!(
target: "freemkv::disc",
phase = "resolve_keys_start",
aacs2,
bus_encryption,
disc_hash = %hash_hex,
mkb_present = mkb_data.is_some(),
"resolve_keys: starting"
);
// Path 1: Look up VUK by disc hash in KEYDB
if let Some(entry) = keydb.find_disc(&hash_hex) {
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path1_hit_entry", "disc hash found in keydb");
if let Some(vuk) = entry.vuk {
return Some(build(vuk, 1));
}
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path1_no_vuk", "disc hash entry has no VUK");
} else {
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path1_miss", "disc hash NOT in keydb");
}
// Path 2: Find entry with matching VID → derive VUK from MK + VID
let mut path2_mk_did_count = 0usize;
for entry in keydb.disc_entries.values() {
if let (Some(mk), Some(did)) = (entry.media_key, entry.disc_id) {
path2_mk_did_count += 1;
if did == *volume_id {
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path2_hit", "MK+VID entry matched volume_id");
return Some(build(derive_vuk(&mk, volume_id), 2));
}
}
}
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path2_miss", mk_did_entries = path2_mk_did_count, "no MK+VID entry matched volume_id");
// Path 3: MKB + processing keys → media key → VUK
if let Some(mkb) = mkb_data {
let mk_dv = mkb_find_mk_dv(mkb);
let subdiff = mkb_find_subdiff_records(mkb);
let cvalues = mkb_find_cvalues(mkb);
tracing::warn!(
target: "freemkv::disc",
phase = "resolve_keys_mkb_records",
mk_dv_found = mk_dv.is_some(),
subdiff_found = subdiff.is_some(),
subdiff_len = subdiff.as_ref().map(|s| s.len()).unwrap_or(0),
cvalues_found = cvalues.is_some(),
cvalues_len = cvalues.as_ref().map(|c| c.len()).unwrap_or(0),
"MKB record scan results"
);
if let Some(mk) = derive_media_key_from_pk(mkb, &keydb.processing_keys) {
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path3_hit", "media key derived from processing key");
return Some(build(derive_vuk(&mk, volume_id), 3));
}
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path3_miss", pk_count = keydb.processing_keys.len(), "PK derivation failed");
// Path 4: MKB + device keys → processing key → media key → VUK
if let Some(mk) = derive_media_key_from_dk(mkb, &keydb.device_keys) {
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path4_hit", "media key derived from device key");
return Some(build(derive_vuk(&mk, volume_id), 4));
}
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_path4_miss", dk_count = keydb.device_keys.len(), "DK derivation failed");
} else {
tracing::warn!(target: "freemkv::disc", phase = "resolve_keys_no_mkb", "no MKB data available; paths 3/4 skipped");
}
None
+58 -7
View File
@@ -22,12 +22,27 @@ impl Disc {
) -> Option<HandshakeResult> {
use crate::aacs::{self, KeyDb};
let keydb_path = opts.resolve_keydb()?;
tracing::warn!(
target: "freemkv::disc",
phase = "handshake_entry",
"do_handshake entered"
);
let keydb_path = match opts.resolve_keydb() {
Some(p) => p,
None => {
tracing::warn!(
target: "freemkv::disc",
phase = "handshake_no_keydb",
"no KEYDB found in search paths; handshake skipped"
);
return None;
}
};
let keydb = match KeyDb::load(&keydb_path) {
Ok(db) => db,
Err(e) => {
tracing::warn!(
target: "freemkv::aacs",
target: "freemkv::disc",
phase = "handshake_keydb_load_failed",
io_error_kind = ?e.kind(),
keydb = %keydb_path.display(),
@@ -38,11 +53,12 @@ impl Disc {
};
let host_cert_count = keydb.host_certs.len();
tracing::debug!(
target: "freemkv::aacs",
tracing::warn!(
target: "freemkv::disc",
phase = "handshake_start",
host_cert_count,
keydb = %keydb_path.display(),
"handshake starting"
);
const MAX_CERT_ATTEMPTS: usize = 16;
@@ -54,7 +70,7 @@ impl Disc {
Ok(vid) => vid,
Err(e) => {
tracing::warn!(
target: "freemkv::aacs",
target: "freemkv::disc",
phase = "handshake_vid_read_failed",
cert_index = idx,
error_code = e.code(),
@@ -67,7 +83,7 @@ impl Disc {
.ok()
.map(|(rdk, _)| rdk);
tracing::debug!(
target: "freemkv::aacs",
target: "freemkv::disc",
phase = "handshake_ok",
cert_index = idx,
has_read_data_key = read_data_key.is_some(),
@@ -84,7 +100,7 @@ impl Disc {
}
}
tracing::warn!(
target: "freemkv::aacs",
target: "freemkv::disc",
phase = "handshake_all_certs_failed",
host_cert_count,
tried = host_cert_count.min(MAX_CERT_ATTEMPTS),
@@ -118,6 +134,19 @@ impl Disc {
.or_else(|_| udf_fs.read_file(reader, "/AACS/DUPLICATE/Unit_Key_RO.inf"))
.map_err(|_| Error::AacsNoKeys)?;
// Log the disc hash so we can confirm whether it's present in KEYDB
// when key resolution fails. The disc hash is SHA-1 of the full
// Unit_Key_RO.inf file bytes — same value KEYDB.cfg keys VUK entries by.
let dh = crate::aacs::disc_hash(&uk_ro_data);
let dh_hex = crate::aacs::disc_hash_hex(&dh);
tracing::warn!(
target: "freemkv::disc",
phase = "scan_aacs_disc_hash",
disc_hash = %dh_hex,
uk_ro_len = uk_ro_data.len(),
"disc hash computed (compare with keydb.cfg entries)"
);
let cc_data = udf_fs
.read_file(reader, "/AACS/Content000.cer")
.or_else(|_| udf_fs.read_file(reader, "/AACS/Content001.cer"))
@@ -129,6 +158,28 @@ impl Disc {
.ok();
let mkb_ver = mkb_data.as_deref().and_then(aacs::mkb_version);
let mkb_first_64_hex = mkb_data
.as_deref()
.map(|m| {
m.iter()
.take(64)
.map(|b| format!("{b:02x}"))
.collect::<String>()
})
.unwrap_or_default();
tracing::warn!(
target: "freemkv::disc",
phase = "scan_aacs_mkb_info",
mkb_present = mkb_data.is_some(),
mkb_len = mkb_data.as_deref().map(|m| m.len()).unwrap_or(0),
mkb_version = ?mkb_ver,
mkb_first_64 = %mkb_first_64_hex,
keydb_disc_count = keydb.disc_entries.len(),
keydb_dk_count = keydb.device_keys.len(),
keydb_pk_count = keydb.processing_keys.len(),
"AACS resolution inputs"
);
// Use handshake volume ID if available, otherwise zeros
// (KEYDB VUK lookup by disc hash works without volume ID)
let volume_id = handshake.map(|h| h.volume_id).unwrap_or([0u8; 16]);
+51 -30
View File
@@ -1545,7 +1545,7 @@ impl Disc {
let batch: u16 = match opts.batch_sectors {
Some(b) => b,
None if opts.skip_on_error => ecc_sectors(self.format),
None => DEFAULT_BATCH_SECTORS,
None => DEFAULT_BATCH_SECTORS_OPTICAL,
};
// Pre-compute the list of NonTried regions before handing the
@@ -3327,7 +3327,8 @@ impl Disc {
}
const MAX_BATCH_SECTORS: u16 = 510;
const DEFAULT_BATCH_SECTORS: u16 = 60;
const DEFAULT_BATCH_SECTORS_OPTICAL: u16 = 60;
const DEFAULT_BATCH_SECTORS_BLOCK: u16 = 8192;
const MIN_BATCH_SECTORS: u16 = 3;
pub(crate) fn ecc_sectors(format: DiscFormat) -> u16 {
@@ -3404,43 +3405,63 @@ mod severity_tests {
}
/// Detect the maximum transfer size in sectors for a device.
/// Reads /sys/block/<dev>/queue/max_hw_sectors_kb on Linux.
/// For sg devices, resolves the corresponding block device via sysfs.
/// Returns a value aligned to 3 sectors (one aligned unit).
pub fn detect_max_batch_sectors(device_path: &str) -> u16 {
let dev_name = device_path.rsplit('/').next().unwrap_or("");
if dev_name.is_empty() {
return DEFAULT_BATCH_SECTORS;
return DEFAULT_BATCH_SECTORS_OPTICAL;
}
// For sg devices, find the corresponding block device name
let block_name = if dev_name.starts_with("sg") {
let block_dir = format!("/sys/class/scsi_generic/{dev_name}/device/block");
std::fs::read_dir(&block_dir)
.ok()
.and_then(|mut entries| entries.next())
.and_then(|e| e.ok())
.map(|e| e.file_name().to_string_lossy().to_string())
} else {
Some(dev_name.to_string())
};
if let Some(bname) = block_name {
let sysfs_path = format!("/sys/block/{bname}/queue/max_hw_sectors_kb");
if let Ok(content) = std::fs::read_to_string(&sysfs_path) {
if let Ok(kb) = content.trim().parse::<u32>() {
// Convert KB to sectors (1 sector = 2 KB = 2048 bytes)
let sectors = (kb / 2) as u16;
// Align down to 3 (one aligned unit)
let aligned = (sectors / 3) * 3;
if aligned >= MIN_BATCH_SECTORS {
return aligned.min(MAX_BATCH_SECTORS);
// Check if optical drive (0x05 = CD/DVD)
let is_optical = (|| -> bool {
use std::path::Path;
let scsi_device_dir = "/sys/class/scsi_device/".to_string();
if let Ok(entries) = std::fs::read_dir(&scsi_device_dir) {
for entry in entries.flatten() {
let device_type_path = entry.path().join("device/type");
if Path::new(&device_type_path).exists() {
if let Ok(content) = std::fs::read_to_string(&device_type_path) {
// Type 0x05 (decimal 5) = CD/DVD drive
if content.trim().parse::<u32>() == Ok(5) {
return true;
}
}
}
}
}
false
})();
if is_optical {
// For sg devices, find the corresponding block device name
let block_name = if dev_name.starts_with("sg") {
let block_dir = format!("/sys/class/scsi_generic/{dev_name}/device/block");
std::fs::read_dir(&block_dir)
.ok()
.and_then(|mut entries| entries.next())
.and_then(|e| e.ok())
.map(|e| e.file_name().to_string_lossy().to_string())
} else {
Some(dev_name.to_string())
};
if let Some(bname) = block_name {
let sysfs_path = format!("/sys/block/{bname}/queue/max_hw_sectors_kb");
if let Ok(content) = std::fs::read_to_string(&sysfs_path) {
if let Ok(kb) = content.trim().parse::<u32>() {
// Convert KB to sectors (1 sector = 2 KB = 2048 bytes)
let sectors = (kb / 2) as u16;
// Align down to 3 (one aligned unit)
let aligned = (sectors / 3) * 3;
if aligned >= MIN_BATCH_SECTORS {
return aligned.min(MAX_BATCH_SECTORS);
}
}
}
}
DEFAULT_BATCH_SECTORS_OPTICAL
} else {
DEFAULT_BATCH_SECTORS_BLOCK
}
// Fallback: safe default well under typical kernel limits
DEFAULT_BATCH_SECTORS
}
// ─── Format helpers ────────────────────────────────────────────────────────
+4 -2
View File
@@ -27,5 +27,7 @@ pub(crate) use writeback_file::WritebackFile;
// caller — the targeted `#[allow]` keeps the re-export visible without
// dragging the rest of the module under `dead_code`.
#[allow(unused_imports)]
pub use pipeline::WRITE_THROUGH_DEPTH;
pub use pipeline::{DEFAULT_PIPELINE_DEPTH, Flow, Pipeline, Sink};
pub use pipeline::{
DEFAULT_PIPELINE_DEPTH, Flow, Pipeline, READ_PIPELINE_DEPTH, Sink, WRITE_PIPELINE_DEPTH,
WRITE_THROUGH_DEPTH,
};
+80 -20
View File
@@ -27,15 +27,11 @@
//! - Consumer panic is converted into
//! `Error::IoError { source: io::Error::other(...) }`.
//!
//! ## Dead-code suppression
//! ## Debug logging
//!
//! Both `Disc::sweep` (`DEFAULT_PIPELINE_DEPTH`, `spawn_named`,
//! `try_send`) and `Disc::patch` (`WRITE_THROUGH_DEPTH`, `Flow::Stop`)
//! are now in-tree callers (0.18 round 2). The targeted `#[allow]`
//! markers below cover the corners of the API not exercised by either
//! call site (e.g. `Pipeline::spawn` without a name; `Flow::Stop`
//! return path from sweep's sink — sweep always consumes the producer's
//! full work-list). Drop the allows once mux migrates.
//! Set `FREEMKV_DEBUG=1` environment variable to enable verbose debug
//! logging throughout the pipeline (channel sends/receives, backpressure,
//! consumer lag detection). This is critical for diagnosing stalls.
use std::io;
use std::sync::mpsc::{SyncSender, sync_channel};
@@ -43,20 +39,29 @@ use std::thread::{self, JoinHandle};
use crate::error::Error;
/// Check if verbose debug logging is enabled via FREEMKV_DEBUG env var.
pub fn debug_enabled() -> bool {
std::env::var("FREEMKV_DEBUG")
.ok()
.map(|v| v == "1" || v == "true" || v == "yes")
.unwrap_or(false)
}
/// Default channel depth for callers without a specific reason to
/// pick another value.
///
/// Empirically tuned for sweep and mux — both want enough slack that
/// short consumer stalls don't immediately back up onto the producer,
/// but not so much that a producer outpacing the consumer accumulates
/// arbitrary buffered work. `4` matches the depth sweep has used
/// since 0.17.11 (originally in `disc/sweep_pipeline.rs`, now in
/// `disc/sweep.rs::SweepSink`). Patch should usually use
/// [`WRITE_THROUGH_DEPTH`] (`1`) instead — write-through gives clean
/// back-pressure between every read attempt and the matching write,
/// which matters when the consumer is updating the mapfile in lockstep.
/// pick another value. Kept conservative (4) — most callers should
/// use READ_PIPELINE_DEPTH or WRITE_PIPELINE_DEPTH instead.
pub const DEFAULT_PIPELINE_DEPTH: usize = 4;
/// Read pipeline depth. Larger buffer compensates for drive variability
/// and NFS sync_file_range stalls; keeps ISO reader thread fed even when
/// consumer blocks on write.
pub const READ_PIPELINE_DEPTH: usize = 32;
/// Write pipeline depth. Smaller buffer reduces backpressure risk when
/// sync_file_range blocks; prevents producer from accumulating too much
/// work while consumer waits for NFS to drain.
pub const WRITE_PIPELINE_DEPTH: usize = 16;
/// Channel depth for write-through pipelines. Each `send` fully
/// drains before the next can enqueue. Use this when the producer
/// must observe consumer side-effects (e.g. mapfile state) before
@@ -149,6 +154,12 @@ impl<I: Send + 'static, R: Send + 'static> Pipeline<I, R> {
let mut stopped = false;
while let Ok(item) = rx.recv() {
if debug_enabled() {
tracing::debug!("Pipeline receive: item={}", std::any::type_name::<I>());
}
let apply_start = std::time::Instant::now();
if first_err.is_some() || stopped {
// Drain remaining items so the producer never
// blocks on a dead receiver. `apply` is not
@@ -159,11 +170,32 @@ impl<I: Send + 'static, R: Send + 'static> Pipeline<I, R> {
Ok(Flow::Continue) => {}
Ok(Flow::Stop) => {
stopped = true;
if debug_enabled() {
tracing::debug!("Pipeline: consumer returned Flow::Stop");
}
}
Err(e) => {
if debug_enabled() {
tracing::debug!("Pipeline: apply error, stopping, err={:?}", e);
}
first_err = Some(e);
}
}
let apply_elapsed = apply_start.elapsed();
if debug_enabled() && apply_elapsed > std::time::Duration::from_millis(100) {
tracing::debug!(
"Pipeline apply: took {:.2}s, item={}",
apply_elapsed.as_secs_f64(),
std::any::type_name::<I>()
);
} else if debug_enabled() {
tracing::debug!(
"Pipeline apply: OK in {:.3}ms, item={}",
apply_elapsed.as_micros(),
std::any::type_name::<I>()
);
}
}
match first_err {
@@ -188,7 +220,35 @@ impl<I: Send + 'static, R: Send + 'static> Pipeline<I, R> {
/// independent signal (e.g. `Halt`) — `send` alone is not the
/// notification edge.
pub fn send(&self, item: I) -> Result<(), I> {
self.tx.send(item).map_err(|e| e.0)
let start = std::time::Instant::now();
match self.tx.send(item) {
Ok(()) => {
let elapsed = start.elapsed();
if debug_enabled() && elapsed > std::time::Duration::from_millis(10) {
tracing::debug!(
"Pipeline send: blocked {:.2}s, item={}",
elapsed.as_secs_f64(),
std::any::type_name::<I>()
);
} else if debug_enabled() {
tracing::debug!("Pipeline send: OK in {:.3}ms", elapsed.as_micros());
}
Ok(())
}
Err(e) => {
let elapsed = start.elapsed();
if debug_enabled() && elapsed > std::time::Duration::from_millis(10) {
tracing::debug!(
"Pipeline send: blocked {:.2}s before channel closed, item={}",
elapsed.as_secs_f64(),
std::any::type_name::<I>()
);
} else if debug_enabled() {
tracing::debug!("Pipeline send: failed after {:.3}ms", elapsed.as_micros());
}
Err(e.0)
}
}
}
/// Non-blocking variant of [`Pipeline::send`]. If the channel is
+2 -2
View File
@@ -27,7 +27,7 @@ use std::path::Path;
use super::writeback::WritebackPipeline;
const CHUNK_BYTES: u64 = 32 * 1024 * 1024;
const WRITEBACK_CHUNK_BYTES: u64 = 32 * 1024 * 1024;
pub(crate) struct WritebackFile {
file: File,
@@ -42,7 +42,7 @@ impl WritebackFile {
/// or appended files).
pub(crate) fn new(mut file: File) -> io::Result<Self> {
let pos = file.stream_position()?;
let pipeline = WritebackPipeline::new(&file, pos, CHUNK_BYTES);
let pipeline = WritebackPipeline::new(&file, pos, WRITEBACK_CHUNK_BYTES);
Ok(Self {
file,
pipeline,
+10 -7
View File
@@ -82,7 +82,7 @@ pub mod event;
pub mod halt;
pub(crate) mod identity;
pub(crate) mod ifo;
pub(crate) mod io;
pub mod io;
pub mod keydb;
pub mod labels;
pub(crate) mod mpls;
@@ -128,16 +128,19 @@ pub use halt::Halt;
// Generic bounded producer/consumer primitive used by sweep, patch, and
// mux to overlap reads with writes via a dedicated consumer thread.
// `Pipeline::spawn(depth, sink)` spawns the consumer; `pipe.send(item)`
// `Pipeline::spawn(name, depth, sink)` spawns a named consumer; `pipe.send(item)`
// pushes one item with back-pressure; `pipe.finish()` joins the
// consumer and surfaces its `close()` output. Callers implement `Sink`
// to define per-item behaviour and end-of-stream finalisation.
//
// `DEFAULT_PIPELINE_DEPTH` (=4) is the depth sweep + mux use; patch
// uses `WRITE_THROUGH_DEPTH` (=1) so each read fully drains before the
// next can enqueue. Returning `Flow::Stop` from `apply` ends the
// consumer cleanly (still calls `close()`).
pub use io::pipeline::{DEFAULT_PIPELINE_DEPTH, Flow, Pipeline, Sink, WRITE_THROUGH_DEPTH};
// `DEFAULT_PIPELINE_DEPTH` (=4) is for callers without specific needs;
// most should use READ_PIPELINE_DEPTH or WRITE_PIPELINE_DEPTH instead.
// Patch uses `WRITE_THROUGH_DEPTH` (=1). Returning `Flow::Stop` from
// `apply` ends the consumer cleanly (still calls `close()`).
pub use io::pipeline::{
DEFAULT_PIPELINE_DEPTH, Flow, Pipeline, READ_PIPELINE_DEPTH, Sink, WRITE_PIPELINE_DEPTH,
WRITE_THROUGH_DEPTH,
};
// ─── Drive events (low-level callbacks) ─────────────────────────────────────
pub use event::{Event, EventKind};
+5 -1
View File
@@ -204,7 +204,11 @@ pub fn input(url: &str, opts: &InputOptions) -> io::Result<Box<dyn crate::pes::S
let title = disc.titles[idx].clone();
let keys = disc.decrypt_keys();
let format = disc.content_format;
let mut stream = DiscStream::new(Box::new(reader), title, keys, 64, format);
// ISO file: use large batch size (16 MB) — sequential read from fast storage, no bad sectors.
// Physical drives need small batches for adaptive error handling and retry logic.
const ISO_MUX_BATCH_SECTORS: u16 = 8192;
let mut stream =
DiscStream::new(Box::new(reader), title, keys, ISO_MUX_BATCH_SECTORS, format);
if opts.raw {
stream.set_raw();
}