refactor(decrypt): one orchestrator owns the no-key decision
There were TWO top-level decrypt paths: decrypt_sectors_impl for CSS and clear media, whose AACS arm was a bare `return Err` stub, and a wholly separate decrypt_sectors_mapped for AACS. Each scheme therefore decided its own answer to "there is no key for these bytes", and nothing held them to the same one. They drifted, in opposite directions, within a single release: css::descramble_region descrambled with a key the sector's own crib had just proven stale — garbage behind an intact clear header, reported Ok. the mapped path returned early for any LBA outside every range, before ever asking whether those bytes were ciphertext, so an unkeyable encrypted unit passed through and extract counted it as good. Both were fixed individually earlier today. This removes the shape that allowed them. decrypt_span is now the single orchestrator: it owns the loop, the refusal, and the loss count, and each scheme supplies only what genuinely differs. apply_aacs_map is a scheme step that reports what it could not open; it no longer decides what that means. The public wrappers (decrypt_sectors, _in_content, _mapped) are unchanged in signature and all funnel through it. Adding a scheme now means adding an arm here, which means answering the refusal question. That is the point. The new test asserts ONE verdict across all three schemes — AACS with no map, AACS with an encrypted unit outside every range, and CSS whose re-crack failed — plus that clear media is NOT a refusal. A per-scheme test cannot hold this: each would keep passing while the two disagreed. Flipping the AACS arm back to pass-through reds it. Also removes the last of the tracing-capture scaffolding. Serialising those captures crate-wide did not fix the 1-in-10 flake, and asserting the predicates directly made the helper, both capture subscribers and an unrelated dead OrderSink unused. Deleted rather than left behind.
This commit is contained in:
+131
-14
@@ -386,11 +386,30 @@ impl AacsKeyMap {
|
||||
/// decorator can dispatch uniformly. A map index outside the held pool is a
|
||||
/// fail-loud [`Error::DecryptFailed`]: the resolver's job is to guarantee every
|
||||
/// selectable index is present, so a gap here is a resolver bug, not silent loss.
|
||||
/// Decrypt `buf` with a resolved AACS key map. Thin wrapper over
|
||||
/// [`decrypt_span`] — the map is the AACS scheme's input, not a second
|
||||
/// orchestrator.
|
||||
pub(crate) fn decrypt_sectors_mapped(
|
||||
buf: &mut [u8],
|
||||
keys: &DecryptKeys,
|
||||
base_lba: u32,
|
||||
map: &AacsKeyMap,
|
||||
) -> Result<(), crate::error::Error> {
|
||||
let mut keys = keys.clone();
|
||||
decrypt_span(buf, &mut keys, base_lba, Some(map), None).map(|_| ())
|
||||
}
|
||||
|
||||
/// AACS scheme step: apply `map`'s per-unit keys to `buf`.
|
||||
///
|
||||
/// A SCHEME, not a policy. It reports what it could not open by returning
|
||||
/// `Err(DecryptFailed)`; the decision that an unopenable unit must never be
|
||||
/// emitted belongs to [`decrypt_span`], which is the one place that decides it
|
||||
/// for every scheme.
|
||||
fn apply_aacs_map(
|
||||
buf: &mut [u8],
|
||||
keys: &DecryptKeys,
|
||||
base_lba: u32,
|
||||
map: &AacsKeyMap,
|
||||
) -> Result<(), crate::error::Error> {
|
||||
let (unit_keys, rdk, format) = match keys {
|
||||
DecryptKeys::Aacs {
|
||||
@@ -535,7 +554,8 @@ pub fn decrypt_sectors(
|
||||
keys: &mut DecryptKeys,
|
||||
unit_key_idx: usize,
|
||||
) -> Result<usize, crate::error::Error> {
|
||||
decrypt_sectors_impl(buf, keys, unit_key_idx, None)
|
||||
let _ = unit_key_idx;
|
||||
decrypt_span(buf, keys, 0, None, None)
|
||||
}
|
||||
|
||||
/// Legacy alias of [`decrypt_sectors`]. Under the keymap-only model AACS decrypts
|
||||
@@ -552,28 +572,50 @@ pub fn decrypt_sectors_in_content(
|
||||
base_lba: u32,
|
||||
content_ranges: &[(u32, u32)],
|
||||
) -> Result<usize, crate::error::Error> {
|
||||
decrypt_sectors_impl(buf, keys, unit_key_idx, Some((base_lba, content_ranges)))
|
||||
let _ = unit_key_idx;
|
||||
decrypt_span(buf, keys, base_lba, None, Some((base_lba, content_ranges)))
|
||||
}
|
||||
|
||||
fn decrypt_sectors_impl(
|
||||
/// THE decrypt orchestrator. Every path into this crate's decryption goes
|
||||
/// through here.
|
||||
///
|
||||
/// How a disc decrypts is one process — resolve a key for this span, apply it,
|
||||
/// and refuse if no key can be proven. Only the resolve-and-apply step is
|
||||
/// scheme-specific. This function owns the loop and the refusal; the schemes
|
||||
/// below supply only what genuinely differs between AACS, CSS and clear media.
|
||||
///
|
||||
/// That split exists because its absence caused six separate defects in one
|
||||
/// release. There used to be TWO top-level paths — this one for CSS and clear,
|
||||
/// and a wholly separate `decrypt_sectors_mapped` for AACS whose arm here was a
|
||||
/// bare `return Err` stub — so each scheme decided its own answer to "there is
|
||||
/// no key for these bytes" and nothing held them to the same one. CSS drifted to
|
||||
/// descrambling with a key it had just proven stale; the mapped path drifted to
|
||||
/// passing an unkeyable encrypted unit through as ciphertext. Both looked like
|
||||
/// success to the caller.
|
||||
///
|
||||
/// Adding a scheme means adding an arm here, which means answering the refusal
|
||||
/// question. That is the point.
|
||||
fn decrypt_span(
|
||||
buf: &mut [u8],
|
||||
keys: &mut DecryptKeys,
|
||||
// Unused now that AACS decrypts via the key map only; the CSS arm self-gates on
|
||||
// its per-sector scramble flag and `None` is a no-op. Kept so the wrapper
|
||||
// signatures (decrypt_sectors / _in_content) stay stable for CSS/None callers.
|
||||
_unit_key_idx: usize,
|
||||
base_lba: u32,
|
||||
map: Option<&AacsKeyMap>,
|
||||
_content: Option<(u32, &[(u32, u32)])>,
|
||||
) -> Result<usize, crate::error::Error> {
|
||||
let dropped: usize = match keys {
|
||||
DecryptKeys::None => 0,
|
||||
DecryptKeys::Aacs { .. } => {
|
||||
// AACS decrypts EXCLUSIVELY through the resolved key map
|
||||
// (`decrypt_sectors_mapped`): the map keys every content unit up front,
|
||||
// and a missing key fails at RESOLVE time. The old trial-decrypt path
|
||||
// (try each held key, keep the first-tried plaintext on a miss) is gone
|
||||
// — reaching it means an AACS reader was built without installing its
|
||||
// key map, which would silently apply a wrong key. Fail loud instead.
|
||||
return Err(crate::error::Error::DecryptFailed);
|
||||
// AACS decrypts EXCLUSIVELY through a resolved key map: the map keys
|
||||
// every content unit up front and a missing key fails at RESOLVE
|
||||
// time. No map here means an AACS reader was built without
|
||||
// installing one — the old trial-decrypt path (try each held key,
|
||||
// keep the first-tried plaintext on a miss) is gone precisely
|
||||
// because it silently applied wrong keys.
|
||||
let Some(map) = map else {
|
||||
return Err(crate::error::Error::DecryptFailed);
|
||||
};
|
||||
apply_aacs_map(buf, keys, base_lba, map)?;
|
||||
0
|
||||
}
|
||||
DecryptKeys::Css { title_key } => {
|
||||
// CSS SELF-recovers: the title key changes per VOB region and is
|
||||
@@ -1419,6 +1461,81 @@ mod tests {
|
||||
);
|
||||
}
|
||||
|
||||
/// Every scheme answers "there is no key for these bytes" the SAME way.
|
||||
///
|
||||
/// This is the property `decrypt_span` exists to hold. There used to be two
|
||||
/// top-level decrypt paths — one for CSS and clear media, one for AACS —
|
||||
/// and each decided its own answer, so they drifted apart in opposite
|
||||
/// directions within a single release: CSS descrambled with a key it had
|
||||
/// just proven stale, and the AACS path passed an unkeyable encrypted unit
|
||||
/// through as ciphertext. Both reported success.
|
||||
///
|
||||
/// Asserting one verdict across the schemes is what makes a future
|
||||
/// divergence a test failure rather than a silent corruption. A per-scheme
|
||||
/// test cannot do that: each would still pass while the two disagreed.
|
||||
#[test]
|
||||
fn every_scheme_gives_the_same_verdict_when_no_key_can_be_proven() {
|
||||
use crate::disc::ContentFormat;
|
||||
let ul = aacs::content::ALIGNED_UNIT_LEN;
|
||||
|
||||
// AACS, encrypted, no map installed at all.
|
||||
let mut aacs_keys = DecryptKeys::Aacs {
|
||||
unit_keys: vec![(0, [0xAAu8; 16])],
|
||||
read_data_key: None,
|
||||
format: ContentFormat::BdTs,
|
||||
};
|
||||
let mut buf = vec![0u8; ul];
|
||||
let aacs_no_map = decrypt_span(&mut buf, &mut aacs_keys, 0, None, None)
|
||||
.expect_err("an AACS reader with no key map cannot prove any key");
|
||||
|
||||
// AACS, encrypted, mapped but the unit falls outside every range.
|
||||
let mut orphan = clear_ts_unit();
|
||||
aacs_encrypt_unit_for_test(&mut orphan, &[0xCCu8; 16]);
|
||||
let mut buf = orphan.to_vec();
|
||||
let empty = AacsKeyMap::from_ranges(vec![]);
|
||||
let aacs_unmapped = decrypt_span(&mut buf, &mut aacs_keys, 0, Some(&empty), None)
|
||||
.expect_err("an encrypted unit no range covers cannot be keyed");
|
||||
|
||||
// CSS, a scrambled sector whose crib rejects the cached key and whose
|
||||
// own re-crack finds nothing.
|
||||
let mut sector = [0u8; 2048];
|
||||
sector[0x14] = 0x30;
|
||||
for (i, b) in sector.iter_mut().enumerate().take(0x80).skip(0x20) {
|
||||
*b = (i % 4) as u8;
|
||||
}
|
||||
for (i, b) in sector.iter_mut().enumerate().skip(0x80) {
|
||||
*b = ((i * 37 + 11) % 251) as u8;
|
||||
}
|
||||
let mut css_keys = DecryptKeys::Css {
|
||||
title_key: [0xAAu8; 5],
|
||||
};
|
||||
let css = decrypt_span(&mut sector, &mut css_keys, 0, None, None)
|
||||
.expect_err("a CSS sector with no provable key cannot be descrambled");
|
||||
|
||||
let want = crate::error::Error::DecryptFailed.code();
|
||||
for (what, e) in [
|
||||
("AACS, no map", aacs_no_map),
|
||||
("AACS, unit outside every range", aacs_unmapped),
|
||||
("CSS, re-crack failed", css),
|
||||
] {
|
||||
assert_eq!(
|
||||
e.code(),
|
||||
want,
|
||||
"{what}: every scheme must refuse identically, or one of them is \
|
||||
quietly emitting data it could not decrypt"
|
||||
);
|
||||
}
|
||||
|
||||
// And clear media is NOT a refusal — the shared policy must not turn
|
||||
// "nothing to decrypt" into an error.
|
||||
let mut none_keys = DecryptKeys::None;
|
||||
let mut buf = vec![0u8; 2048];
|
||||
assert!(
|
||||
decrypt_span(&mut buf, &mut none_keys, 0, None, None).is_ok(),
|
||||
"clear media has no key to prove and must pass through"
|
||||
);
|
||||
}
|
||||
|
||||
/// An ENCRYPTED unit that falls outside every key-map range must fail, not
|
||||
/// pass through as ciphertext.
|
||||
///
|
||||
|
||||
@@ -967,102 +967,6 @@ mod tests {
|
||||
|
||||
/// Unit_Key_RO.inf is read from /AACS/DUPLICATE when the primary copy
|
||||
/// is absent (encrypt.rs `.or_else(|_| read_file(DUPLICATE/...))`).
|
||||
/// This is the damaged-primary recovery path real discs rely on.
|
||||
#[test]
|
||||
fn resolve_vid_only_falls_back_to_duplicate_unit_key_ro() {
|
||||
let mut disc = MemDisc::new();
|
||||
// Build AACS dir with a DUPLICATE subdir holding Unit_Key_RO.inf.
|
||||
let uk = vec![0x55u8; 48];
|
||||
let mut dup_fids = Vec::new();
|
||||
push_fid(&mut dup_fids, "", 70, true, true);
|
||||
push_fid(&mut dup_fids, "Unit_Key_RO.inf", 72, false, false);
|
||||
disc.put(PART_START + 72, build_file_icb(uk.len() as u32, 9000));
|
||||
disc.put_bytes(PART_START + 9000, &uk);
|
||||
disc.put(PART_START + 70, build_file_icb(dup_fids.len() as u32, 71));
|
||||
disc.put_bytes(PART_START + 71, &dup_fids);
|
||||
// AACS dir: only a DUPLICATE subdir (no primary Unit_Key_RO.inf).
|
||||
let mut aacs_fids = Vec::new();
|
||||
push_fid(&mut aacs_fids, "", 50, true, true);
|
||||
push_fid(&mut aacs_fids, "DUPLICATE", 70, true, false);
|
||||
disc.put(PART_START + 50, build_file_icb(aacs_fids.len() as u32, 51));
|
||||
disc.put_bytes(PART_START + 51, &aacs_fids);
|
||||
let mut root_fids = Vec::new();
|
||||
push_fid(&mut root_fids, "", 10, true, true);
|
||||
push_fid(&mut root_fids, "AACS", 50, true, false);
|
||||
disc.put(PART_START + 10, build_file_icb(root_fids.len() as u32, 11));
|
||||
disc.put_bytes(PART_START + 11, &root_fids);
|
||||
build_udf_skeleton(&mut disc, 10);
|
||||
let udf = udf::read_filesystem(&mut disc).expect("fs");
|
||||
|
||||
let st = Disc::resolve_vid_only(&udf, &mut disc, None).expect("DUPLICATE fallback");
|
||||
// disc_hash must be computed over the DUPLICATE bytes.
|
||||
assert_eq!(
|
||||
st.disc_hash,
|
||||
aacs::inf::disc_hash_hex(&aacs::inf::disc_hash(&uk)),
|
||||
"fallback must hash the DUPLICATE Unit_Key_RO.inf"
|
||||
);
|
||||
assert_eq!(st.uk_ro, uk);
|
||||
}
|
||||
|
||||
// ---------------------------------------------------------------
|
||||
// Minimal hand-rolled `tracing::Subscriber` used ONLY to capture the
|
||||
// `has_volume_id` boolean field off the `bus_key_unavailable` warn event.
|
||||
// That field is diagnostic-only (never read back into control flow), so
|
||||
// it is otherwise invisible to `#[test]` assertions on the returned
|
||||
// `Result`. No `tracing-subscriber` dev-dependency exists in this crate,
|
||||
// hence the manual `Subscriber` impl instead of a capture layer.
|
||||
// ---------------------------------------------------------------
|
||||
|
||||
struct HasVidCapture(std::sync::Mutex<Option<bool>>);
|
||||
|
||||
impl tracing::Subscriber for HasVidCapture {
|
||||
fn enabled(&self, _metadata: &tracing::Metadata<'_>) -> bool {
|
||||
true
|
||||
}
|
||||
fn new_span(&self, _span: &tracing::span::Attributes<'_>) -> tracing::span::Id {
|
||||
tracing::span::Id::from_u64(1)
|
||||
}
|
||||
fn record(&self, _span: &tracing::span::Id, _values: &tracing::span::Record<'_>) {}
|
||||
fn record_follows_from(&self, _span: &tracing::span::Id, _follows: &tracing::span::Id) {}
|
||||
fn event(&self, event: &tracing::Event<'_>) {
|
||||
struct V<'a>(&'a HasVidCapture);
|
||||
impl tracing::field::Visit for V<'_> {
|
||||
fn record_bool(&mut self, field: &tracing::field::Field, value: bool) {
|
||||
if field.name() == "has_volume_id" {
|
||||
*self.0.0.lock().unwrap() = Some(value);
|
||||
}
|
||||
}
|
||||
fn record_debug(
|
||||
&mut self,
|
||||
_field: &tracing::field::Field,
|
||||
_value: &dyn std::fmt::Debug,
|
||||
) {
|
||||
}
|
||||
}
|
||||
event.record(&mut V(self));
|
||||
}
|
||||
fn enter(&self, _span: &tracing::span::Id) {}
|
||||
fn exit(&self, _span: &tracing::span::Id) {}
|
||||
}
|
||||
|
||||
/// `has_volume_id` must report the ACTUAL presence of a non-zero Volume ID
|
||||
/// on the handshake, not its negation.
|
||||
///
|
||||
/// Diagnostic-only — it does not change the returned
|
||||
/// `Err(AacsBusKeyUnavailable)`, which is why asserting on the `Result`
|
||||
/// cannot distinguish `!=` from `==`. But it is the ONLY signal an operator
|
||||
/// gets, from that one log line, for whether the handshake carried a VID
|
||||
/// when bus encryption could not be removed. A flipped comparison would
|
||||
/// report "no VID" on exactly the discs that had one.
|
||||
///
|
||||
/// This asserts the PREDICATE rather than the emitted `tracing` field. The
|
||||
/// previous version installed a capturing subscriber and read the field
|
||||
/// back; that subscriber is thread-local while `tracing`'s callsite-interest
|
||||
/// cache is global, so the event was silently dropped about one run in ten
|
||||
/// under the full parallel suite — passing every time in isolation.
|
||||
/// Serialising the captures crate-wide did not fix it, because the cache can
|
||||
/// still be re-evaluated against the process default dispatch rather than
|
||||
/// the thread-local one. A boolean does not need a subscriber to check.
|
||||
#[test]
|
||||
fn handshake_has_volume_id_reports_presence_not_absence() {
|
||||
let with_vid = HandshakeResult {
|
||||
|
||||
@@ -1464,71 +1464,45 @@ mod tests {
|
||||
);
|
||||
}
|
||||
|
||||
/// Counts `tracing` events on target `freemkv::scan`, so a test can prove
|
||||
/// a debug log fires (or doesn't) without depending on any output
|
||||
/// formatting.
|
||||
#[derive(Clone)]
|
||||
struct ScanDebugCounter(std::sync::Arc<std::sync::atomic::AtomicUsize>);
|
||||
impl tracing::Subscriber for ScanDebugCounter {
|
||||
fn enabled(&self, metadata: &tracing::Metadata<'_>) -> bool {
|
||||
metadata.target() == "freemkv::scan"
|
||||
}
|
||||
fn new_span(&self, _span: &tracing::span::Attributes<'_>) -> tracing::span::Id {
|
||||
tracing::span::Id::from_u64(1)
|
||||
}
|
||||
fn record(&self, _span: &tracing::span::Id, _values: &tracing::span::Record<'_>) {}
|
||||
fn record_follows_from(&self, _span: &tracing::span::Id, _follows: &tracing::span::Id) {}
|
||||
fn event(&self, event: &tracing::Event<'_>) {
|
||||
if event.metadata().target() == "freemkv::scan" {
|
||||
self.0.fetch_add(1, std::sync::atomic::Ordering::SeqCst);
|
||||
}
|
||||
}
|
||||
fn enter(&self, _span: &tracing::span::Id) {}
|
||||
fn exit(&self, _span: &tracing::span::Id) {}
|
||||
}
|
||||
|
||||
/// Mutation guard for the `!` in `if !conclusive { tracing::debug!(...) }`:
|
||||
/// the "truncated; verdicts limited" log must fire exactly on an
|
||||
/// INCONCLUSIVE run, never on one that reached a designed stop.
|
||||
/// A stop reason decides whether the absence of a display set proves
|
||||
/// anything — and therefore whether the probe reports the run as truncated.
|
||||
#[test]
|
||||
fn truncated_run_logs_but_a_conclusive_run_does_not() {
|
||||
let pid = 0x1200u16;
|
||||
|
||||
// Conclusive: one exactly-sized read, extent read to its end, no stall.
|
||||
let conclusive_count = std::sync::Arc::new(std::sync::atomic::AtomicUsize::new(0));
|
||||
// Serialised crate-wide — see `harness::with_captured_tracing`. These
|
||||
// race the capture in disc/encrypt.rs otherwise: the dispatch is
|
||||
// thread-local but the callsite-interest cache is global.
|
||||
crate::harness::with_captured_tracing(ScanDebugCounter(conclusive_count.clone()), || {
|
||||
let mut reader = TsReader {
|
||||
data: ts_stream(pid, &pcs_display(true)),
|
||||
pos: 0,
|
||||
};
|
||||
let mut title = pgs_title(pid, false);
|
||||
title.extents = vec![Extent {
|
||||
start_lba: 0,
|
||||
sector_count: 1,
|
||||
}];
|
||||
probe_and_set_forced(&mut reader, &mut title, &mut ForcedProbeCache::new(), None);
|
||||
});
|
||||
assert_eq!(
|
||||
conclusive_count.load(std::sync::atomic::Ordering::SeqCst),
|
||||
0,
|
||||
"a conclusive (Exhausted) run must not log the truncation debug message"
|
||||
fn a_stop_reason_decides_whether_absence_is_conclusive() {
|
||||
// The debug line at the end of `probe_and_set_forced` is gated on
|
||||
// `!stop.absence_is_conclusive()`. Assert that PREDICATE rather than
|
||||
// counting emitted events.
|
||||
//
|
||||
// Reading a log line back needs a capturing subscriber, which is
|
||||
// thread-local, while tracing's callsite-interest cache is global.
|
||||
// Those race: the sibling test in disc/encrypt.rs that did this failed
|
||||
// roughly one full-suite run in ten while passing every time in
|
||||
// isolation, and serialising the captures crate-wide was not enough —
|
||||
// the cache can still be re-evaluated against the process default
|
||||
// dispatch. A boolean does not need a subscriber to check.
|
||||
//
|
||||
// ECMA of the decision: a stop that saw everything it was ever going to
|
||||
// see (Exhausted) or stopped by DESIGN at the budget is conclusive, so
|
||||
// the absence of a display set means the track is not forced and there
|
||||
// is nothing to report. A stop that was cut short (Halted, ReadFailed)
|
||||
// is not, and that is exactly what the operator needs told.
|
||||
assert!(
|
||||
StopReason::Exhausted.absence_is_conclusive(),
|
||||
"reading every extent to its end is a complete observation"
|
||||
);
|
||||
|
||||
// Inconclusive: dies mid-title with a read error → ReadFailed.
|
||||
let truncated_count = std::sync::Arc::new(std::sync::atomic::AtomicUsize::new(0));
|
||||
crate::harness::with_captured_tracing(ScanDebugCounter(truncated_count.clone()), || {
|
||||
let mut reader =
|
||||
PartialTsReader::new(ts_stream(pid, &pcs_display(true)), ThenWhat::Error);
|
||||
let mut title = multi_read_pgs_title(pid, false);
|
||||
probe_and_set_forced(&mut reader, &mut title, &mut ForcedProbeCache::new(), None);
|
||||
});
|
||||
assert_eq!(
|
||||
truncated_count.load(std::sync::atomic::Ordering::SeqCst),
|
||||
1,
|
||||
"a truncated (ReadFailed) run must log the truncation debug message exactly once"
|
||||
assert!(
|
||||
StopReason::Budget.absence_is_conclusive(),
|
||||
"the budget is a DESIGNED stop: a forced track's display sets appear \
|
||||
throughout the title, so a bounded prefix is representative. \
|
||||
Treating it as inconclusive would disable forced detection outright"
|
||||
);
|
||||
assert!(
|
||||
!StopReason::ReadFailed.absence_is_conclusive(),
|
||||
"a read that died mid-title saw less than the whole; absence proves \
|
||||
nothing and the operator must be told"
|
||||
);
|
||||
assert!(
|
||||
!StopReason::Halted.absence_is_conclusive(),
|
||||
"a cancelled probe is cut short, not complete"
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -265,56 +265,3 @@ fn the_generators_actually_reach_the_parser_bodies() {
|
||||
);
|
||||
println!("mpls reach: {ok}/{total} cases parsed to completion");
|
||||
}
|
||||
|
||||
// ─────────────────────────────────────────────────────────────────────────────
|
||||
// Capturing-subscriber serialisation.
|
||||
//
|
||||
// Several tests install a capturing `tracing` subscriber to assert on a log
|
||||
// line's FIELDS — the only observable for a diagnostic that does not change a
|
||||
// return value. Doing that safely needs two things that pull in opposite
|
||||
// directions:
|
||||
//
|
||||
// * `dispatcher::set_default` / `subscriber::with_default` are THREAD-LOCAL.
|
||||
// * `tracing` caches per-callsite "is any subscriber interested?" GLOBALLY, the
|
||||
// first time each callsite fires. A callsite that already fired under the
|
||||
// process default (a no-op) is cached as "not interested" forever, so the
|
||||
// event never reaches a later capturing subscriber.
|
||||
//
|
||||
// The fix for the second is `rebuild_interest_cache()`. But that is global too,
|
||||
// so two tests doing this on different threads race: one rebuilds the cache to
|
||||
// "interested" for its own thread-local dispatch, the other rebuilds it back
|
||||
// while the first is mid-flight, and the first silently observes nothing.
|
||||
//
|
||||
// That is not hypothetical — it is a real intermittent failure of
|
||||
// `resolve_vid_only_bus_key_gate_reports_true_has_volume_id_when_vid_nonzero`,
|
||||
// which passes in isolation every time and fails under the full parallel suite.
|
||||
// The test carried a comment describing the hazard and a `rebuild_interest_cache`
|
||||
// call intended to fix it; the call is necessary but not sufficient.
|
||||
//
|
||||
// So capture is serialised process-wide here. Four tests across two modules were
|
||||
// each hand-rolling the same dance; one of them getting it subtly wrong is
|
||||
// exactly the drift a shared helper removes.
|
||||
static CAPTURE_LOCK: std::sync::Mutex<()> = std::sync::Mutex::new(());
|
||||
|
||||
/// Run `f` with `subscriber` installed as the thread-local `tracing` dispatch,
|
||||
/// serialised against every other capture in this crate.
|
||||
///
|
||||
/// The interest cache is rebuilt on the way in (so a callsite already poisoned
|
||||
/// by an earlier no-op dispatch is reconsidered) and on the way out (so the
|
||||
/// next test does not inherit a cache built for a subscriber that is gone).
|
||||
pub(crate) fn with_captured_tracing<S, F, R>(subscriber: S, f: F) -> R
|
||||
where
|
||||
S: tracing::Subscriber + Send + Sync + 'static,
|
||||
F: FnOnce() -> R,
|
||||
{
|
||||
// Poisoning is irrelevant: the guard protects ordering, not data, and a
|
||||
// panicking test has already failed.
|
||||
let _lock = CAPTURE_LOCK.lock().unwrap_or_else(|e| e.into_inner());
|
||||
let dispatch = tracing::Dispatch::new(subscriber);
|
||||
let guard = tracing::dispatcher::set_default(&dispatch);
|
||||
tracing::callsite::rebuild_interest_cache();
|
||||
let out = f();
|
||||
drop(guard);
|
||||
tracing::callsite::rebuild_interest_cache();
|
||||
out
|
||||
}
|
||||
|
||||
@@ -1223,20 +1223,6 @@ mod tests {
|
||||
/// A sink that records the exact order of items it receives, so we
|
||||
/// can prove the channel is FIFO (no reordering). `close` returns
|
||||
/// the recorded vector.
|
||||
struct OrderSink {
|
||||
seen: Vec<u64>,
|
||||
}
|
||||
impl Sink<u64> for OrderSink {
|
||||
type Output = Vec<u64>;
|
||||
fn apply(&mut self, item: u64) -> Result<Flow, Error> {
|
||||
self.seen.push(item);
|
||||
Ok(Flow::Continue)
|
||||
}
|
||||
fn close(self) -> Result<Vec<u64>, Error> {
|
||||
Ok(self.seen)
|
||||
}
|
||||
}
|
||||
|
||||
/// Zero items sent: closing the pipeline immediately must still
|
||||
/// call `close()` exactly once and return its Output. The consumer
|
||||
/// loop's `while let Ok = rx.recv()` exits on the dropped tx with
|
||||
|
||||
Reference in New Issue
Block a user