Skip to main content

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