libfreemkv: rc.5.1 DVD correctness fixes
- CSS: unlock scrambled-sector reads on enforcing drives via bus-auth only; classify sense 6F/03 as CSS-locked; early-bail on a fully locked scan; gate the AACS handshake off DVD discs. - DVD first-play menu no longer prepended to the feature: read the title VOBS base from vtstt_vobs (0xC4), not the menu VOBS vtsm_vobs (0xC0). - Interlaced field-duration (DefaultDecodedFieldDuration) written as a direct TrackEntry child rather than inside Video, so Windows reports the correct frame rate. - Audio channel count read from the AC-3 bitstream; FieldOrder set to TFF; per-track BPS tags. - Structured disc diagnostics at --log-level 3; reduced per-operation log spam.
This commit is contained in:
+46
-4
@@ -290,6 +290,16 @@ impl<I: Send + 'static, R: Send + 'static> Pipeline<I, R> {
|
||||
let mut first_err: Option<Error> = None;
|
||||
let mut stopped = false;
|
||||
|
||||
// Rolling apply-throughput summary. The per-item "apply: OK"
|
||||
// line was 99% of the mux log; collapse it into a periodic
|
||||
// summary (count, avg ms, items/s) emitted ~every 5 s while
|
||||
// debug tracing is on. The individual slow-apply ("took … s")
|
||||
// STALL events below stay visible — those are signal, not noise.
|
||||
let mut summary_count: u64 = 0;
|
||||
let mut summary_nanos: u128 = 0;
|
||||
let mut summary_since = Instant::now();
|
||||
const SUMMARY_INTERVAL: Duration = Duration::from_secs(5);
|
||||
|
||||
while let Ok(item) = rx.recv() {
|
||||
let debug = debug_enabled();
|
||||
if debug {
|
||||
@@ -338,21 +348,50 @@ impl<I: Send + 'static, R: Send + 'static> Pipeline<I, R> {
|
||||
if let Some(start) = apply_start {
|
||||
let apply_elapsed = start.elapsed();
|
||||
if apply_elapsed > Duration::from_millis(100) {
|
||||
// STALL event — a single slow apply. Keep it visible:
|
||||
// its presence is a signal, not per-frame noise.
|
||||
tracing::debug!(
|
||||
"Pipeline apply: took {:.2}s, item={}",
|
||||
apply_elapsed.as_secs_f64(),
|
||||
std::any::type_name::<I>()
|
||||
);
|
||||
} else {
|
||||
}
|
||||
// Benign per-item OK: roll into the periodic summary
|
||||
// rather than logging one line per frame.
|
||||
summary_count += 1;
|
||||
summary_nanos += apply_elapsed.as_nanos();
|
||||
if summary_since.elapsed() >= SUMMARY_INTERVAL && summary_count > 0 {
|
||||
let secs = summary_since.elapsed().as_secs_f64();
|
||||
let avg_ms = (summary_nanos as f64 / summary_count as f64) / 1_000_000.0;
|
||||
tracing::debug!(
|
||||
"Pipeline apply: OK in {:.3}ms, item={}",
|
||||
apply_elapsed.as_micros(),
|
||||
"Pipeline apply summary: {} items in {:.1}s, avg {:.3}ms, {:.0} items/s, type={}",
|
||||
summary_count,
|
||||
secs,
|
||||
avg_ms,
|
||||
summary_count as f64 / secs.max(1e-9),
|
||||
std::any::type_name::<I>()
|
||||
);
|
||||
summary_count = 0;
|
||||
summary_nanos = 0;
|
||||
summary_since = Instant::now();
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// Flush the residual apply-summary tail at end-of-stream so the
|
||||
// last partial window's item count isn't silently dropped.
|
||||
if summary_count > 0 && debug_enabled() {
|
||||
let secs = summary_since.elapsed().as_secs_f64();
|
||||
let avg_ms = (summary_nanos as f64 / summary_count as f64) / 1_000_000.0;
|
||||
tracing::debug!(
|
||||
"Pipeline apply summary (final): {} items in {:.1}s, avg {:.3}ms, type={}",
|
||||
summary_count,
|
||||
secs,
|
||||
avg_ms,
|
||||
std::any::type_name::<I>()
|
||||
);
|
||||
}
|
||||
|
||||
// Final abandonment check: the common leak case is a
|
||||
// consumer wedged inside `apply` (a blocking write
|
||||
// syscall). When that syscall finally returns, the
|
||||
@@ -401,13 +440,16 @@ impl<I: Send + 'static, R: Send + 'static> Pipeline<I, R> {
|
||||
if let Some(start) = start {
|
||||
let elapsed = start.elapsed();
|
||||
if elapsed > Duration::from_millis(10) {
|
||||
// BLOCKED event — back-pressure stall. Keep visible.
|
||||
tracing::debug!(
|
||||
"Pipeline send: blocked {:.2}s, item={}",
|
||||
elapsed.as_secs_f64(),
|
||||
std::any::type_name::<I>()
|
||||
);
|
||||
} else {
|
||||
tracing::debug!("Pipeline send: OK in {:.3}ms", elapsed.as_micros());
|
||||
// Benign per-item OK: trace-level (L4) only; the
|
||||
// apply-side rolling summary carries throughput.
|
||||
tracing::trace!("Pipeline send: OK in {:.3}ms", elapsed.as_micros());
|
||||
}
|
||||
}
|
||||
Ok(())
|
||||
|
||||
@@ -101,6 +101,13 @@ pub(crate) struct WritebackFile {
|
||||
file: File,
|
||||
pipeline: WritebackPipeline,
|
||||
pos: u64,
|
||||
/// Count of position-moving seeks (for the finalize summary). The MKV muxer
|
||||
/// seeks back occasionally (cluster size patching, Cues, Segment header
|
||||
/// backpatch); the per-seek DEBUG line is trace-level now, and this rolls
|
||||
/// the total into one finalize summary.
|
||||
seek_count: u64,
|
||||
/// Sum of |delta| over all position-moving seeks, in bytes.
|
||||
seek_bytes: u64,
|
||||
}
|
||||
|
||||
impl WritebackFile {
|
||||
@@ -115,6 +122,8 @@ impl WritebackFile {
|
||||
file,
|
||||
pipeline,
|
||||
pos,
|
||||
seek_count: 0,
|
||||
seek_bytes: 0,
|
||||
})
|
||||
}
|
||||
|
||||
@@ -176,6 +185,14 @@ impl WritebackFile {
|
||||
/// then external commit/DB update) must not treat `Ok(())` as a
|
||||
/// durability barrier.
|
||||
pub(crate) fn sync_all(&mut self) -> io::Result<()> {
|
||||
if self.seek_count > 0 {
|
||||
tracing::debug!(
|
||||
target: "mux",
|
||||
"WritebackFile finalize: {} seeks, {} bytes seeked total",
|
||||
self.seek_count,
|
||||
self.seek_bytes
|
||||
);
|
||||
}
|
||||
self.pipeline.finalize();
|
||||
platform::durable_sync(&self.file)
|
||||
}
|
||||
@@ -219,10 +236,14 @@ impl Seek for WritebackFile {
|
||||
let from_pos = self.pos;
|
||||
let to_pos = p;
|
||||
let delta: i64 = (to_pos as i64).wrapping_sub(from_pos as i64);
|
||||
tracing::debug!(
|
||||
// Per-seek detail is trace-level (L4) — benign and high-frequency.
|
||||
// The aggregate (count + total bytes) is logged once at finalize.
|
||||
tracing::trace!(
|
||||
target: "mux",
|
||||
"WritebackFile seek from={from_pos} to={to_pos} delta={delta}"
|
||||
);
|
||||
self.seek_count += 1;
|
||||
self.seek_bytes += delta.unsigned_abs();
|
||||
self.pipeline.handle_seek(p);
|
||||
self.pos = p;
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user