anodizer_core/log.rs
1//! Thin structured logging helper for anodizer stages.
2//!
3//! Provides level-gated output to stderr in a single unified style ("format
4//! B"). Keeps stdout clean for machine-parseable output (e.g. `anodizer tag`).
5//!
6//! # Output style
7//!
8//! Two visual registers, one source of truth — never hand-format a stage line:
9//!
10//! ```text
11//! Checking determinism ← SECTION HEADER (group / step)
12//! • targets aarch64-… ← META key/value row (kv)
13//! • stages build, sign ← META key/value row (kv)
14//! • runs 2 ← META key/value row (kv)
15//! Building binaries ← SECTION HEADER
16//! • compiling x86_64-… ← DETAIL / info line (detail / status)
17//! ✓ x86_64-… 1.2 MiB ← SUCCESS line (success)
18//! ✗ aarch64-… build failed ← FAILURE line (failure)
19//! ```
20//!
21//! Body lines belonging to a [`StageLogger::group`] section additionally
22//! carry the section's 2-space nesting indent, so a header's own detail
23//! rows sit one level beneath it (the indents in the sketch above are
24//! relative, not absolute columns).
25//!
26//! - **Section headers** ([`StageLogger::step`] / [`StageLogger::group`]) put a
27//! bold-green present-participle verb (the leading word of the stage's
28//! [`stage_header`] phrase) right-aligned in a fixed 12-column gutter, then
29//! one space, then the message. ONLY verbs live in this gutter — never a
30//! lowercase key.
31//! - **Body lines** ([`StageLogger::detail`] / [`success`] / [`failure`], plus
32//! the retargeted [`StageLogger::status`]) sit at a 3-space body indent under
33//! their header, prefixed by a marker — `•` info (cyan), `✓` success (green),
34//! `✗` failure (red) — one space, then the text.
35//! - **Key/value rows** ([`StageLogger::kv`]) are `•` detail lines whose
36//! lowercase dimmed key is padded so the values align within a group.
37//! - **Status labels** (`Warning` / `Error` / `Note`, via
38//! [`render_warning`] / [`render_error`] / [`render_note`]) render the label
39//! right-aligned in the same verb gutter as a section header (no colon), so
40//! their messages align with the header messages above them.
41//!
42//! [`success`]: StageLogger::success
43//! [`failure`]: StageLogger::failure
44//!
45//! # Verbosity levels
46//!
47//! - **quiet**: errors only (for CI where only failures matter)
48//! - **default**: status messages (stage start/complete, key actions)
49//! - **verbose**: detail (command output, env vars, file paths)
50//! - **debug**: everything (HTTP request/response, template contexts, resolved config)
51//!
52//! # Secret redaction
53//!
54//! Every `StageLogger` carries an optional env-pairs list that drives the
55//! redaction policy applied inside [`StageLogger::check_output`]. Callers
56//! that go through [`crate::context::Context::logger`] inherit the merged
57//! `{process env, config env}` pairs automatically; manual constructors
58//! (`StageLogger::new`) start with no env and can be enriched via
59//! [`StageLogger::with_env`]. Stderr / stdout interpolated into log lines
60//! or `bail!` messages is therefore redacted without callers having to
61//! remember to scrub at every site.
62
63use std::sync::Arc;
64use std::sync::Mutex;
65use std::sync::OnceLock;
66use std::sync::atomic::{AtomicUsize, Ordering};
67
68use colored::Colorize;
69
70/// Secret-redaction table shape shared by [`StageLogger`] and
71/// [`crate::context::Context`]: a live, shareable cell of `(env-var name,
72/// value)` pairs. Named so the field/parameter declarations that use it
73/// don't repeat the nested `Arc<Mutex<Vec<(String, String)>>>` shape (which
74/// clippy's `type_complexity` lint flags on the raw form).
75pub(crate) type RedactionEnv = Arc<Mutex<Vec<(String, String)>>>;
76
77/// Process-global section nesting depth. Drives the 2-space-per-level
78/// indentation applied to every stderr log line so output produced
79/// inside a [`StageLogger::group`] sits visually beneath its header.
80///
81/// A single atomic (rather than per-logger state) is correct because the
82/// release pipeline drives one stderr stream and no `group()` is ever
83/// opened from a worker thread — sections bracket whole stages on the
84/// main thread, while a stage's interior parallelism (e.g. `build`
85/// spawning per-target threads) emits *inside* an already-open section.
86/// The depth is therefore a property of "where the main thread is in the
87/// run", not of any individual logger clone or worker.
88static SECTION_DEPTH: AtomicUsize = AtomicUsize::new(0);
89
90/// Env var carrying a parent `anodizer` process's visual nesting depth.
91///
92/// The determinism harness spawns child `anodizer release` subprocesses
93/// whose stderr is inherited, so the child's lines interleave directly
94/// into the parent's stream. Without an inherited base depth the child's
95/// section headers would render flush-left, visually escaping the
96/// parent's open section. The parent exports its depth here; the child
97/// reads it once (see [`base_depth`]) and offsets every indent by it.
98pub const LOG_DEPTH_ENV: &str = "ANODIZER_LOG_DEPTH";
99
100/// Base nesting depth inherited from a parent process via
101/// [`LOG_DEPTH_ENV`], parsed once on first use. Zero when the var is
102/// absent or unparseable (a standalone process indents from column 0).
103static BASE_DEPTH: OnceLock<usize> = OnceLock::new();
104
105/// Parse the inherited base depth from a raw [`LOG_DEPTH_ENV`] value.
106/// Lenient by design: a missing or malformed value degrades to 0 (the
107/// standalone-process default) rather than failing — indentation is
108/// presentation, never worth aborting a release over.
109fn parse_base_depth(raw: Option<&str>) -> usize {
110 raw.and_then(|v| v.trim().parse().ok()).unwrap_or(0)
111}
112
113/// The process's inherited base depth (see [`LOG_DEPTH_ENV`]).
114fn base_depth() -> usize {
115 *BASE_DEPTH.get_or_init(|| parse_base_depth(std::env::var(LOG_DEPTH_ENV).ok().as_deref()))
116}
117
118/// Current absolute nesting depth: the inherited base plus every open
119/// section. This is the value [`indent`] renders and the value a parent
120/// exports (offset for the child's nesting) when spawning a subprocess
121/// whose stderr joins this process's stream.
122pub fn current_depth() -> usize {
123 base_depth() + SECTION_DEPTH.load(Ordering::Relaxed)
124}
125
126/// A section header that has been opened ([`StageLogger::group`]) but not yet
127/// printed. The header line is deferred until the section actually emits a
128/// body line, so a stage that does nothing prints nothing at all (matching
129/// GoReleaser, which only prints a section header once the section has output).
130struct PendingHeader {
131 /// Section depth captured at open time. The header renders at *this* depth,
132 /// not the current global depth, so a nested section's deferred header is
133 /// still indented to its own level when flushed alongside its ancestors.
134 depth: usize,
135 /// Right-aligned bold-green verb (the leading word of the stage's
136 /// [`stage_header`] phrase).
137 verb: String,
138 /// The remaining words of the phrase, printed after the verb (empty for a
139 /// single-word phrase, which renders a bare gutter verb).
140 msg: String,
141 /// Whether this header has already been printed. A flushed entry stays on
142 /// the stack (so the LIFO pop in [`SectionGuard::drop`] removes the right
143 /// one) but is never reprinted.
144 flushed: bool,
145}
146
147/// Stack of section headers awaiting their first body line. Pushed by
148/// [`StageLogger::group`], drained by [`flush_pending`] when a real line is
149/// about to print, and popped (LIFO) by [`SectionGuard::drop`].
150///
151/// A `Mutex` (not a thread-local) because sections are opened on the main
152/// thread like [`SECTION_DEPTH`], but body lines may flush from a stage's
153/// worker threads (e.g. `build` spawning per-target threads). The lock
154/// serializes the flush state transition: each header's `flushed` flag flips
155/// under the lock, so a header prints exactly once — never lost, never
156/// duplicated. Header-before-body ordering holds because every emit method
157/// calls [`flush_pending`] then writes its body line with no early return
158/// between. It does not serialize body-line-vs-body-line ordering across
159/// workers — two `build` threads may print their body lines in either order
160/// under a just-flushed header, matching build's existing unordered parallel
161/// output.
162static PENDING: Mutex<Vec<PendingHeader>> = Mutex::new(Vec::new());
163
164/// Print every still-unflushed pending section header, in ancestor-first
165/// (bottom-to-top) order, then mark each flushed.
166///
167/// Called immediately before any method actually writes a visible body line,
168/// so the deferred headers appear above their first line in correct nesting
169/// order. A header renders at its own stored [`PendingHeader::depth`] — the
170/// 2-space-per-level indent, the right-aligned bold-green verb in the
171/// [`VERB_COLUMN`] gutter, then (if non-empty) one space and the message.
172///
173/// No-op when nothing is pending (the common case once a section has already
174/// emitted its first line), so the per-body-line cost is one uncontended lock.
175fn flush_pending() {
176 // Recover a poisoned guard rather than bailing: pending headers are pure
177 // presentation state, and silently muting every section header for the
178 // rest of the run on one panic-mid-format is worse than reusing it.
179 let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
180 for entry in pending.iter_mut() {
181 if entry.flushed {
182 continue;
183 }
184 eprintln!("{}", render_header(entry.depth, &entry.verb, &entry.msg));
185 entry.flushed = true;
186 }
187}
188
189/// Render a section/stage header line at `depth`: the 2-space-per-level
190/// nesting indent, a bold-green verb right-aligned in the [`VERB_COLUMN`]
191/// gutter, then (only for a non-empty `msg`) a single space and the message.
192///
193/// The single source of truth shared by both header-emitting paths — the
194/// deferred section header in [`flush_pending`] and the direct
195/// [`StageLogger::step`] — so interleaved headers and steps land in
196/// byte-identical columns for the same depth. A single-word phrase (empty
197/// `msg`) renders the bare gutter verb with no trailing space, so headers
198/// never carry stray whitespace.
199fn render_header(depth: usize, verb: &str, msg: &str) -> String {
200 render_gutter(&" ".repeat(depth), verb, |s| s.green().bold(), msg)
201}
202
203/// Render one gutter line: `label` right-aligned in the [`VERB_COLUMN`] gutter
204/// (painted by `paint`) after `prefix`, then a space and `msg` — or, when `msg`
205/// is empty, the bare painted label with no trailing space. The single column
206/// system shared by section headers and the Warning/Error/Note status labels,
207/// so a status label's message lands in the same column as a header's.
208fn render_gutter(
209 prefix: &str,
210 label: &str,
211 paint: impl Fn(String) -> colored::ColoredString,
212 msg: &str,
213) -> String {
214 let label = paint(format!("{label:>VERB_COLUMN$}"));
215 if msg.is_empty() {
216 format!("{prefix}{label}")
217 } else {
218 format!("{prefix}{label} {msg}")
219 }
220}
221
222/// Width of the right-aligned verb column in [`StageLogger::step`],
223/// matching Cargo's ` Compiling foo` look (3 leading spaces + 9-char
224/// verb = a 12-column gutter before the message).
225const VERB_COLUMN: usize = 12;
226
227/// Indent (after any section nesting) of a body line — a [`StageLogger::detail`]
228/// / [`success`] / [`failure`] / [`kv`] row, or a status label. Three spaces
229/// place the marker column one stop in from the section header's text, so body
230/// lines read as subordinate to the header above them.
231///
232/// [`success`]: StageLogger::success
233/// [`failure`]: StageLogger::failure
234/// [`kv`]: StageLogger::kv
235const BODY_INDENT: &str = " ";
236
237/// Marker for an info / detail body line (`•`). Rendered cyan.
238const MARKER_DETAIL: &str = "•";
239
240/// Marker for a success body line (`✓`). Rendered green.
241const MARKER_SUCCESS: &str = "✓";
242
243/// Marker for a failure body line (`✗`). Rendered red.
244const MARKER_FAILURE: &str = "✗";
245
246/// Map a pipeline stage name to its full Cargo-style header phrase
247/// (`"Building binaries"`, `"Signing artifacts"`, `"Publishing"`). Drives
248/// [`StageLogger::group`]'s deferred header: the leading verb is right-aligned
249/// into the [`VERB_COLUMN`] gutter (bold-green, matching `cargo`'s
250/// ` Compiling foo` look), and the remaining words form the message that
251/// follows. A single-word phrase (`"Publishing"`) renders just the gutter
252/// verb with no trailing message.
253///
254/// The phrase is a *readable description* of the work, not an echo of the
255/// stage name — `group("build")` reads ` Building binaries`, not
256/// ` Building build`. This keeps the continuous log scannable: a reader
257/// sees what each section does, not the internal stage identifier.
258///
259/// Falls back to `"Running <stage>"` for any stage without a bespoke
260/// phrase, so a newly-added stage still renders in the system vocabulary
261/// (` Running myfancystage`) without a code change here.
262pub fn stage_header(stage: &str) -> &'static str {
263 match stage {
264 "setup" => "Preparing release",
265 "build" => "Building binaries",
266 "archive" => "Creating archives",
267 "checksum" => "Computing checksums",
268 "sbom" => "Cataloging dependencies",
269 "templatefiles" => "Rendering templates",
270 "changelog" => "Generating changelog",
271 "attest" => "Generating attestations",
272 "binary-sign" => "Signing binaries",
273 "sign" => "Signing artifacts",
274 "docker" => "Building images",
275 "docker-sign" => "Signing images",
276 "upx" => "Compressing binaries",
277 "nfpm" => "Building packages",
278 "snapcraft" => "Building snap",
279 "flatpak" => "Building Flatpak",
280 "msi" => "Building MSI",
281 "nsis" => "Building installer",
282 "dmg" => "Building DMG",
283 "pkg" => "Building pkg",
284 "notarize" => "Notarizing app",
285 "makeself" => "Building installer",
286 "install-script" => "Building install script",
287 "srpm" => "Building source RPM",
288 "appbundle" => "Building app bundle",
289 "appimage" => "Building AppImage",
290 "universal" => "Merging binaries",
291 "source" => "Archiving source",
292 "release" => "Creating release",
293 "before-publish" => "Preparing publishers",
294 "emission-validate" => "Validating output",
295 "publish" => "Publishing",
296 "blob" => "Uploading blobs",
297 "snapcraft-publish" => "Publishing snap",
298 "announce" => "Announcing release",
299 "verify-release" => "Verifying release",
300 "publisher-summary" => "Summary",
301 "check-determinism" => "Checking determinism",
302 "finalize" => "Finalizing",
303 "prepare" => "Preparing",
304 _ => "Running",
305 }
306}
307
308/// Render the themed `Warning` line for `msg`: the label right-aligned in the
309/// gutter (bold-yellow, no colon) at the enclosing section's header indent
310/// ([`label_indent`]), so it reads as a peer of the section verbs and its
311/// message aligns with theirs. The single source of truth for the warning
312/// palette and label, shared by [`StageLogger::warn`] and the CLI's tracing
313/// formatter so a library-side `warn!` looks identical to a logger warn (one
314/// output authority).
315pub fn render_warning(msg: &str) -> String {
316 render_gutter(&label_indent(), "Warning", |s| s.yellow().bold(), msg)
317}
318
319/// Render the themed `Error` line for `msg` — gutter-aligned bold-red label,
320/// companion to [`render_warning`]; shared so the error palette/label lives in
321/// exactly one place.
322pub fn render_error(msg: &str) -> String {
323 render_gutter(&label_indent(), "Error", |s| s.red().bold(), msg)
324}
325
326/// Render the themed `Note` line for `msg`: gutter-aligned bold-green label.
327/// The third status label — informational lines that are neither warnings nor
328/// errors (host-target selection, auto-snapshot activation). The bold-green
329/// deliberately matches the section-verb palette (not yellow/red): a note is a
330/// neutral peer of the section headers, not an alert. Shared so the `Note`
331/// palette/label lives in exactly one place rather than being open-coded per
332/// call site.
333pub fn render_note(msg: &str) -> String {
334 render_gutter(&label_indent(), "Note", |s| s.green().bold(), msg)
335}
336
337/// Current indentation prefix (2 spaces per open section). Empty at the
338/// top level. Applied identically everywhere — including under GitHub
339/// Actions, where the indentation (not a collapsible `::group::` block) is
340/// what conveys section nesting, matching the continuous single-stream log
341/// GoReleaser emits.
342///
343/// This is the body-line depth (`•` detail / `success` / `failure` / `kv`
344/// rows). Status labels do NOT use it — they sit one level shallower at the
345/// enclosing header's depth via [`label_indent`].
346pub fn indent() -> String {
347 " ".repeat(current_depth())
348}
349
350/// Indentation prefix for a status label (`Warning` / `Error` / `Note`).
351///
352/// A label is a body-level event, but unlike a `•` detail line it renders
353/// through the right-aligned [`render_gutter`] system (like a section header),
354/// so to land its label in the verb column and its message in the header's
355/// message column it must sit at the ENCLOSING header's depth — one level
356/// shallower than [`indent`] (which tracks the deeper body depth). Using the
357/// body indent here would push the gutter-aligned label two columns past both
358/// the sibling headers and the body bullets, leaving it floating on its own.
359///
360/// Floored at the inherited [`base_depth`] so a label emitted with no open
361/// section never dedents below the ambient (e.g. GitHub Actions) indent.
362fn label_indent() -> String {
363 " ".repeat(current_depth().saturating_sub(1).max(base_depth()))
364}
365
366/// RAII guard returned by [`indent_one_level`]. Removes the extra indent
367/// level when dropped.
368#[must_use = "dropping the guard immediately removes the extra indent"]
369pub struct IndentGuard {
370 _private: (),
371}
372
373impl Drop for IndentGuard {
374 fn drop(&mut self) {
375 SECTION_DEPTH.fetch_sub(1, Ordering::Relaxed);
376 }
377}
378
379/// Deepen the body indent by one level WITHOUT opening a section header.
380///
381/// For rows that must align with the body bullets of sibling sections
382/// while no section is open — e.g. the pipeline's consolidated
383/// `skipped a, b, c` row, which prints between stage sections (the
384/// previous stage's guard has already dropped) but should sit at the
385/// same column as those sections' own `•` lines instead of two columns
386/// to their left. Unlike [`StageLogger::group`] this pushes no pending
387/// header, so nothing extra ever prints.
388pub fn indent_one_level() -> IndentGuard {
389 SECTION_DEPTH.fetch_add(1, Ordering::Relaxed);
390 IndentGuard { _private: () }
391}
392
393/// RAII guard returned by [`StageLogger::group`]. Closes the section
394/// (decrements the indent depth) when dropped, so a stage's body
395/// indentation is always balanced even if the stage bails early with `?`.
396#[must_use = "dropping the guard immediately ends the section"]
397pub struct SectionGuard {
398 _private: (),
399}
400
401impl Drop for SectionGuard {
402 fn drop(&mut self) {
403 // Take the PENDING lock BEFORE decrementing the depth: a
404 // flush_pending observer on another thread serializes on this
405 // lock, so it sees the depth decrement and the pop as one
406 // transition instead of a window where the depth is already
407 // lowered but the section's pending header is still queued.
408 let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
409 SECTION_DEPTH.fetch_sub(1, Ordering::Relaxed);
410 // Remove this section's pending entry (LIFO matches nesting). An
411 // unflushed entry means the section emitted no body line — a no-op
412 // stage — so dropping it without printing is exactly the desired
413 // "no-op stages print nothing" behavior.
414 pending.pop();
415 }
416}
417
418/// Level of a log line captured by a [`LogCapture`]. Mirrors the
419/// [`StageLogger`] methods that produce each level.
420///
421/// Gated behind the `test-helpers` Cargo feature — production binaries
422/// do not link the capture infrastructure.
423#[cfg(feature = "test-helpers")]
424#[derive(Debug, Clone, Copy, PartialEq, Eq)]
425pub enum LogLevel {
426 Error,
427 Warn,
428 Status,
429 /// Liveness / progress line from [`StageLogger::heartbeat`], surfaced
430 /// during a slow subprocess or upload. A level of its own so a heartbeat is
431 /// never counted as a status result line.
432 Heartbeat,
433 Verbose,
434 Debug,
435}
436
437/// In-memory sink that records every log line a [`StageLogger`] emits.
438///
439/// Cheap clone (`Arc<Mutex<Vec<…>>>` underneath) — pass the same handle to
440/// every logger derived from a [`crate::context::Context`] and read aggregated
441/// counts back via the accessor methods. Intended for tests that need to
442/// assert "publisher emitted ≥N status lines" — calls still write to stderr
443/// so test output stays debuggable.
444///
445/// Gated behind the `test-helpers` Cargo feature.
446#[cfg(feature = "test-helpers")]
447#[derive(Clone, Default)]
448pub struct LogCapture {
449 inner: Arc<Mutex<Vec<(LogLevel, String)>>>,
450}
451
452#[cfg(feature = "test-helpers")]
453impl LogCapture {
454 /// Construct a fresh empty capture sink.
455 pub fn new() -> Self {
456 Self::default()
457 }
458
459 /// Append a log line to the capture vec. Called from the
460 /// [`StageLogger`] methods when a capture is attached.
461 pub(crate) fn record(&self, level: LogLevel, msg: impl Into<String>) {
462 if let Ok(mut guard) = self.inner.lock() {
463 guard.push((level, msg.into()));
464 }
465 }
466
467 /// Number of [`LogLevel::Status`] lines recorded.
468 pub fn status_count(&self) -> usize {
469 self.count(LogLevel::Status)
470 }
471
472 /// Number of [`LogLevel::Debug`] lines recorded.
473 pub fn debug_count(&self) -> usize {
474 self.count(LogLevel::Debug)
475 }
476
477 /// Number of [`LogLevel::Verbose`] lines recorded.
478 pub fn verbose_count(&self) -> usize {
479 self.count(LogLevel::Verbose)
480 }
481
482 /// Number of [`LogLevel::Warn`] lines recorded.
483 pub fn warn_count(&self) -> usize {
484 self.count(LogLevel::Warn)
485 }
486
487 /// Number of [`LogLevel::Heartbeat`] lines recorded.
488 pub fn heartbeat_count(&self) -> usize {
489 self.count(LogLevel::Heartbeat)
490 }
491
492 /// Number of [`LogLevel::Error`] lines recorded.
493 pub fn error_count(&self) -> usize {
494 self.count(LogLevel::Error)
495 }
496
497 /// Total count across all levels (useful sanity check).
498 pub fn total_count(&self) -> usize {
499 self.inner.lock().map(|g| g.len()).unwrap_or(0)
500 }
501
502 fn count(&self, level: LogLevel) -> usize {
503 self.inner
504 .lock()
505 .map(|g| g.iter().filter(|(l, _)| *l == level).count())
506 .unwrap_or(0)
507 }
508
509 /// Snapshot of every recorded line in insertion order.
510 pub fn all_messages(&self) -> Vec<(LogLevel, String)> {
511 self.inner.lock().map(|g| g.clone()).unwrap_or_default()
512 }
513
514 /// Snapshot of every [`LogLevel::Warn`] message in insertion order.
515 ///
516 /// Convenience accessor for tests that care only about warns — strips
517 /// the level tuple [`all_messages`] returns so callers can write
518 /// `cap.warn_messages().iter().any(|m| m.contains("..."))` without
519 /// the per-call filter+map boilerplate.
520 ///
521 /// [`all_messages`]: Self::all_messages
522 pub fn warn_messages(&self) -> Vec<String> {
523 self.inner
524 .lock()
525 .map(|g| {
526 g.iter()
527 .filter(|(lvl, _)| *lvl == LogLevel::Warn)
528 .map(|(_, m)| m.clone())
529 .collect()
530 })
531 .unwrap_or_default()
532 }
533}
534
535/// Verbosity level, derived from CLI flags.
536#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Default)]
537pub enum Verbosity {
538 Quiet,
539 #[default]
540 Normal,
541 Verbose,
542 Debug,
543}
544
545impl Verbosity {
546 /// Derive verbosity from CLI flag combination.
547 /// `--quiet` overrides `--verbose`; `--debug` overrides everything.
548 pub fn from_flags(quiet: bool, verbose: bool, debug: bool) -> Self {
549 if debug {
550 Verbosity::Debug
551 } else if quiet {
552 Verbosity::Quiet
553 } else if verbose {
554 Verbosity::Verbose
555 } else {
556 Verbosity::Normal
557 }
558 }
559}
560
561/// Stage logger: wraps a stage name, verbosity level, and an optional
562/// env-pairs list used for secret redaction.
563///
564/// All output goes to stderr. Create one per stage via [`StageLogger::new`].
565/// Prefer `Context::logger("name")` over `StageLogger::new` when a
566/// `Context` is in scope, because it carries the env automatically.
567///
568/// ```rust,ignore
569/// let log = ctx.logger("build"); // env pre-populated
570/// let log = StageLogger::new("build", verbosity) // no env yet
571/// .with_env(env_pairs); // attach env for redact
572/// log.status("compiling for x86_64-unknown-linux-gnu");
573/// log.verbose(&format!("RUSTFLAGS={}", flags));
574/// log.debug(&format!("full env = {:?}", env));
575/// ```
576#[derive(Clone)]
577pub struct StageLogger {
578 /// The logger's stage identity. No longer printed (the per-line
579 /// `[stage]` tag was dropped for the unified body style — section
580 /// headers name the stage instead), but retained as the constructor
581 /// contract: callers build a logger per stage via [`Self::new`] /
582 /// [`crate::context::Context::logger`] and retag sub-sections via
583 /// [`Self::with_stage`]. Kept so those entry points keep a stable
584 /// signature.
585 #[allow(dead_code)]
586 stage: &'static str,
587 verbosity: Verbosity,
588 /// Env-pairs used to redact subprocess output and bail messages, behind
589 /// a shared `Arc<Mutex<_>>` cell rather than a frozen `Arc<Vec<_>>`.
590 /// [`crate::context::Context::logger`] hands every `StageLogger` a clone
591 /// of the SAME cell it refreshes on every `env_source` mutation (e.g.
592 /// the crates.io Trusted-Publishing token mint), so a logger constructed
593 /// before a mid-run credential mint still redacts secrets minted
594 /// afterward — [`StageLogger::redact`] reads the cell at call time, not
595 /// a snapshot taken at construction. `StageLogger::with_env` wraps its
596 /// argument in a private, never-mutated cell, so manual construction
597 /// keeps its previous frozen-table behavior. `None` means redaction is a
598 /// no-op (matches the behaviour before this field existed).
599 env: Option<RedactionEnv>,
600 /// Optional in-memory capture sink. When present, every log method also
601 /// appends to the capture vec (after the stderr write). `None` means
602 /// the logger only writes to stderr (production default).
603 ///
604 /// Gated behind the `test-helpers` Cargo feature — production binaries
605 /// do not carry the field, so no per-log-call `is_none()` check fires.
606 #[cfg(feature = "test-helpers")]
607 capture: Option<LogCapture>,
608}
609
610impl StageLogger {
611 pub fn new(stage: &'static str, verbosity: Verbosity) -> Self {
612 Self {
613 stage,
614 verbosity,
615 env: None,
616 #[cfg(feature = "test-helpers")]
617 capture: None,
618 }
619 }
620
621 /// Construct a logger backed by an in-memory [`LogCapture`] alongside the
622 /// usual stderr writes. Returns the logger plus a clone of the capture
623 /// handle so the test can read counts back after the SUT runs.
624 ///
625 /// Intended exclusively for tests — production code uses
626 /// [`StageLogger::new`] or [`crate::context::Context::logger`].
627 ///
628 /// Gated behind the `test-helpers` Cargo feature.
629 #[cfg(feature = "test-helpers")]
630 pub fn with_capture(stage: &'static str, verbosity: Verbosity) -> (Self, LogCapture) {
631 let capture = LogCapture::new();
632 let logger = Self {
633 stage,
634 verbosity,
635 env: None,
636 capture: Some(capture.clone()),
637 };
638 (logger, capture)
639 }
640
641 /// Attach an existing [`LogCapture`] to this logger. Useful when the
642 /// capture is owned by a [`crate::context::Context`] and every derived
643 /// logger should append to the same vec.
644 ///
645 /// Gated behind the `test-helpers` Cargo feature.
646 #[cfg(feature = "test-helpers")]
647 pub fn with_capture_handle(mut self, capture: LogCapture) -> Self {
648 self.capture = Some(capture);
649 self
650 }
651
652 /// Attach an env-pairs list to drive secret redaction inside
653 /// [`StageLogger::check_output`] and [`StageLogger::redact`]. Wraps the
654 /// list in a private cell that nothing else mutates — a frozen table,
655 /// same as before this method's underlying storage moved to
656 /// `Arc<Mutex<_>>`. Use [`StageLogger::with_shared_env`] to attach a
657 /// cell that can still change after construction.
658 pub fn with_env(mut self, env: Vec<(String, String)>) -> Self {
659 self.env = Some(Arc::new(Mutex::new(env)));
660 self
661 }
662
663 /// Attach a shared, mutable redaction cell: unlike [`StageLogger::with_env`],
664 /// updates the caller makes to `env` AFTER this call are visible to
665 /// every clone of this logger, because [`StageLogger::redact`] reads
666 /// the cell live rather than a snapshot taken here.
667 ///
668 /// Used exclusively by [`crate::context::Context::logger`], which hands
669 /// out clones of its own live redaction cell — refreshed on every
670 /// `env_source` mutation — so a logger built before a mid-run
671 /// credential mint (e.g. crates.io Trusted Publishing's
672 /// `CARGO_REGISTRY_TOKEN`) still redacts it.
673 pub(crate) fn with_shared_env(mut self, env: RedactionEnv) -> Self {
674 self.env = Some(env);
675 self
676 }
677
678 /// Derive a clone of this logger tagged for a different `stage`, keeping
679 /// verbosity, the (Arc-shared) redaction env, and any capture sink.
680 ///
681 /// The pipeline driver owns one `[release]`-tagged logger but brackets
682 /// sub-sections (`setup`, `finalize`, `publisher-summary`) with their own
683 /// `group()`. Body lines emitted inside such a section must carry the
684 /// *section's* tag, not `[release]`, or the output reads
685 /// `[release] wrote …` underneath `::group::finalize`. Retagging once at
686 /// the section boundary lets every helper called within the section emit
687 /// under the correct tag without threading an explicit `stage` argument
688 /// through each call.
689 pub fn with_stage(&self, stage: &'static str) -> Self {
690 Self {
691 stage,
692 verbosity: self.verbosity,
693 env: self.env.clone(),
694 #[cfg(feature = "test-helpers")]
695 capture: self.capture.clone(),
696 }
697 }
698
699 /// Redact secret values from `s` using this logger's attached env,
700 /// re-read from the cell at call time (see [`Self::with_shared_env`]) —
701 /// a secret added to a live cell after this logger was constructed is
702 /// still masked.
703 ///
704 /// When no env has been attached (the default for `StageLogger::new`),
705 /// returns the input unchanged. Combines `redact::string` (for
706 /// known-secret env values) with `redact::redact_url_credentials`
707 /// (for inline `https://<user>:<pass>@host` URL credentials that may
708 /// not match any exported env-var value).
709 pub fn redact(&self, s: &str) -> String {
710 match &self.env {
711 Some(env) => {
712 let table = env.lock().unwrap_or_else(|e| e.into_inner());
713 crate::redact::with_env(s, &table)
714 }
715 None => crate::redact::redact_url_credentials(s),
716 }
717 }
718
719 /// Render a body line: the current section indent, the 3-space body
720 /// indent, a colored `marker`, one space, then `text`. The single source
721 /// of truth for the `•` / `✓` / `✗` body register so every marker line
722 /// aligns byte-identically under its section header.
723 fn render_body(marker: &str, text: &str) -> String {
724 format!("{}{}{} {}", indent(), BODY_INDENT, marker, text)
725 }
726
727 /// Error message — always shown (even in quiet mode). Renders the
728 /// `Error` status label gutter-aligned beneath the current section.
729 pub fn error(&self, msg: &str) {
730 flush_pending();
731 eprintln!("{}", render_error(msg));
732 #[cfg(feature = "test-helpers")]
733 if let Some(cap) = &self.capture {
734 cap.record(LogLevel::Error, msg);
735 }
736 }
737
738 /// Warning message — shown at Normal and above. Renders the `Warning`
739 /// status label gutter-aligned beneath the current section.
740 pub fn warn(&self, msg: &str) {
741 if self.verbosity >= Verbosity::Normal {
742 flush_pending();
743 eprintln!("{}", render_warning(msg));
744 }
745 #[cfg(feature = "test-helpers")]
746 if let Some(cap) = &self.capture {
747 cap.record(LogLevel::Warn, msg);
748 }
749 }
750
751 /// Status message — shown at Normal and above. This is the default level
752 /// for key actions (stage start, completion, skips, dry-run notes).
753 ///
754 /// Renders as a `•` detail body line beneath the current section. An
755 /// empty `msg` is preserved as a bare blank spacer line (no marker, no
756 /// indent) so callers using `status("")` for vertical rhythm keep a
757 /// clean blank even inside a group. For an explicit register, prefer
758 /// [`Self::detail`] / [`Self::success`] / [`Self::failure`].
759 pub fn status(&self, msg: &str) {
760 if self.verbosity >= Verbosity::Normal {
761 if msg.is_empty() {
762 // A marker on a "blank" line would render as a stray bullet;
763 // emit a truly empty line to preserve the caller's rhythm.
764 // A blank spacer is NOT a real body line, so it does not flush
765 // pending headers (a no-op section must stay invisible).
766 eprintln!();
767 } else {
768 flush_pending();
769 eprintln!(
770 "{}",
771 Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
772 );
773 }
774 }
775 #[cfg(feature = "test-helpers")]
776 if let Some(cap) = &self.capture {
777 cap.record(LogLevel::Status, msg);
778 }
779 }
780
781 /// Info / detail body line — a cyan `•` marker, then `msg`, at the body
782 /// indent beneath the current section. Shown at Normal and above. The
783 /// explicit-register sibling of [`Self::status`] for callers that want to
784 /// name the `•` style directly.
785 pub fn detail(&self, msg: &str) {
786 if self.verbosity >= Verbosity::Normal {
787 flush_pending();
788 eprintln!(
789 "{}",
790 Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
791 );
792 }
793 #[cfg(feature = "test-helpers")]
794 if let Some(cap) = &self.capture {
795 cap.record(LogLevel::Status, msg);
796 }
797 }
798
799 /// Success body line — a green `✓` marker, then `msg`, at the body indent
800 /// beneath the current section. Shown at Normal and above. Use for a
801 /// completed unit of work (`✓ x86_64-… 1.2 MiB`, `✓ signed 6 artifacts`).
802 pub fn success(&self, msg: &str) {
803 if self.verbosity >= Verbosity::Normal {
804 flush_pending();
805 eprintln!(
806 "{}",
807 Self::render_body(&MARKER_SUCCESS.green().to_string(), msg)
808 );
809 }
810 #[cfg(feature = "test-helpers")]
811 if let Some(cap) = &self.capture {
812 cap.record(LogLevel::Status, msg);
813 }
814 }
815
816 /// Failure body line — a red `✗` marker, then `msg`, at the body indent
817 /// beneath the current section. Shown at Normal and above. Use for a
818 /// failed unit of work that is reported inline (the run continues or the
819 /// error is surfaced separately via [`Self::error`]).
820 pub fn failure(&self, msg: &str) {
821 if self.verbosity >= Verbosity::Normal {
822 flush_pending();
823 eprintln!(
824 "{}",
825 Self::render_body(&MARKER_FAILURE.red().to_string(), msg)
826 );
827 }
828 #[cfg(feature = "test-helpers")]
829 if let Some(cap) = &self.capture {
830 cap.record(LogLevel::Status, msg);
831 }
832 }
833
834 /// Whether liveness heartbeats should surface: only at exactly Normal
835 /// verbosity. Quiet shows errors only, and at Verbose/Debug the live
836 /// subprocess tee already conveys progress, so a heartbeat there would
837 /// double the signal. The single authority for the suppression policy:
838 /// the drivers consult it via `progress::heartbeat_period` before spawning
839 /// any ticker, and [`Self::heartbeat`] re-checks it as defense-in-depth for
840 /// a direct caller — both gates read this one predicate, never a second
841 /// copy of the rule.
842 pub fn heartbeats_enabled(&self) -> bool {
843 self.verbosity == Verbosity::Normal
844 }
845
846 /// Heartbeat / liveness body line — a cyan `•` marker, then `msg`. Renders a
847 /// slow operation (`still running cargo publish (2m15s)`) so it is not
848 /// mistaken for a hang. Shown only when [`Self::heartbeats_enabled`], and
849 /// recorded at its own [`LogLevel::Heartbeat`] level.
850 pub fn heartbeat(&self, msg: &str) {
851 if !self.heartbeats_enabled() {
852 return;
853 }
854 flush_pending();
855 eprintln!(
856 "{}",
857 Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
858 );
859 #[cfg(feature = "test-helpers")]
860 if let Some(cap) = &self.capture {
861 cap.record(LogLevel::Heartbeat, msg);
862 }
863 }
864
865 /// Key/value meta row — a `•` detail line whose lowercase dimmed `key` is
866 /// left-padded to `key_width` so the values line up within a group, then
867 /// the `value`. Shown at Normal and above.
868 ///
869 /// Lowercase keys must never sit in the verb gutter (that column is for
870 /// bold capitalized verbs only), so meta rows render in the body
871 /// register. Callers that emit several rows pass the width of their
872 /// widest key as `key_width` so the values share a column:
873 ///
874 /// ```rust,ignore
875 /// let w = ["targets", "stages", "runs"].iter().map(|k| k.len()).max().unwrap();
876 /// log.kv("targets", "aarch64-pc-windows-msvc", w);
877 /// log.kv("stages", "build, source, sign", w);
878 /// log.kv("runs", "2", w);
879 /// // • targets aarch64-pc-windows-msvc
880 /// // • stages build, source, sign
881 /// // • runs 2
882 /// ```
883 pub fn kv(&self, key: &str, value: &str, key_width: usize) {
884 if self.verbosity >= Verbosity::Normal {
885 // Pad the PLAIN key to width before coloring — padding the
886 // already-dimmed string would count the ANSI escape bytes toward
887 // the field width and misalign the value column. Two spaces after
888 // the padded key give a readable gutter without a separator glyph.
889 let padded = format!("{key:<key_width$}");
890 let row = format!("{} {}", padded.dimmed(), value);
891 flush_pending();
892 eprintln!(
893 "{}",
894 Self::render_body(&MARKER_DETAIL.cyan().to_string(), &row)
895 );
896 }
897 #[cfg(feature = "test-helpers")]
898 if let Some(cap) = &self.capture {
899 cap.record(LogLevel::Status, format!("{key} = {value}"));
900 }
901 }
902
903 /// Cargo-style status line: a capitalized, right-aligned, bold-green
904 /// `verb` in a fixed-width gutter followed by `msg`
905 /// (` Building binaries`, ` Signing artifacts`). Shown at Normal and
906 /// above. Use for section/stage headers where there is a natural
907 /// verb; plain key-action lines stay on [`StageLogger::status`].
908 pub fn step(&self, verb: &str, msg: &str) {
909 if self.verbosity >= Verbosity::Normal {
910 eprintln!("{}", render_header(current_depth(), verb, msg));
911 }
912 #[cfg(feature = "test-helpers")]
913 if let Some(cap) = &self.capture {
914 cap.record(LogLevel::Status, msg);
915 }
916 }
917
918 /// Open a log section for stage `title`.
919 ///
920 /// The Cargo-style header (derived from [`stage_header`]: the phrase's
921 /// leading verb bold-green and right-aligned in the [`VERB_COLUMN`]
922 /// gutter, then one space and the remaining words — ` Building binaries`,
923 /// ` Publishing` for a single-word phrase) is *deferred*: it prints only
924 /// when this section emits its first real body line, matching GoReleaser
925 /// (a section header appears only once the section has output). A stage
926 /// that does nothing therefore prints no header at all — no bare
927 /// `Verifying release` over an empty body. The header renders identically
928 /// everywhere — locally and under GitHub Actions — because anodizer streams
929 /// one continuous log; the body indentation (not a collapsible `::group::`
930 /// block) conveys nesting. Every subsequent log line is indented two spaces
931 /// until the guard drops. Sections nest.
932 ///
933 /// ```rust,ignore
934 /// let _section = log.group("build"); // header pending…
935 /// log.status("compiling x86_64-unknown-linux-gnu"); // Building binaries
936 /// // • compiling …
937 /// // section closes here as `_section` drops
938 /// ```
939 #[must_use = "the section stays open only while the guard is alive"]
940 pub fn group(&self, title: &str) -> SectionGuard {
941 // Defer the header: push it onto the pending stack at the CURRENT depth
942 // (before incrementing) and print it only when this section actually
943 // emits a body line via `flush_pending`. A stage that does nothing
944 // therefore prints no header at all.
945 let (verb, msg) = self.split_header(title);
946 let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
947 pending.push(PendingHeader {
948 depth: current_depth(),
949 verb: verb.to_string(),
950 msg: msg.to_string(),
951 flushed: false,
952 });
953 // Track depth even at Quiet verbosity so any line that DOES print
954 // (errors) indents correctly and the guard's decrement is balanced.
955 SECTION_DEPTH.fetch_add(1, Ordering::Relaxed);
956 SectionGuard { _private: () }
957 }
958
959 /// Split a stage's [`stage_header`] phrase into the `(verb, message)`
960 /// pair [`Self::group`] feeds to [`Self::step`]. The verb is everything
961 /// up to the first space; the message is the remainder (empty for a
962 /// single-word phrase, which renders as a bare gutter verb). An unknown
963 /// stage (default `"Running"`) takes the stage name itself as the
964 /// message, so it reads ` Running myfancystage`.
965 fn split_header<'a>(&self, title: &'a str) -> (&'a str, &'a str) {
966 let phrase = stage_header(title);
967 match phrase.split_once(' ') {
968 Some((verb, rest)) => (verb, rest),
969 // Single-word phrase: the default "Running" echoes the stage name
970 // as its object; any other single word renders verb-only.
971 None if phrase == "Running" => (phrase, title),
972 None => (phrase, ""),
973 }
974 }
975
976 /// Detail message — shown only at Verbose and above. Renders as a `•`
977 /// detail body line beneath the current section.
978 /// Use for: command output on success, env vars, file paths, template vars.
979 pub fn verbose(&self, msg: &str) {
980 if self.verbosity >= Verbosity::Verbose {
981 flush_pending();
982 eprintln!(
983 "{}",
984 Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
985 );
986 }
987 #[cfg(feature = "test-helpers")]
988 if let Some(cap) = &self.capture {
989 cap.record(LogLevel::Verbose, msg);
990 }
991 }
992
993 /// Debug message — shown only at Debug level. Renders as a dimmed `•`
994 /// detail body line beneath the current section.
995 /// Use for: HTTP request/response details, full template contexts, resolved config.
996 pub fn debug(&self, msg: &str) {
997 if self.verbosity >= Verbosity::Debug {
998 flush_pending();
999 eprintln!(
1000 "{}",
1001 Self::render_body(
1002 &MARKER_DETAIL.dimmed().to_string(),
1003 &msg.dimmed().to_string()
1004 )
1005 );
1006 }
1007 #[cfg(feature = "test-helpers")]
1008 if let Some(cap) = &self.capture {
1009 cap.record(LogLevel::Debug, msg);
1010 }
1011 }
1012
1013 /// Emit a per-crate "no `<publisher>` config block" skip line at the
1014 /// verbosity the operator asked for.
1015 ///
1016 /// These lines fire once per non-applicable crate in workspace mode (every
1017 /// PR-based publisher visits every selected crate and skips the ones whose
1018 /// config lacks its block), so at default verbosity they would bury the
1019 /// real output under hundreds of lines of pure no-op noise. They are routed
1020 /// to [`Self::debug`] (invisible at default and `--verbose`, visible at
1021 /// `--debug`) unless `show` is set — `--show-skipped`, the diagnostic
1022 /// escape hatch for "why didn't publisher X run for crate Y?" — in which
1023 /// case they surface at [`Self::status`] like any other key action.
1024 pub fn skip_line(&self, show: bool, msg: &str) {
1025 if show {
1026 self.status(msg);
1027 } else {
1028 self.debug(msg);
1029 }
1030 }
1031
1032 /// Return the current verbosity level.
1033 pub fn verbosity(&self) -> Verbosity {
1034 self.verbosity
1035 }
1036
1037 /// Snapshot this logger's redaction env-pairs (empty when none is
1038 /// attached). Lets a caller construct a sibling logger at a different
1039 /// verbosity while preserving the same secret-redaction policy — e.g. the
1040 /// blob KMS path, which runs its encrypt subprocesses through a
1041 /// Normal-verbosity clone so ciphertext is never teed live, yet must keep
1042 /// the original logger's redaction coverage.
1043 pub fn redaction_env(&self) -> Vec<(String, String)> {
1044 self.env
1045 .as_ref()
1046 .map(|env| env.lock().unwrap_or_else(|e| e.into_inner()).clone())
1047 .unwrap_or_default()
1048 }
1049
1050 /// Check if verbose output is enabled.
1051 pub fn is_verbose(&self) -> bool {
1052 self.verbosity >= Verbosity::Verbose
1053 }
1054
1055 /// Check if debug output is enabled.
1056 pub fn is_debug(&self) -> bool {
1057 self.verbosity >= Verbosity::Debug
1058 }
1059
1060 /// Tee a single line of a child process's standard output to this
1061 /// process's STDERR, unmodified except for secret redaction.
1062 ///
1063 /// Used by the verbose live-stream in [`crate::run::run_checked`]: long
1064 /// tools (cargo, snapcraft, nix-build) show progress as they run. Unlike
1065 /// the marker-prefixed body register ([`Self::verbose`]), the line is
1066 /// written *raw* — no `•` marker, no section indent — so the streamed
1067 /// output looks exactly as the tool produced it, matching a tee.
1068 ///
1069 /// The tee goes to **stderr**, not stdout: anodizer's stdout is a
1070 /// machine-readable data channel (GHA step outputs like `new_tag=…`, plus
1071 /// json/changelog/metadata payloads), and a hook's child stdout teed onto
1072 /// stdout would corrupt it. Progress UX belongs on stderr with every other
1073 /// human/log line. Recorded into any attached [`LogCapture`] at
1074 /// [`LogLevel::Verbose`] so tests can assert the stream surfaced.
1075 ///
1076 /// `line` must be a single line with its trailing newline already
1077 /// stripped (the caller's line reader does this); the newline is added
1078 /// here by `eprintln!`.
1079 pub fn stream_child_stdout(&self, line: &str) {
1080 self.stream_child_line(line, false);
1081 }
1082
1083 /// Tee a single line of a child process's standard error to this
1084 /// process's stderr, unmodified except for secret redaction. The stderr
1085 /// companion to [`Self::stream_child_stdout`]; recorded at
1086 /// [`LogLevel::Error`] so the verbose-failure double-emit guard is
1087 /// observable in tests.
1088 pub fn stream_child_stderr(&self, line: &str) {
1089 self.stream_child_line(line, true);
1090 }
1091
1092 /// Shared body of [`stream_child_stdout`](Self::stream_child_stdout) and
1093 /// [`stream_child_stderr`](Self::stream_child_stderr): flush any deferred
1094 /// section header, write the redacted line to stderr, and record it.
1095 /// Both child streams tee to stderr (see
1096 /// [`stream_child_stdout`](Self::stream_child_stdout)); the methods differ
1097 /// only in which capture level the line is recorded under
1098 /// (`from_stderr` selects [`LogLevel::Error`] vs [`LogLevel::Verbose`]),
1099 /// so the write lives here once.
1100 ///
1101 /// `flush_pending()` runs first so a streamed line never prints *above* its
1102 /// deferred section header — the same header-before-body ordering every
1103 /// other body-line emitter (`verbose` / `status` / `error` / `debug`)
1104 /// upholds.
1105 fn stream_child_line(&self, line: &str, from_stderr: bool) {
1106 let redacted = self.redact(line);
1107 flush_pending();
1108 eprintln!("{redacted}");
1109 #[cfg(feature = "test-helpers")]
1110 if let Some(cap) = &self.capture {
1111 let level = if from_stderr {
1112 LogLevel::Error
1113 } else {
1114 LogLevel::Verbose
1115 };
1116 cap.record(level, redacted);
1117 }
1118 #[cfg(not(feature = "test-helpers"))]
1119 let _ = from_stderr;
1120 }
1121
1122 /// Check command output, log stderr/stdout on failure, and bail with context.
1123 /// On success, log stdout at verbose level. Returns `Ok(output)` on success.
1124 ///
1125 /// Stderr and stdout are passed through [`StageLogger::redact`] before
1126 /// they reach the log sink, so any secret env-var values present in the
1127 /// subprocess output are replaced with `$KEY_NAME` (and inline
1128 /// `https://<user>:<pass>@host` URL credentials are scrubbed) without
1129 /// callers having to remember to redact at each call site. Mirrors
1130 /// a safe-stderr pattern at every subprocess
1131 /// boundary.
1132 pub fn check_output(
1133 &self,
1134 output: std::process::Output,
1135 label: &str,
1136 ) -> anyhow::Result<std::process::Output> {
1137 self.check_output_inner(output, label, false)
1138 }
1139
1140 /// Like [`StageLogger::check_output`], but for callers that already
1141 /// streamed the child's stdout/stderr live (the verbose tee in
1142 /// [`crate::run::run_checked`]). Suppresses the stderr/stdout re-emit
1143 /// — both on the success-verbose path and the failure path — so output
1144 /// that was teed line-by-line is not printed a second time. The
1145 /// `bail!` embed (tail-truncated, redacted stderr in the error chain)
1146 /// is preserved unchanged, so error-chain consumers still see context.
1147 pub fn check_output_streamed(
1148 &self,
1149 output: std::process::Output,
1150 label: &str,
1151 ) -> anyhow::Result<std::process::Output> {
1152 self.check_output_inner(output, label, true)
1153 }
1154
1155 /// Shared body of [`check_output`](Self::check_output) and
1156 /// [`check_output_streamed`](Self::check_output_streamed).
1157 ///
1158 /// `already_streamed` suppresses the stderr/stdout log re-emit (the
1159 /// caller's live tee already wrote those lines), but never the `bail!`
1160 /// embed: an error chain propagated past the logger still carries the
1161 /// redacted, truncated stderr tail regardless of streaming.
1162 fn check_output_inner(
1163 &self,
1164 output: std::process::Output,
1165 label: &str,
1166 already_streamed: bool,
1167 ) -> anyhow::Result<std::process::Output> {
1168 let (stderr_line, stdout_line) = self.format_output_lines(&output, label);
1169 if !output.status.success() {
1170 if !already_streamed {
1171 if let Some(line) = stderr_line {
1172 self.error(&line);
1173 }
1174 if let Some(line) = stdout_line {
1175 self.error(&line);
1176 }
1177 }
1178 // Embed a (truncated, redacted) stderr tail in the bubbled
1179 // error so operators reading the final anyhow chain see
1180 // something more actionable than just an exit code. The
1181 // separately-emitted `log.error` lines above remain the
1182 // primary surface; this is defense in depth for callers
1183 // that propagate the error past the StageLogger context.
1184 let stderr_raw = String::from_utf8_lossy(&output.stderr);
1185 let stderr_tail = if stderr_raw.is_empty() {
1186 String::from("<no stderr>")
1187 } else {
1188 // Strip the child's terminal color codes BEFORE redaction and
1189 // truncation: this tail is bubbled up the anyhow chain and ends
1190 // up in non-terminal sinks (failure-notification emails, the
1191 // on_error hook's $ANODIZER_ERROR, JSON run summaries) where raw
1192 // ANSI renders as garbage around every styled token. Color is
1193 // forced on for child processes so the live CI log stays
1194 // colorized; the persisted error must not inherit it. Stripping
1195 // first also makes the byte cap below count visible content, not
1196 // escape bytes.
1197 let stripped = strip_ansi(&stderr_raw);
1198 let redacted = self.redact(&stripped);
1199 let trimmed = redacted.trim();
1200 // Cap at 2 KiB to keep error chains scannable.
1201 const MAX: usize = 2048;
1202 if trimmed.len() > MAX {
1203 let cut = trimmed
1204 .char_indices()
1205 .nth(MAX)
1206 .map(|(i, _)| i)
1207 .unwrap_or(MAX);
1208 format!("{}…", &trimmed[..cut])
1209 } else {
1210 trimmed.to_string()
1211 }
1212 };
1213 anyhow::bail!(
1214 "{} failed with exit code: {}; stderr: {}",
1215 label,
1216 output.status.code().unwrap_or(-1),
1217 stderr_tail
1218 );
1219 }
1220 if !already_streamed
1221 && self.is_verbose()
1222 && let Some(line) = stdout_line
1223 {
1224 self.verbose(&line);
1225 }
1226 Ok(output)
1227 }
1228
1229 /// Compose the redacted stderr / stdout log lines that
1230 /// [`StageLogger::check_output`] would emit for `output`. Returned as
1231 /// `(stderr_line, stdout_line)` where each `Option` is `Some` only when
1232 /// the corresponding stream had any content. Exposed via
1233 /// `pub(crate)` so the redaction logic can be unit-tested without
1234 /// having to capture stderr (`eprintln!` cannot be intercepted from
1235 /// the same process portably).
1236 pub(crate) fn format_output_lines(
1237 &self,
1238 output: &std::process::Output,
1239 label: &str,
1240 ) -> (Option<String>, Option<String>) {
1241 let stderr_raw = String::from_utf8_lossy(&output.stderr);
1242 let stderr_line = if stderr_raw.is_empty() {
1243 None
1244 } else {
1245 let stderr = self.redact(&stderr_raw);
1246 let prefix = if output.status.success() {
1247 "output"
1248 } else {
1249 "stderr"
1250 };
1251 // Failure messages format stderr separately from stdout (under
1252 // the "stderr" label); success uses one "output" label for
1253 // stdout only.
1254 if output.status.success() {
1255 // success path: stderr is never surfaced through check_output
1256 None
1257 } else {
1258 Some(format!("{label} {prefix}:\n{stderr}"))
1259 }
1260 };
1261 let stdout_raw = String::from_utf8_lossy(&output.stdout);
1262 let stdout_line = if stdout_raw.is_empty() {
1263 None
1264 } else {
1265 let stdout = self.redact(&stdout_raw);
1266 let prefix = if output.status.success() {
1267 "output"
1268 } else {
1269 "stdout"
1270 };
1271 Some(format!("{label} {prefix}:\n{stdout}"))
1272 };
1273 (stderr_line, stdout_line)
1274 }
1275}
1276
1277/// Strip ANSI CSI escape sequences (SGR color codes, cursor moves) from `s`.
1278///
1279/// Captured subprocess output (cargo, gpg, …) carries terminal color codes
1280/// when color is forced for the live CI log. Those bytes must never leak into
1281/// a propagated error message that reaches a non-terminal sink — a failure
1282/// email, the `on_error` hook's `$ANODIZER_ERROR`, a JSON run summary — where
1283/// they render as garbage around every styled token.
1284pub(crate) fn strip_ansi(s: &str) -> String {
1285 let mut out = String::with_capacity(s.len());
1286 let mut chars = s.chars();
1287 while let Some(c) = chars.next() {
1288 if c == '\u{1b}' {
1289 // Only a CSI introducer (`ESC [`) starts a parameterized sequence
1290 // we must consume to its final byte (0x40–0x7E); any other escape
1291 // form (a lone ESC, a two-char sequence) drops just the introducer.
1292 if chars.next() == Some('[') {
1293 for ec in chars.by_ref() {
1294 if ('\u{40}'..='\u{7e}').contains(&ec) {
1295 break;
1296 }
1297 }
1298 }
1299 } else {
1300 out.push(c);
1301 }
1302 }
1303 out
1304}
1305
1306#[cfg(test)]
1307mod tests {
1308 use super::*;
1309
1310 /// Serializes the section-depth tests: `SECTION_DEPTH` is a
1311 /// process-global atomic, so two grouping tests running on parallel
1312 /// threads would observe each other's increments.
1313 static SECTION_TEST_LOCK: Mutex<()> = Mutex::new(());
1314
1315 #[test]
1316 fn test_group_guard_balances_depth_locally() {
1317 // `group()` increments depth on open and the guard decrements on
1318 // drop, so nested sections always balance back to the start depth.
1319 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1320 let log = StageLogger::new("build", Verbosity::Normal);
1321 let start = SECTION_DEPTH.load(Ordering::Relaxed);
1322 {
1323 let _outer = log.group("build");
1324 assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
1325 {
1326 let _inner = log.group("sign");
1327 assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 2);
1328 }
1329 assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
1330 }
1331 assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start);
1332 }
1333
1334 #[test]
1335 fn test_group_quiet_still_tracks_local_depth() {
1336 // Even at Quiet verbosity the indent depth must stay balanced so
1337 // any status lines that DO print (errors) indent correctly and the
1338 // guard's decrement has a matching increment.
1339 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1340 let log = StageLogger::new("build", Verbosity::Quiet);
1341 let start = SECTION_DEPTH.load(Ordering::Relaxed);
1342 {
1343 let _s = log.group("build");
1344 assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
1345 }
1346 assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start);
1347 }
1348
1349 #[test]
1350 fn test_group_with_body_flushes_header_once() {
1351 // A section that emits a real body line flushes its deferred header:
1352 // the pending entry is marked `flushed` exactly once and stays at its
1353 // own depth. (`flush_pending` writes the header to stderr; we assert
1354 // the state transition rather than capture the uncapturable eprintln.)
1355 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1356 let log = StageLogger::new("build", Verbosity::Normal);
1357 {
1358 let _section = log.group("build");
1359 // Header is pending, not yet printed.
1360 assert!(!PENDING.lock().unwrap().last().unwrap().flushed);
1361 log.status("compiling x86_64-unknown-linux-gnu");
1362 // The body line flushed the header.
1363 let pending = PENDING.lock().unwrap();
1364 let entry = pending.last().unwrap();
1365 assert!(entry.flushed, "body line must flush the header");
1366 assert_eq!(entry.verb, "Building");
1367 assert_eq!(entry.msg, "binaries");
1368 }
1369 // Guard drop popped the (flushed) entry.
1370 assert!(PENDING.lock().unwrap().is_empty());
1371 }
1372
1373 #[test]
1374 fn test_noop_group_prints_no_header() {
1375 // A section that emits NOTHING leaves its pending entry unflushed, and
1376 // the guard drop pops it without ever printing — a no-op stage shows
1377 // no bare header (the GoReleaser behavior). A blank `status("")` spacer
1378 // is NOT a real body line, so it does not flush either.
1379 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1380 let log = StageLogger::new("verify-release", Verbosity::Normal);
1381 {
1382 let _section = log.group("verify-release");
1383 log.status(""); // blank spacer — must not flush
1384 assert!(
1385 !PENDING.lock().unwrap().last().unwrap().flushed,
1386 "a no-op section's header must stay unflushed"
1387 );
1388 }
1389 assert!(PENDING.lock().unwrap().is_empty());
1390 }
1391
1392 #[test]
1393 fn test_nested_groups_flush_in_ancestor_order() {
1394 // A body line in a nested section flushes BOTH the ancestor and the
1395 // nested header (each at its own stored depth), so the deferred
1396 // headers appear in correct order above the first line.
1397 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1398 let log = StageLogger::new("publish", Verbosity::Normal);
1399 let start = SECTION_DEPTH.load(Ordering::Relaxed);
1400 {
1401 let _outer = log.group("publish");
1402 {
1403 let _inner = log.group("blob");
1404 log.status("uploading blob");
1405 let pending = PENDING.lock().unwrap();
1406 assert_eq!(pending.len(), 2);
1407 assert!(pending[0].flushed, "ancestor header must flush");
1408 assert!(pending[1].flushed, "nested header must flush");
1409 assert_eq!(pending[0].depth, start);
1410 assert_eq!(pending[1].depth, start + 1);
1411 }
1412 }
1413 assert!(PENDING.lock().unwrap().is_empty());
1414 }
1415
1416 /// Run `f` with the process stderr fd (2) redirected to a temp file, then
1417 /// restore it and return everything that reached fd 2 as a string, or
1418 /// `None` if `eprintln!` output is being intercepted before fd 2.
1419 ///
1420 /// `eprintln!` writes through libtest's macro path, which — under a plain
1421 /// in-process `cargo test` — diverts output to a thread-local capture sink
1422 /// BEFORE it reaches fd 2, so an fd swap observes nothing. Under
1423 /// `cargo nextest` (the CI test runner) each test is its own process with a
1424 /// real stderr pipe, so the swap captures the true bytes. A sentinel probe
1425 /// distinguishes the two: if the sentinel does not survive the round-trip,
1426 /// fd 2 is not the real emit target and the caller must fall back.
1427 ///
1428 /// `f` must emit its header as the FIRST line it writes — callers slice the
1429 /// header off with `.lines().next()`, which is only correct because the
1430 /// caller's `group()` defers the header and `flush_pending` writes it ahead
1431 /// of any body line. A change that made `f` emit anything before its header
1432 /// would silently grab the wrong line.
1433 ///
1434 /// Unix-only. The fd-2 swap is process-global across the WHOLE
1435 /// `anodizer-core` test binary, so callers carry the crate-wide unnamed
1436 /// `#[serial_test::serial]` key (the convention in
1437 /// [`crate::test_helpers`]) to mutually exclude against every other
1438 /// env/cwd/fd-mutating test; `SECTION_TEST_LOCK` only orders the in-file
1439 /// `PENDING`/`SECTION_DEPTH` state these callers also touch.
1440 #[cfg(unix)]
1441 fn capture_stderr(f: impl FnOnce()) -> Option<String> {
1442 use std::io::{Read, Seek, SeekFrom, Write};
1443 use std::os::unix::io::AsRawFd;
1444
1445 /// Restores fd 2 from the saved dup on EVERY exit path, including a
1446 /// panic in `f` or the probe between the swap and the read. Without
1447 /// this, an unwind would leave fd 2 pointed at the dropped tempfile, so
1448 /// every later test's panic/`eprintln!` diagnostics in this shared
1449 /// process would write to a dangling fd and vanish.
1450 struct StderrRestore(libc::c_int);
1451 impl Drop for StderrRestore {
1452 fn drop(&mut self) {
1453 // SAFETY: self.0 is the dup of the original stderr taken before
1454 // the swap; restoring it on every exit path (including unwind)
1455 // guarantees fd 2 is never left dangling at the tempfile.
1456 unsafe {
1457 libc::dup2(self.0, libc::STDERR_FILENO);
1458 libc::close(self.0);
1459 }
1460 }
1461 }
1462
1463 let mut file = tempfile::tempfile().expect("tempfile for stderr capture");
1464 std::io::stderr().flush().ok();
1465 // SAFETY: dup/dup2 on the live stderr fd; the saved fd is owned by the
1466 // StderrRestore guard below, which restores fd 2 and closes the dup on
1467 // every exit path (panic-safe). The whole swap is serialized by the
1468 // caller's crate-wide `#[serial]` key.
1469 let saved = unsafe { libc::dup(libc::STDERR_FILENO) };
1470 assert!(saved >= 0, "dup(stderr) failed");
1471 unsafe {
1472 assert!(
1473 libc::dup2(file.as_raw_fd(), libc::STDERR_FILENO) >= 0,
1474 "dup2(tempfile, stderr) failed"
1475 );
1476 }
1477 // Owns `saved` from here on; its Drop restores fd 2 even if `f` panics.
1478 let _restore = StderrRestore(saved);
1479
1480 const SENTINEL: &str = "__anodizer_capture_probe__";
1481 eprintln!("{SENTINEL}");
1482 f();
1483 std::io::stderr().flush().ok();
1484
1485 file.seek(SeekFrom::Start(0)).expect("rewind capture file");
1486 let mut out = String::new();
1487 file.read_to_string(&mut out).expect("read capture file");
1488 // The sentinel survives only when fd 2 is the real emit target (nextest
1489 // / `--nocapture`); under in-process `cargo test` libtest swallowed it
1490 // (and `f`'s output), so the fd capture cannot prove anything.
1491 let body = out.strip_prefix(SENTINEL)?.trim_start_matches('\n');
1492 Some(body.to_string())
1493 }
1494
1495 #[test]
1496 #[cfg(unix)]
1497 #[serial_test::serial]
1498 fn test_header_paths_emit_identical_bytes() {
1499 // Regression guard for the v0.9.1 drift where stage headers rendered
1500 // with 2/3/4/5 leading spaces depending on which path printed them.
1501 //
1502 // This drives the TWO REAL emitting paths — the deferred-section header
1503 // in `flush_pending` and the direct `step` — and asserts they write
1504 // byte-identical headers at the same depth. It compares ACTUAL stderr
1505 // bytes (not `render_header`'s return value), so it FAILS the moment
1506 // either path open-codes its own indent/spacing instead of delegating
1507 // to `render_header`. Under `cargo nextest` (the CI gate) the fd capture
1508 // sees real output; under a bare in-process `cargo test` libtest
1509 // intercepts `eprintln!` and `capture_stderr` returns None, so the body
1510 // falls back to re-checking the shared helper rather than failing
1511 // spuriously. The crate-wide `#[serial]` key keeps every other
1512 // env/fd-mutating test out of the fd-swapped capture; SECTION_TEST_LOCK
1513 // only orders the in-file PENDING/SECTION_DEPTH state.
1514 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1515 let log = StageLogger::new("sign", Verbosity::Normal);
1516 // Absolute depth both paths must render at (includes any inherited base
1517 // from ANODIZER_LOG_DEPTH, so the anchor below shifts with it).
1518 let depth = current_depth();
1519
1520 // flush_pending path: open a section (pending header pushed at `depth`),
1521 // then a body line triggers `flush_pending`, which prints the header.
1522 // The header is the FIRST captured line; the body line follows it.
1523 let flushed = capture_stderr(|| {
1524 let _section = log.group("sign");
1525 assert_eq!(
1526 PENDING.lock().unwrap().last().unwrap().depth,
1527 depth,
1528 "pending header must sit at the pre-increment depth"
1529 );
1530 log.status("byte-equality probe"); // forces flush_pending
1531 });
1532 assert!(
1533 PENDING.lock().unwrap().is_empty(),
1534 "guard must pop the entry"
1535 );
1536
1537 // step path: the section is closed, so `current_depth()` is back to
1538 // `depth` — the same depth the pending header rendered at. `step` emits
1539 // exactly the header line, nothing else.
1540 assert_eq!(current_depth(), depth, "depth must return to start");
1541 let stepped = capture_stderr(|| log.step("Signing", "artifacts"));
1542
1543 let prefix = " ".repeat(depth);
1544 let expected = format!("{prefix}{:>VERB_COLUMN$} artifacts", "Signing");
1545
1546 match (flushed, stepped) {
1547 (Some(flushed), Some(stepped)) => {
1548 let flush_header = strip_ansi(
1549 flushed
1550 .lines()
1551 .next()
1552 .expect("flush_pending must emit a header line"),
1553 );
1554 let step_header = strip_ansi(stepped.trim_end_matches('\n'));
1555 // The whole point: both REAL paths produce the same header
1556 // bytes. If a future edit makes one open-code a different
1557 // indent, these diverge and the test fails.
1558 assert_eq!(
1559 flush_header, step_header,
1560 "flush_pending and step must emit byte-identical headers \
1561 (flush={flush_header:?} step={step_header:?})"
1562 );
1563 // Anchor the shared bytes so a regression that drifts BOTH paths
1564 // in lockstep (still equal to each other) is also caught.
1565 assert_eq!(
1566 step_header, expected,
1567 "header must be indent + gutter verb + space + message"
1568 );
1569 }
1570 // In-process `cargo test`: BOTH swaps were intercepted, so the real
1571 // paths are unobservable here. Re-assert the shared helper so the
1572 // test is not a silent no-op; nextest exercises the real bytes.
1573 (None, None) => {
1574 assert_eq!(
1575 strip_ansi(&render_header(depth, "Signing", "artifacts")),
1576 expected
1577 );
1578 }
1579 // The sentinel survived one swap but not the other — a real capture
1580 // anomaly (a flaky/half-redirected environment), not the documented
1581 // all-or-nothing fallback. Surface it loudly instead of silently
1582 // running the weaker check.
1583 (flushed, stepped) => panic!(
1584 "inconsistent stderr capture: flush={} step={}",
1585 flushed.is_some(),
1586 stepped.is_some()
1587 ),
1588 }
1589 }
1590
1591 #[test]
1592 #[cfg(unix)]
1593 #[serial_test::serial]
1594 fn test_single_word_header_emits_no_trailing_space() {
1595 // A single-word phrase (empty message) renders the bare gutter verb
1596 // with NO trailing space on the REAL `step` path — a stray space here
1597 // would leave invisible whitespace at the end of every `Publishing`
1598 // header line. Drives `step` directly and inspects the emitted bytes.
1599 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1600 let log = StageLogger::new("publish", Verbosity::Normal);
1601 let depth = current_depth();
1602 let prefix = " ".repeat(depth);
1603
1604 match capture_stderr(|| log.step("Publishing", "")) {
1605 Some(stepped) => {
1606 let header = strip_ansi(stepped.trim_end_matches('\n'));
1607 assert_eq!(header, format!("{prefix}{:>VERB_COLUMN$}", "Publishing"));
1608 assert!(
1609 !header.ends_with(' '),
1610 "single-word header must not carry a trailing space: {header:?}"
1611 );
1612 }
1613 // In-process `cargo test` intercepts `eprintln!`; re-assert the
1614 // shared helper so the invariant still has a floor under nextest.
1615 None => {
1616 let header = strip_ansi(&render_header(depth, "Publishing", ""));
1617 assert_eq!(header, format!("{prefix}{:>VERB_COLUMN$}", "Publishing"));
1618 assert!(!header.ends_with(' '));
1619 }
1620 }
1621 }
1622
1623 #[test]
1624 fn test_status_labels_gutter_aligned_without_colon() {
1625 // Regression guard: Warning/Error/Note must render as right-aligned
1626 // gutter labels with NO trailing colon, and their message must land in
1627 // the same column as a section header's message (both follow the
1628 // VERB_COLUMN gutter + one space). The old format open-coded
1629 // "Warning:" at BODY_INDENT, which faked Cargo alignment with an
1630 // anti-Cargo colon.
1631 let header = strip_ansi(&render_header(0, "Building", "binaries"));
1632 let header_msg_col = header.find("binaries");
1633 for (rendered, label, msg) in [
1634 (render_warning("oops"), "Warning", "oops"),
1635 (render_error("boom"), "Error", "boom"),
1636 (render_note("fyi"), "Note", "fyi"),
1637 ] {
1638 let line = strip_ansi(&rendered);
1639 assert!(
1640 !line.contains(':'),
1641 "status label must not carry a colon: {line:?}"
1642 );
1643 // Label lines go through the SAME gutter renderer as section
1644 // headers: stripped of color, a Warning/Error/Note line is
1645 // byte-identical to a header whose verb is that label. Deriving the
1646 // expectation from `render_header` (not a hand-written format)
1647 // proves the shared renderer rather than re-stating its shape.
1648 assert_eq!(line, strip_ansi(&render_header(0, label, msg)));
1649 // Column-invariance across differing label widths: every label's
1650 // message lands in the same column as the "Building" header's,
1651 // regardless of how long the verb is.
1652 assert_eq!(
1653 line.find(msg),
1654 header_msg_col,
1655 "status-label message must align with the header message column"
1656 );
1657 }
1658 }
1659
1660 #[test]
1661 #[serial_test::serial]
1662 fn test_status_label_aligns_with_enclosing_header_not_body_depth() {
1663 // Regression: a Warning/Error/Note fired INSIDE a section must align
1664 // with that section's HEADER (label in the verb column, message in the
1665 // header message column), NOT one level deeper at the body-bullet
1666 // depth. The body-depth variant pushed the gutter-aligned label two
1667 // columns past both the sibling headers and the `•` bullets, leaving it
1668 // floating on its own.
1669 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1670 let log = StageLogger::new("build", Verbosity::Normal);
1671 let base = base_depth();
1672 // Open one section: its header renders at depth `base`; body lines
1673 // (and the bullets) render one level deeper at `base + 1`.
1674 let _outer = log.group("preparing release");
1675 let warn = strip_ansi(&render_warning("preflight skipped"));
1676 // Aligns with the enclosing header (depth `base`) ...
1677 assert_eq!(
1678 warn,
1679 strip_ansi(&render_header(base, "Warning", "preflight skipped")),
1680 "in-section label must align with its enclosing header"
1681 );
1682 // ... and NOT with the deeper body depth (`base + 1`) it used before.
1683 assert_ne!(
1684 warn,
1685 strip_ansi(&render_header(base + 1, "Warning", "preflight skipped")),
1686 "in-section label must not float at the deeper body indent"
1687 );
1688 }
1689
1690 #[test]
1691 #[cfg(unix)]
1692 #[serial_test::serial]
1693 fn test_capture_stderr_restores_fd_on_panic() {
1694 // The fd-restore must run on the unwind path: a panic inside `f`
1695 // (the asserts in the real callers are a reachable panic path) must
1696 // not leave fd 2 dangling at the dropped tempfile, which would make
1697 // every later test's stderr vanish in the shared process.
1698 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1699 let panicked = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| {
1700 capture_stderr(|| panic!("boom inside capture"));
1701 }));
1702 assert!(panicked.is_err(), "the injected panic must propagate");
1703
1704 // fd 2 is usable again: a fresh capture round-trips its sentinel. (Under
1705 // in-process `cargo test` the sentinel is swallowed and the result is
1706 // None — still a successful, non-dangling write; only a leaked fd 2
1707 // would corrupt this follow-up capture.)
1708 let after = capture_stderr(|| eprintln!("after panic"));
1709 if let Some(body) = after {
1710 assert!(
1711 body.contains("after panic"),
1712 "stderr must work after a mid-capture panic: {body:?}"
1713 );
1714 }
1715 }
1716
1717 #[test]
1718 fn test_indent_reflects_section_depth() {
1719 // Indentation tracks the open-section depth (2 spaces per level)
1720 // identically everywhere — anodizer streams one continuous log, so
1721 // indentation (not a collapsible `::group::` block) conveys nesting.
1722 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1723 let log = StageLogger::new("build", Verbosity::Normal);
1724 // Relative to the inherited base so an exported ANODIZER_LOG_DEPTH
1725 // in the test environment shifts every expectation uniformly.
1726 let base = " ".repeat(base_depth());
1727 assert_eq!(indent(), base);
1728 {
1729 let _outer = log.group("build");
1730 assert_eq!(indent(), format!("{base} "));
1731 {
1732 let _inner = log.group("sign");
1733 assert_eq!(indent(), format!("{base} "));
1734 }
1735 assert_eq!(indent(), format!("{base} "));
1736 }
1737 assert_eq!(indent(), base);
1738 }
1739
1740 #[test]
1741 fn test_indent_one_level_adds_depth_without_pending_header() {
1742 // The header-less guard must deepen the indent (so the row aligns
1743 // with sibling sections' body bullets) without registering a
1744 // pending header that a later body line could spuriously flush.
1745 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1746 let start = SECTION_DEPTH.load(Ordering::Relaxed);
1747 let pending_before = PENDING.lock().unwrap().len();
1748 {
1749 let _indent = indent_one_level();
1750 assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
1751 assert_eq!(
1752 PENDING.lock().unwrap().len(),
1753 pending_before,
1754 "indent_one_level must not push a pending header"
1755 );
1756 assert_eq!(indent(), " ".repeat(current_depth()));
1757 }
1758 assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start);
1759 }
1760
1761 #[test]
1762 fn test_parse_base_depth_accepts_valid_and_degrades_invalid() {
1763 // A subprocess child inherits a numeric depth; anything else
1764 // (absent, junk, negative) degrades to the standalone default 0 —
1765 // indentation must never abort a run.
1766 assert_eq!(parse_base_depth(Some("3")), 3);
1767 assert_eq!(parse_base_depth(Some(" 2 ")), 2);
1768 assert_eq!(parse_base_depth(Some("0")), 0);
1769 assert_eq!(parse_base_depth(Some("-1")), 0);
1770 assert_eq!(parse_base_depth(Some("abc")), 0);
1771 assert_eq!(parse_base_depth(Some("")), 0);
1772 assert_eq!(parse_base_depth(None), 0);
1773 }
1774
1775 #[test]
1776 fn test_current_depth_tracks_sections() {
1777 // `current_depth` = inherited base (0 in tests — the env var is
1778 // not set under cargo test) + open sections; it is the value a
1779 // parent exports to children via LOG_DEPTH_ENV.
1780 let _guard = SECTION_TEST_LOCK.lock().unwrap();
1781 let log = StageLogger::new("build", Verbosity::Normal);
1782 let start = current_depth();
1783 {
1784 let _outer = log.group("build");
1785 assert_eq!(current_depth(), start + 1);
1786 }
1787 assert_eq!(current_depth(), start);
1788 }
1789
1790 #[test]
1791 fn test_stage_header_splits_into_verb_and_message() {
1792 // A multi-word phrase splits on the FIRST space: the verb feeds the
1793 // right-aligned gutter, the remainder is the section message.
1794 let log = StageLogger::new("build", Verbosity::Normal);
1795 assert_eq!(log.split_header("build"), ("Building", "binaries"));
1796 assert_eq!(log.split_header("sign"), ("Signing", "artifacts"));
1797 assert_eq!(log.split_header("source"), ("Archiving", "source"));
1798 }
1799
1800 #[test]
1801 fn test_stage_header_single_word_renders_verb_only() {
1802 // A known single-word phrase ("Publishing") renders just the gutter
1803 // verb with an empty message — no stage-name echo.
1804 let log = StageLogger::new("publish", Verbosity::Normal);
1805 assert_eq!(log.split_header("publish"), ("Publishing", ""));
1806 }
1807
1808 #[test]
1809 fn test_stage_header_unknown_stage_uses_running_plus_name() {
1810 // An unknown stage falls back to "Running" + the stage name, so it
1811 // still renders in the system vocabulary (` Running myfancystage`).
1812 let log = StageLogger::new("x", Verbosity::Normal);
1813 assert_eq!(
1814 log.split_header("myfancystage"),
1815 ("Running", "myfancystage")
1816 );
1817 }
1818
1819 #[test]
1820 fn test_verbosity_from_flags_default() {
1821 assert_eq!(
1822 Verbosity::from_flags(false, false, false),
1823 Verbosity::Normal
1824 );
1825 }
1826
1827 #[test]
1828 fn test_verbosity_from_flags_quiet() {
1829 assert_eq!(Verbosity::from_flags(true, false, false), Verbosity::Quiet);
1830 }
1831
1832 #[test]
1833 fn test_verbosity_from_flags_verbose() {
1834 assert_eq!(
1835 Verbosity::from_flags(false, true, false),
1836 Verbosity::Verbose
1837 );
1838 }
1839
1840 #[test]
1841 fn test_verbosity_from_flags_debug() {
1842 assert_eq!(Verbosity::from_flags(false, false, true), Verbosity::Debug);
1843 }
1844
1845 #[test]
1846 fn test_verbosity_from_flags_debug_wins_over_verbose() {
1847 assert_eq!(Verbosity::from_flags(false, true, true), Verbosity::Debug);
1848 }
1849
1850 #[test]
1851 fn test_verbosity_from_flags_debug_wins_over_quiet() {
1852 assert_eq!(Verbosity::from_flags(true, false, true), Verbosity::Debug);
1853 }
1854
1855 #[test]
1856 fn test_verbosity_from_flags_quiet_overrides_verbose() {
1857 assert_eq!(Verbosity::from_flags(true, true, false), Verbosity::Quiet);
1858 }
1859
1860 #[test]
1861 fn test_verbosity_ordering() {
1862 assert!(Verbosity::Quiet < Verbosity::Normal);
1863 assert!(Verbosity::Normal < Verbosity::Verbose);
1864 assert!(Verbosity::Verbose < Verbosity::Debug);
1865 }
1866
1867 #[test]
1868 fn test_stage_logger_is_verbose() {
1869 let log = StageLogger::new("test", Verbosity::Verbose);
1870 assert!(log.is_verbose());
1871 assert!(!log.is_debug());
1872 }
1873
1874 #[test]
1875 fn test_stage_logger_is_debug() {
1876 let log = StageLogger::new("test", Verbosity::Debug);
1877 assert!(log.is_verbose());
1878 assert!(log.is_debug());
1879 }
1880
1881 #[test]
1882 fn test_stage_logger_normal_not_verbose() {
1883 let log = StageLogger::new("test", Verbosity::Normal);
1884 assert!(!log.is_verbose());
1885 assert!(!log.is_debug());
1886 }
1887
1888 #[test]
1889 fn test_default_verbosity_is_normal() {
1890 assert_eq!(Verbosity::default(), Verbosity::Normal);
1891 }
1892
1893 // -----------------------------------------------------------------
1894 // Redaction inside check_output
1895 // -----------------------------------------------------------------
1896
1897 #[cfg(unix)]
1898 fn fake_output(stdout: &[u8], stderr: &[u8], code: i32) -> std::process::Output {
1899 use std::os::unix::process::ExitStatusExt;
1900 std::process::Output {
1901 status: std::process::ExitStatus::from_raw(code << 8),
1902 stdout: stdout.to_vec(),
1903 stderr: stderr.to_vec(),
1904 }
1905 }
1906
1907 #[test]
1908 fn test_redact_uses_attached_env() {
1909 // A logger built via `with_env` must scrub configured secrets.
1910 let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
1911 "GITHUB_TOKEN".to_string(),
1912 "ghp_real_secret_token".to_string(),
1913 )]);
1914 let out = log.redact("auth header: ghp_real_secret_token");
1915 assert_eq!(out, "auth header: $GITHUB_TOKEN");
1916 assert!(!out.contains("ghp_real_secret_token"));
1917 }
1918
1919 #[test]
1920 fn test_redact_without_env_only_scrubs_inline_urls() {
1921 // A logger constructed without `with_env` still scrubs inline URL
1922 // credentials, even if the bare token is not in env (the env-pair
1923 // list is empty).
1924 let log = StageLogger::new("test", Verbosity::Normal);
1925 let out = log.redact("fetched from https://user:tok@example.com/path");
1926 assert_eq!(out, "fetched from https://<redacted>@example.com/path");
1927 }
1928
1929 #[test]
1930 fn test_redact_combines_env_and_url_credentials() {
1931 let log = StageLogger::new("test", Verbosity::Normal)
1932 .with_env(vec![("API_TOKEN".to_string(), "ghp_tok123".to_string())]);
1933 // Both the env-value token AND the inline URL credential should be
1934 // scrubbed in a single call.
1935 let out = log.redact("remote: https://ghp_tok123@github.com/x/y");
1936 // URL credential strip runs first, so the `ghp_tok123` between
1937 // `://` and `@` becomes `<redacted>`. The path / host text never
1938 // contains `ghp_tok123`, so the env-value pass is a no-op here.
1939 assert_eq!(out, "remote: https://<redacted>@github.com/x/y");
1940 assert!(!out.contains("ghp_tok123"));
1941 }
1942
1943 #[cfg(unix)]
1944 #[test]
1945 fn test_check_output_redacts_stderr_on_failure() {
1946 // Stderr from a failing subprocess must be redacted before
1947 // the logger surfaces it, so secrets present in `output.stderr`
1948 // never reach the eprintln sink (or any future log appender).
1949 let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
1950 "REGISTRY_PASSWORD".to_string(),
1951 "supersecret_pw_123".to_string(),
1952 )]);
1953 let output = fake_output(
1954 b"",
1955 b"docker login failed: invalid password 'supersecret_pw_123'",
1956 1,
1957 );
1958 let (stderr_line, _) = log.format_output_lines(&output, "docker login");
1959 let line = stderr_line.expect("stderr should be present on failure");
1960 assert!(
1961 !line.contains("supersecret_pw_123"),
1962 "stderr must be redacted: {line}"
1963 );
1964 assert!(line.contains("$REGISTRY_PASSWORD"));
1965 }
1966
1967 #[cfg(unix)]
1968 #[test]
1969 fn test_check_output_redacts_stdout_on_failure() {
1970 // Stdout on the failure path must be redacted alongside
1971 // stderr. Some tools dump credentials onto stdout (e.g. helm
1972 // login prints a warning to stdout, not stderr).
1973 let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
1974 "DOCKER_PASSWORD".to_string(),
1975 "tok_dckr_abc".to_string(),
1976 )]);
1977 let output = fake_output(b"echoed config: DOCKER_PASSWORD=tok_dckr_abc\n", b"", 2);
1978 let (_, stdout_line) = log.format_output_lines(&output, "docker");
1979 let line = stdout_line.expect("stdout should be present on failure");
1980 assert!(!line.contains("tok_dckr_abc"));
1981 assert!(line.contains("$DOCKER_PASSWORD"));
1982 }
1983
1984 #[cfg(unix)]
1985 #[test]
1986 fn test_check_output_redacts_stdout_on_verbose_success() {
1987 // At verbose level, successful subprocess stdout is logged
1988 // too; it must also be redacted.
1989 let log = StageLogger::new("test", Verbosity::Verbose).with_env(vec![(
1990 "MY_API_KEY".to_string(),
1991 "key-abcdef-123".to_string(),
1992 )]);
1993 let output = fake_output(b"echo: key-abcdef-123 OK\n", b"", 0);
1994 let (_, stdout_line) = log.format_output_lines(&output, "echo");
1995 let line = stdout_line.expect("stdout should be present on success");
1996 assert!(!line.contains("key-abcdef-123"));
1997 assert!(line.contains("$MY_API_KEY"));
1998 }
1999
2000 #[cfg(unix)]
2001 #[test]
2002 fn test_check_output_strips_inline_url_credentials_without_env() {
2003 // A logger built without env still strips URL credentials,
2004 // so even when the user did not export a matching env var, an
2005 // inline `https://<user>:<pw>@host` in stderr is scrubbed.
2006 let log = StageLogger::new("test", Verbosity::Normal);
2007 let output = fake_output(
2008 b"",
2009 b"fatal: cannot read https://user:p4ssw0rd@example.com/repo.git\n",
2010 128,
2011 );
2012 let (stderr_line, _) = log.format_output_lines(&output, "git fetch");
2013 let line = stderr_line.expect("stderr should be present on failure");
2014 assert!(
2015 !line.contains("p4ssw0rd"),
2016 "userinfo must be redacted: {line}"
2017 );
2018 assert!(line.contains("<redacted>@example.com"));
2019 }
2020
2021 #[cfg(unix)]
2022 #[test]
2023 fn test_check_output_bail_message_excludes_raw_secret() {
2024 // The bail message embeds the (truncated, redacted) stderr tail
2025 // so an operator reading the bubbled anyhow chain sees something
2026 // more actionable than the bare exit code. That redaction must
2027 // still strip env-resolved secrets — otherwise the new tail
2028 // would leak whatever stderr the subprocess emitted.
2029 let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
2030 "AUTH_TOKEN".to_string(),
2031 "secret_zzz_yyy".to_string(),
2032 )]);
2033 let output = fake_output(b"", b"401 Unauthorized: secret_zzz_yyy\n", 1);
2034 let err = log
2035 .check_output(output, "curl")
2036 .expect_err("non-zero exit should bail");
2037 let msg = format!("{err:#}");
2038 assert!(
2039 !msg.contains("secret_zzz_yyy"),
2040 "bail message leaks secret: {msg}"
2041 );
2042 assert!(
2043 msg.contains("stderr:") && msg.contains("401 Unauthorized"),
2044 "bail message should embed redacted stderr tail: {msg}"
2045 );
2046 }
2047
2048 #[cfg(unix)]
2049 #[test]
2050 fn test_check_output_bail_message_strips_ansi_color_codes() {
2051 // Color is forced on for child processes so the live CI log stays
2052 // colorized; cargo (and friends) then emit SGR escapes around versions,
2053 // paths, and numbers. The bubbled tail flows into failure-notification
2054 // emails and the on_error hook's $ANODIZER_ERROR, which render raw ANSI
2055 // as garbage — so the persisted error must carry plain text only.
2056 let log = StageLogger::new("test", Verbosity::Normal);
2057 // cargo-shaped colorized stderr: bold version, dimmed path, red error.
2058 let colorized =
2059 b"\x1b[1mPackaging\x1b[0m foo \x1b[2mv\x1b[1m0.11.3\x1b[0m\n\x1b[31merror\x1b[0m: exit \x1b[33m101\x1b[0m\n";
2060 let output = fake_output(b"", colorized, 101);
2061 let err = log
2062 .check_output(output, "cargo publish")
2063 .expect_err("non-zero exit should bail");
2064 let msg = format!("{err:#}");
2065 assert!(
2066 !msg.contains('\u{1b}'),
2067 "bail message must contain no ANSI escape bytes: {msg:?}"
2068 );
2069 assert!(
2070 msg.contains("Packaging") && msg.contains("0.11.3") && msg.contains("101"),
2071 "plain-text content must survive ANSI stripping: {msg}"
2072 );
2073 }
2074
2075 #[cfg(unix)]
2076 #[test]
2077 fn test_check_output_bail_includes_no_stderr_marker_when_empty() {
2078 // Subprocess failed with empty stderr — the bail still wants
2079 // SOMETHING after `stderr:` so a grep on operator logs sees a
2080 // deterministic marker rather than blank text.
2081 let log = StageLogger::new("test", Verbosity::Normal);
2082 let output = fake_output(b"", b"", 7);
2083 let err = log
2084 .check_output(output, "tool")
2085 .expect_err("non-zero exit should bail");
2086 let msg = format!("{err:#}");
2087 assert!(
2088 msg.contains("stderr: <no stderr>"),
2089 "expected explicit <no stderr> marker: {msg}"
2090 );
2091 }
2092
2093 #[cfg(unix)]
2094 #[test]
2095 fn test_check_output_bail_truncates_long_stderr() {
2096 // Stderr larger than the 2 KiB cap is truncated with an ellipsis
2097 // so the operator's error chain remains scannable.
2098 let log = StageLogger::new("test", Verbosity::Normal);
2099 // 3 KiB of stderr.
2100 let big = vec![b'x'; 3072];
2101 let output = fake_output(b"", &big, 1);
2102 let err = log
2103 .check_output(output, "tool")
2104 .expect_err("non-zero exit should bail");
2105 let msg = format!("{err:#}");
2106 assert!(
2107 msg.ends_with('…'),
2108 "expected ellipsis on truncated stderr: {msg}"
2109 );
2110 // Truncation must keep the surface manageable — well under
2111 // 3 KiB of raw stderr should make it into the bail.
2112 assert!(
2113 msg.len() < 2500,
2114 "bail message too long: {} bytes",
2115 msg.len()
2116 );
2117 }
2118
2119 #[test]
2120 fn test_with_env_is_arc_shared() {
2121 // Cloning a logger should share the env cell via Arc, not deep-copy.
2122 // Verified by `Arc::ptr_eq` on the shared `Arc<Mutex<Vec<_>>>` cell.
2123 let env = vec![("K".to_string(), "v_long_enough_to_be_a_token".to_string())];
2124 let a = StageLogger::new("a", Verbosity::Normal).with_env(env);
2125 let b = a.clone();
2126 assert!(Arc::ptr_eq(
2127 a.env.as_ref().unwrap(),
2128 b.env.as_ref().unwrap()
2129 ));
2130 }
2131
2132 #[test]
2133 fn test_with_stage_rebinds_stage_field() {
2134 // The per-line `[stage]` tag is gone from rendered output, but
2135 // `with_stage` still rebinds the `stage` field a logger carries (it
2136 // drives redaction env inheritance, not line formatting now).
2137 let log = StageLogger::new("release", Verbosity::Normal);
2138 assert_eq!(log.stage, "release");
2139 assert_eq!(log.with_stage("finalize").stage, "finalize");
2140 }
2141
2142 #[test]
2143 fn test_body_markers_render_at_body_indent() {
2144 // Body lines sit at the 3-space body indent (top level: no section
2145 // nesting) behind a colored marker glyph. ANSI codes are stripped
2146 // for the assertion so the test pins the visible shape, not palette.
2147 let _guard = SECTION_TEST_LOCK.lock().unwrap();
2148 let strip = |s: String| {
2149 // Drop CSI sequences so the assertion is palette-independent.
2150 let mut out = String::new();
2151 let mut chars = s.chars().peekable();
2152 while let Some(c) = chars.next() {
2153 if c == '\u{1b}' {
2154 for n in chars.by_ref() {
2155 if n == 'm' {
2156 break;
2157 }
2158 }
2159 } else {
2160 out.push(c);
2161 }
2162 }
2163 out
2164 };
2165 // Relative to the live indent so an exported ANODIZER_LOG_DEPTH
2166 // (or a section left open by a parallel test) cannot skew the
2167 // absolute column.
2168 let prefix = indent();
2169 assert_eq!(
2170 strip(StageLogger::render_body(MARKER_DETAIL, "x")),
2171 format!("{prefix} • x")
2172 );
2173 assert_eq!(
2174 strip(StageLogger::render_body(MARKER_SUCCESS, "ok")),
2175 format!("{prefix} ✓ ok")
2176 );
2177 assert_eq!(
2178 strip(StageLogger::render_body(MARKER_FAILURE, "bad")),
2179 format!("{prefix} ✗ bad")
2180 );
2181 }
2182
2183 #[test]
2184 fn test_kv_pads_plain_key_so_values_align() {
2185 // The padded key width counts the PLAIN key, not the ANSI-dimmed
2186 // bytes, so a short key and a long key share the same value column.
2187 // Emitting a body line drains the process-global PENDING stack via
2188 // `flush_pending`, so serialize against the section-depth tests that
2189 // assert on that stack.
2190 let _guard = SECTION_TEST_LOCK.lock().unwrap_or_else(|e| e.into_inner());
2191 let (log, cap) = StageLogger::with_capture("check", Verbosity::Normal);
2192 let w = ["targets", "runs"].iter().map(|k| k.len()).max().unwrap();
2193 log.kv("targets", "aarch64", w);
2194 log.kv("runs", "2", w);
2195 // The capture stores a normalized `key = value` form regardless of
2196 // the rendered padding/palette.
2197 assert_eq!(
2198 cap.all_messages(),
2199 vec![
2200 (LogLevel::Status, "targets = aarch64".to_string()),
2201 (LogLevel::Status, "runs = 2".to_string()),
2202 ]
2203 );
2204 }
2205
2206 #[test]
2207 fn test_retag_helpers_record_under_shared_capture() {
2208 // The retagged clone shares the capture sink, and the plain
2209 // delegations still record at the right level — locking the plumbing
2210 // independent of the rendered tag (which the capture does not store).
2211 // Emitting body lines drains the global PENDING stack via
2212 // `flush_pending`; serialize against the section-depth tests.
2213 let _guard = SECTION_TEST_LOCK.lock().unwrap_or_else(|e| e.into_inner());
2214 let (log, cap) = StageLogger::with_capture("release", Verbosity::Normal);
2215
2216 log.with_stage("finalize").status("x");
2217 log.error("y");
2218 log.status("own-status");
2219 log.error("own-error");
2220
2221 assert_eq!(
2222 cap.all_messages(),
2223 vec![
2224 (LogLevel::Status, "x".to_string()),
2225 (LogLevel::Error, "y".to_string()),
2226 (LogLevel::Status, "own-status".to_string()),
2227 (LogLevel::Error, "own-error".to_string()),
2228 ]
2229 );
2230 }
2231
2232 #[test]
2233 fn skip_line_records_debug_when_not_shown() {
2234 // The default (show=false) routes a per-crate "no config block" skip to
2235 // debug() so it stays invisible at Normal/Verbose and only surfaces at
2236 // --debug — the fix for the 300+-line workspace skip-noise problem.
2237 // skip_line emits a body line that drains the global PENDING stack;
2238 // serialize against the section-depth tests.
2239 let _guard = SECTION_TEST_LOCK.lock().unwrap_or_else(|e| e.into_inner());
2240 let (log, cap) = StageLogger::with_capture("homebrew", Verbosity::Normal);
2241 log.skip_line(
2242 false,
2243 "skipped homebrew for crate 'demo' — no homebrew config block",
2244 );
2245 assert_eq!(cap.debug_count(), 1);
2246 assert_eq!(cap.status_count(), 0);
2247 assert_eq!(
2248 cap.all_messages(),
2249 vec![(
2250 LogLevel::Debug,
2251 "skipped homebrew for crate 'demo' — no homebrew config block".to_string()
2252 )]
2253 );
2254 }
2255
2256 #[test]
2257 fn skip_line_records_status_when_shown() {
2258 // --show-skipped (show=true) forces the skip line back to status so the
2259 // operator can diagnose why a publisher didn't run for a given crate.
2260 // skip_line emits a body line that drains the global PENDING stack;
2261 // serialize against the section-depth tests.
2262 let _guard = SECTION_TEST_LOCK.lock().unwrap_or_else(|e| e.into_inner());
2263 let (log, cap) = StageLogger::with_capture("homebrew", Verbosity::Normal);
2264 log.skip_line(
2265 true,
2266 "skipped homebrew for crate 'demo' — no homebrew config block",
2267 );
2268 assert_eq!(cap.status_count(), 1);
2269 assert_eq!(cap.debug_count(), 0);
2270 }
2271}