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//! - **Section headers** ([`StageLogger::step`] / [`StageLogger::group`]) put a
22//!   bold-green present-participle verb (the leading word of the stage's
23//!   [`stage_header`] phrase) right-aligned in a fixed 12-column gutter, then
24//!   one space, then the message. ONLY verbs live in this gutter — never a
25//!   lowercase key.
26//! - **Body lines** ([`StageLogger::detail`] / [`success`] / [`failure`], plus
27//!   the retargeted [`StageLogger::status`]) sit at a 3-space body indent under
28//!   their header, prefixed by a marker — `•` info (cyan), `✓` success (green),
29//!   `✗` failure (red) — one space, then the text.
30//! - **Key/value rows** ([`StageLogger::kv`]) are `•` detail lines whose
31//!   lowercase dimmed key is padded so the values align within a group.
32//! - **Status labels** (`Warning:` / `Error:` / `Note:`, via
33//!   [`render_warning`] / [`render_error`] / [`render_note`]) render at the body
34//!   indent.
35//!
36//! [`success`]: StageLogger::success
37//! [`failure`]: StageLogger::failure
38//!
39//! # Verbosity levels
40//!
41//! - **quiet**: errors only (for CI where only failures matter)
42//! - **default**: status messages (stage start/complete, key actions)
43//! - **verbose**: detail (command output, env vars, file paths)
44//! - **debug**: everything (HTTP request/response, template contexts, resolved config)
45//!
46//! # Secret redaction
47//!
48//! Every `StageLogger` carries an optional env-pairs list that drives the
49//! redaction policy applied inside [`StageLogger::check_output`]. Callers
50//! that go through [`crate::context::Context::logger`] inherit the merged
51//! `{process env, config env}` pairs automatically; manual constructors
52//! (`StageLogger::new`) start with no env and can be enriched via
53//! [`StageLogger::with_env`]. Stderr / stdout interpolated into log lines
54//! or `bail!` messages is therefore redacted without callers having to
55//! remember to scrub at every site.
56
57use std::sync::Arc;
58use std::sync::Mutex;
59use std::sync::atomic::{AtomicUsize, Ordering};
60
61use colored::Colorize;
62
63/// Process-global section nesting depth. Drives the 2-space-per-level
64/// indentation applied to every stderr log line so output produced
65/// inside a [`StageLogger::group`] sits visually beneath its header.
66///
67/// A single atomic (rather than per-logger state) is correct because the
68/// release pipeline drives one stderr stream and no `group()` is ever
69/// opened from a worker thread — sections bracket whole stages on the
70/// main thread, while a stage's interior parallelism (e.g. `build`
71/// spawning per-target threads) emits *inside* an already-open section.
72/// The depth is therefore a property of "where the main thread is in the
73/// run", not of any individual logger clone or worker.
74static SECTION_DEPTH: AtomicUsize = AtomicUsize::new(0);
75
76/// A section header that has been opened ([`StageLogger::group`]) but not yet
77/// printed. The header line is deferred until the section actually emits a
78/// body line, so a stage that does nothing prints nothing at all (matching
79/// GoReleaser, which only prints a section header once the section has output).
80struct PendingHeader {
81    /// Section depth captured at open time. The header renders at *this* depth,
82    /// not the current global depth, so a nested section's deferred header is
83    /// still indented to its own level when flushed alongside its ancestors.
84    depth: usize,
85    /// Right-aligned bold-green verb (the leading word of the stage's
86    /// [`stage_header`] phrase).
87    verb: String,
88    /// The remaining words of the phrase, printed after the verb (empty for a
89    /// single-word phrase, which renders a bare gutter verb).
90    msg: String,
91    /// Whether this header has already been printed. A flushed entry stays on
92    /// the stack (so the LIFO pop in [`SectionGuard::drop`] removes the right
93    /// one) but is never reprinted.
94    flushed: bool,
95}
96
97/// Stack of section headers awaiting their first body line. Pushed by
98/// [`StageLogger::group`], drained by [`flush_pending`] when a real line is
99/// about to print, and popped (LIFO) by [`SectionGuard::drop`].
100///
101/// A `Mutex` (not a thread-local) because sections are opened on the main
102/// thread like [`SECTION_DEPTH`], but body lines may flush from a stage's
103/// worker threads (e.g. `build` spawning per-target threads). The lock
104/// serializes the flush state transition: each header's `flushed` flag flips
105/// under the lock, so a header prints exactly once — never lost, never
106/// duplicated. Header-before-body ordering holds because every emit method
107/// calls [`flush_pending`] then writes its body line with no early return
108/// between. It does not serialize body-line-vs-body-line ordering across
109/// workers — two `build` threads may print their body lines in either order
110/// under a just-flushed header, matching build's existing unordered parallel
111/// output.
112static PENDING: Mutex<Vec<PendingHeader>> = Mutex::new(Vec::new());
113
114/// Print every still-unflushed pending section header, in ancestor-first
115/// (bottom-to-top) order, then mark each flushed.
116///
117/// Called immediately before any method actually writes a visible body line,
118/// so the deferred headers appear above their first line in correct nesting
119/// order. A header renders at its own stored [`PendingHeader::depth`] — the
120/// 2-space-per-level indent, the right-aligned bold-green verb in the
121/// [`VERB_COLUMN`] gutter, then (if non-empty) one space and the message.
122///
123/// No-op when nothing is pending (the common case once a section has already
124/// emitted its first line), so the per-body-line cost is one uncontended lock.
125fn flush_pending() {
126    // Recover a poisoned guard rather than bailing: pending headers are pure
127    // presentation state, and silently muting every section header for the
128    // rest of the run on one panic-mid-format is worse than reusing it.
129    let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
130    for entry in pending.iter_mut() {
131        if entry.flushed {
132            continue;
133        }
134        let prefix = "  ".repeat(entry.depth);
135        let verb = format!("{:>VERB_COLUMN$}", entry.verb).green().bold();
136        if entry.msg.is_empty() {
137            eprintln!("{prefix}{verb}");
138        } else {
139            eprintln!("{prefix}{verb} {}", entry.msg);
140        }
141        entry.flushed = true;
142    }
143}
144
145/// Width of the right-aligned verb column in [`StageLogger::step`],
146/// matching Cargo's `   Compiling foo` look (3 leading spaces + 9-char
147/// verb = a 12-column gutter before the message).
148const VERB_COLUMN: usize = 12;
149
150/// Indent (after any section nesting) of a body line — a [`StageLogger::detail`]
151/// / [`success`] / [`failure`] / [`kv`] row, or a status label. Three spaces
152/// place the marker column one stop in from the section header's text, so body
153/// lines read as subordinate to the header above them.
154///
155/// [`success`]: StageLogger::success
156/// [`failure`]: StageLogger::failure
157/// [`kv`]: StageLogger::kv
158const BODY_INDENT: &str = "   ";
159
160/// Marker for an info / detail body line (`•`). Rendered cyan.
161const MARKER_DETAIL: &str = "•";
162
163/// Marker for a success body line (`✓`). Rendered green.
164const MARKER_SUCCESS: &str = "✓";
165
166/// Marker for a failure body line (`✗`). Rendered red.
167const MARKER_FAILURE: &str = "✗";
168
169/// Map a pipeline stage name to its full Cargo-style header phrase
170/// (`"Building binaries"`, `"Signing artifacts"`, `"Publishing"`). Drives
171/// [`StageLogger::group`]'s deferred header: the leading verb is right-aligned
172/// into the [`VERB_COLUMN`] gutter (bold-green, matching `cargo`'s
173/// `   Compiling foo` look), and the remaining words form the message that
174/// follows. A single-word phrase (`"Publishing"`) renders just the gutter
175/// verb with no trailing message.
176///
177/// The phrase is a *readable description* of the work, not an echo of the
178/// stage name — `group("build")` reads `   Building binaries`, not
179/// `   Building build`. This keeps the continuous log scannable: a reader
180/// sees what each section does, not the internal stage identifier.
181///
182/// Falls back to `"Running <stage>"` for any stage without a bespoke
183/// phrase, so a newly-added stage still renders in the system vocabulary
184/// (`   Running myfancystage`) without a code change here.
185pub fn stage_header(stage: &str) -> &'static str {
186    match stage {
187        "setup" => "Preparing release",
188        "build" => "Building binaries",
189        "archive" => "Creating archives",
190        "checksum" => "Computing checksums",
191        "sbom" => "Cataloging dependencies",
192        "templatefiles" => "Rendering templates",
193        "changelog" => "Generating changelog",
194        "attest" => "Generating attestations",
195        "binary-sign" => "Signing binaries",
196        "sign" => "Signing artifacts",
197        "docker" => "Building images",
198        "docker-sign" => "Signing images",
199        "upx" => "Compressing binaries",
200        "nfpm" => "Building packages",
201        "snapcraft" => "Building snap",
202        "flatpak" => "Building Flatpak",
203        "msi" => "Building MSI",
204        "nsis" => "Building installer",
205        "dmg" => "Building DMG",
206        "pkg" => "Building pkg",
207        "notarize" => "Notarizing app",
208        "makeself" => "Building installer",
209        "srpm" => "Building source RPM",
210        "appbundle" => "Building app bundle",
211        "appimage" => "Building AppImage",
212        "universal" => "Merging binaries",
213        "source" => "Archiving source",
214        "release" => "Creating release",
215        "before-publish" => "Preparing publishers",
216        "emission-validate" => "Validating output",
217        "publish" => "Publishing",
218        "blob" => "Uploading blobs",
219        "snapcraft-publish" => "Publishing snap",
220        "announce" => "Announcing release",
221        "verify-release" => "Verifying release",
222        "publisher-summary" => "Summary",
223        "finalize" => "Finalizing",
224        "prepare" => "Preparing",
225        _ => "Running",
226    }
227}
228
229/// Render the themed `Warning:` line for `msg`, aligned to the body indent
230/// beneath the current section. The single source of truth for the warning
231/// palette and label, shared by [`StageLogger::warn`] and the CLI's tracing
232/// formatter so a library-side `warn!` looks identical to a logger warn
233/// (one output authority).
234pub fn render_warning(msg: &str) -> String {
235    format!(
236        "{}{}{} {}",
237        indent(),
238        BODY_INDENT,
239        "Warning:".yellow().bold(),
240        msg
241    )
242}
243
244/// Render the themed `Error:` line for `msg`, aligned to the body indent
245/// beneath the current section. Companion to [`render_warning`]; shared so
246/// the error palette/label lives in exactly one place.
247pub fn render_error(msg: &str) -> String {
248    format!(
249        "{}{}{} {}",
250        indent(),
251        BODY_INDENT,
252        "Error:".red().bold(),
253        msg
254    )
255}
256
257/// Render the themed `Note:` line for `msg`, aligned to the body indent
258/// beneath the current section. The third (and final) status label in the
259/// vocabulary — informational lines that are neither warnings nor errors
260/// (host-target selection, auto-snapshot activation). Bold-green to read as
261/// a benign status, distinct from the yellow `Warning:` and red `Error:`.
262/// Shared so the `Note:` palette/label lives in exactly one place rather than
263/// being open-coded per call site.
264pub fn render_note(msg: &str) -> String {
265    format!(
266        "{}{}{} {}",
267        indent(),
268        BODY_INDENT,
269        "Note:".green().bold(),
270        msg
271    )
272}
273
274/// Current indentation prefix (2 spaces per open section). Empty at the
275/// top level. Applied identically everywhere — including under GitHub
276/// Actions, where the indentation (not a collapsible `::group::` block) is
277/// what conveys section nesting, matching the continuous single-stream log
278/// GoReleaser emits.
279///
280/// Exposed so the CLI's loggerless `tracing` warning formatter can apply
281/// the same indent a library warn fired mid-stage would otherwise lack,
282/// keeping it aligned with the surrounding body lines.
283pub fn indent() -> String {
284    "  ".repeat(SECTION_DEPTH.load(Ordering::Relaxed))
285}
286
287/// RAII guard returned by [`StageLogger::group`]. Closes the section
288/// (decrements the indent depth) when dropped, so a stage's body
289/// indentation is always balanced even if the stage bails early with `?`.
290#[must_use = "dropping the guard immediately ends the section"]
291pub struct SectionGuard {
292    _private: (),
293}
294
295impl Drop for SectionGuard {
296    fn drop(&mut self) {
297        SECTION_DEPTH.fetch_sub(1, Ordering::Relaxed);
298        // Remove this section's pending entry (LIFO matches nesting). An
299        // unflushed entry means the section emitted no body line — a no-op
300        // stage — so dropping it without printing is exactly the desired
301        // "no-op stages print nothing" behavior.
302        let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
303        pending.pop();
304    }
305}
306
307/// Level of a log line captured by a [`LogCapture`]. Mirrors the
308/// [`StageLogger`] methods that produce each level.
309///
310/// Gated behind the `test-helpers` Cargo feature — production binaries
311/// do not link the capture infrastructure.
312#[cfg(feature = "test-helpers")]
313#[derive(Debug, Clone, Copy, PartialEq, Eq)]
314pub enum LogLevel {
315    Error,
316    Warn,
317    Status,
318    Verbose,
319    Debug,
320}
321
322/// In-memory sink that records every log line a [`StageLogger`] emits.
323///
324/// Cheap clone (`Arc<Mutex<Vec<…>>>` underneath) — pass the same handle to
325/// every logger derived from a [`crate::context::Context`] and read aggregated
326/// counts back via the accessor methods. Intended for tests that need to
327/// assert "publisher emitted ≥N status lines" — calls still write to stderr
328/// so test output stays debuggable.
329///
330/// Gated behind the `test-helpers` Cargo feature.
331#[cfg(feature = "test-helpers")]
332#[derive(Clone, Default)]
333pub struct LogCapture {
334    inner: Arc<Mutex<Vec<(LogLevel, String)>>>,
335}
336
337#[cfg(feature = "test-helpers")]
338impl LogCapture {
339    /// Construct a fresh empty capture sink.
340    pub fn new() -> Self {
341        Self::default()
342    }
343
344    /// Append a log line to the capture vec. Called from the
345    /// [`StageLogger`] methods when a capture is attached.
346    pub(crate) fn record(&self, level: LogLevel, msg: impl Into<String>) {
347        if let Ok(mut guard) = self.inner.lock() {
348            guard.push((level, msg.into()));
349        }
350    }
351
352    /// Number of [`LogLevel::Status`] lines recorded.
353    pub fn status_count(&self) -> usize {
354        self.count(LogLevel::Status)
355    }
356
357    /// Number of [`LogLevel::Warn`] lines recorded.
358    pub fn warn_count(&self) -> usize {
359        self.count(LogLevel::Warn)
360    }
361
362    /// Number of [`LogLevel::Error`] lines recorded.
363    pub fn error_count(&self) -> usize {
364        self.count(LogLevel::Error)
365    }
366
367    /// Total count across all levels (useful sanity check).
368    pub fn total_count(&self) -> usize {
369        self.inner.lock().map(|g| g.len()).unwrap_or(0)
370    }
371
372    fn count(&self, level: LogLevel) -> usize {
373        self.inner
374            .lock()
375            .map(|g| g.iter().filter(|(l, _)| *l == level).count())
376            .unwrap_or(0)
377    }
378
379    /// Snapshot of every recorded line in insertion order.
380    pub fn all_messages(&self) -> Vec<(LogLevel, String)> {
381        self.inner.lock().map(|g| g.clone()).unwrap_or_default()
382    }
383
384    /// Snapshot of every [`LogLevel::Warn`] message in insertion order.
385    ///
386    /// Convenience accessor for tests that care only about warns — strips
387    /// the level tuple [`all_messages`] returns so callers can write
388    /// `cap.warn_messages().iter().any(|m| m.contains("..."))` without
389    /// the per-call filter+map boilerplate.
390    ///
391    /// [`all_messages`]: Self::all_messages
392    pub fn warn_messages(&self) -> Vec<String> {
393        self.inner
394            .lock()
395            .map(|g| {
396                g.iter()
397                    .filter(|(lvl, _)| *lvl == LogLevel::Warn)
398                    .map(|(_, m)| m.clone())
399                    .collect()
400            })
401            .unwrap_or_default()
402    }
403}
404
405/// Verbosity level, derived from CLI flags.
406#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Default)]
407pub enum Verbosity {
408    Quiet,
409    #[default]
410    Normal,
411    Verbose,
412    Debug,
413}
414
415impl Verbosity {
416    /// Derive verbosity from CLI flag combination.
417    /// `--quiet` overrides `--verbose`; `--debug` overrides everything.
418    pub fn from_flags(quiet: bool, verbose: bool, debug: bool) -> Self {
419        if debug {
420            Verbosity::Debug
421        } else if quiet {
422            Verbosity::Quiet
423        } else if verbose {
424            Verbosity::Verbose
425        } else {
426            Verbosity::Normal
427        }
428    }
429}
430
431/// Stage logger: wraps a stage name, verbosity level, and an optional
432/// env-pairs list used for secret redaction.
433///
434/// All output goes to stderr. Create one per stage via [`StageLogger::new`].
435/// Prefer `Context::logger("name")` over `StageLogger::new` when a
436/// `Context` is in scope, because it carries the env automatically.
437///
438/// ```rust,ignore
439/// let log = ctx.logger("build");                  // env pre-populated
440/// let log = StageLogger::new("build", verbosity)  // no env yet
441///     .with_env(env_pairs);                       // attach env for redact
442/// log.status("compiling for x86_64-unknown-linux-gnu");
443/// log.verbose(&format!("RUSTFLAGS={}", flags));
444/// log.debug(&format!("full env: {:?}", env));
445/// ```
446#[derive(Clone)]
447pub struct StageLogger {
448    /// The logger's stage identity. No longer printed (the per-line
449    /// `[stage]` tag was dropped for the unified body style — section
450    /// headers name the stage instead), but retained as the constructor
451    /// contract: callers build a logger per stage via [`Self::new`] /
452    /// [`crate::context::Context::logger`] and retag sub-sections via
453    /// [`Self::with_stage`]. Kept so those entry points keep a stable
454    /// signature.
455    #[allow(dead_code)]
456    stage: &'static str,
457    verbosity: Verbosity,
458    /// Env-pairs used to redact subprocess output and bail messages. The
459    /// inner vec is shared via `Arc` so cloning a logger does not copy the
460    /// env every time. `None` means redaction is a no-op (matches the
461    /// behaviour before this field existed).
462    env: Option<Arc<Vec<(String, String)>>>,
463    /// Optional in-memory capture sink. When present, every log method also
464    /// appends to the capture vec (after the stderr write). `None` means
465    /// the logger only writes to stderr (production default).
466    ///
467    /// Gated behind the `test-helpers` Cargo feature — production binaries
468    /// do not carry the field, so no per-log-call `is_none()` check fires.
469    #[cfg(feature = "test-helpers")]
470    capture: Option<LogCapture>,
471}
472
473impl StageLogger {
474    pub fn new(stage: &'static str, verbosity: Verbosity) -> Self {
475        Self {
476            stage,
477            verbosity,
478            env: None,
479            #[cfg(feature = "test-helpers")]
480            capture: None,
481        }
482    }
483
484    /// Construct a logger backed by an in-memory [`LogCapture`] alongside the
485    /// usual stderr writes. Returns the logger plus a clone of the capture
486    /// handle so the test can read counts back after the SUT runs.
487    ///
488    /// Intended exclusively for tests — production code uses
489    /// [`StageLogger::new`] or [`crate::context::Context::logger`].
490    ///
491    /// Gated behind the `test-helpers` Cargo feature.
492    #[cfg(feature = "test-helpers")]
493    pub fn with_capture(stage: &'static str, verbosity: Verbosity) -> (Self, LogCapture) {
494        let capture = LogCapture::new();
495        let logger = Self {
496            stage,
497            verbosity,
498            env: None,
499            capture: Some(capture.clone()),
500        };
501        (logger, capture)
502    }
503
504    /// Attach an existing [`LogCapture`] to this logger. Useful when the
505    /// capture is owned by a [`crate::context::Context`] and every derived
506    /// logger should append to the same vec.
507    ///
508    /// Gated behind the `test-helpers` Cargo feature.
509    #[cfg(feature = "test-helpers")]
510    pub fn with_capture_handle(mut self, capture: LogCapture) -> Self {
511        self.capture = Some(capture);
512        self
513    }
514
515    /// Attach an env-pairs list to drive secret redaction inside
516    /// [`StageLogger::check_output`] and [`StageLogger::redact`]. The list
517    /// is shared via `Arc`, so passing the same vec to many loggers does
518    /// not duplicate the underlying storage.
519    pub fn with_env(mut self, env: Vec<(String, String)>) -> Self {
520        self.env = Some(Arc::new(env));
521        self
522    }
523
524    /// Derive a clone of this logger tagged for a different `stage`, keeping
525    /// verbosity, the (Arc-shared) redaction env, and any capture sink.
526    ///
527    /// The pipeline driver owns one `[release]`-tagged logger but brackets
528    /// sub-sections (`setup`, `finalize`, `publisher-summary`) with their own
529    /// `group()`. Body lines emitted inside such a section must carry the
530    /// *section's* tag, not `[release]`, or the output reads
531    /// `[release] wrote …` underneath `::group::finalize`. Retagging once at
532    /// the section boundary lets every helper called within the section emit
533    /// under the correct tag without threading an explicit `stage` argument
534    /// through each call.
535    pub fn with_stage(&self, stage: &'static str) -> Self {
536        Self {
537            stage,
538            verbosity: self.verbosity,
539            env: self.env.clone(),
540            #[cfg(feature = "test-helpers")]
541            capture: self.capture.clone(),
542        }
543    }
544
545    /// Redact secret values from `s` using this logger's attached env.
546    ///
547    /// When no env has been attached (the default for `StageLogger::new`),
548    /// returns the input unchanged. Combines `redact::string` (for
549    /// known-secret env values) with `redact::redact_url_credentials`
550    /// (for inline `https://<user>:<pass>@host` URL credentials that may
551    /// not match any exported env-var value).
552    pub fn redact(&self, s: &str) -> String {
553        let credential_stripped = crate::redact::redact_url_credentials(s);
554        match self.env.as_deref() {
555            Some(env) => crate::redact::string(&credential_stripped, env),
556            None => credential_stripped,
557        }
558    }
559
560    /// Render a body line: the current section indent, the 3-space body
561    /// indent, a colored `marker`, one space, then `text`. The single source
562    /// of truth for the `•` / `✓` / `✗` body register so every marker line
563    /// aligns byte-identically under its section header.
564    fn render_body(marker: &str, text: &str) -> String {
565        format!("{}{}{} {}", indent(), BODY_INDENT, marker, text)
566    }
567
568    /// Error message — always shown (even in quiet mode). Renders the
569    /// `Error:` status label at the body indent beneath the current section.
570    pub fn error(&self, msg: &str) {
571        flush_pending();
572        eprintln!("{}", render_error(msg));
573        #[cfg(feature = "test-helpers")]
574        if let Some(cap) = &self.capture {
575            cap.record(LogLevel::Error, msg);
576        }
577    }
578
579    /// Warning message — shown at Normal and above. Renders the `Warning:`
580    /// status label at the body indent beneath the current section.
581    pub fn warn(&self, msg: &str) {
582        if self.verbosity >= Verbosity::Normal {
583            flush_pending();
584            eprintln!("{}", render_warning(msg));
585        }
586        #[cfg(feature = "test-helpers")]
587        if let Some(cap) = &self.capture {
588            cap.record(LogLevel::Warn, msg);
589        }
590    }
591
592    /// Status message — shown at Normal and above. This is the default level
593    /// for key actions (stage start, completion, skips, dry-run notes).
594    ///
595    /// Renders as a `•` detail body line beneath the current section. An
596    /// empty `msg` is preserved as a bare blank spacer line (no marker, no
597    /// indent) so callers using `status("")` for vertical rhythm keep a
598    /// clean blank even inside a group. For an explicit register, prefer
599    /// [`Self::detail`] / [`Self::success`] / [`Self::failure`].
600    pub fn status(&self, msg: &str) {
601        if self.verbosity >= Verbosity::Normal {
602            if msg.is_empty() {
603                // A marker on a "blank" line would render as a stray bullet;
604                // emit a truly empty line to preserve the caller's rhythm.
605                // A blank spacer is NOT a real body line, so it does not flush
606                // pending headers (a no-op section must stay invisible).
607                eprintln!();
608            } else {
609                flush_pending();
610                eprintln!(
611                    "{}",
612                    Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
613                );
614            }
615        }
616        #[cfg(feature = "test-helpers")]
617        if let Some(cap) = &self.capture {
618            cap.record(LogLevel::Status, msg);
619        }
620    }
621
622    /// Info / detail body line — a cyan `•` marker, then `msg`, at the body
623    /// indent beneath the current section. Shown at Normal and above. The
624    /// explicit-register sibling of [`Self::status`] for callers that want to
625    /// name the `•` style directly.
626    pub fn detail(&self, msg: &str) {
627        if self.verbosity >= Verbosity::Normal {
628            flush_pending();
629            eprintln!(
630                "{}",
631                Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
632            );
633        }
634        #[cfg(feature = "test-helpers")]
635        if let Some(cap) = &self.capture {
636            cap.record(LogLevel::Status, msg);
637        }
638    }
639
640    /// Success body line — a green `✓` marker, then `msg`, at the body indent
641    /// beneath the current section. Shown at Normal and above. Use for a
642    /// completed unit of work (`✓ x86_64-… 1.2 MiB`, `✓ signed 6 artifacts`).
643    pub fn success(&self, msg: &str) {
644        if self.verbosity >= Verbosity::Normal {
645            flush_pending();
646            eprintln!(
647                "{}",
648                Self::render_body(&MARKER_SUCCESS.green().to_string(), msg)
649            );
650        }
651        #[cfg(feature = "test-helpers")]
652        if let Some(cap) = &self.capture {
653            cap.record(LogLevel::Status, msg);
654        }
655    }
656
657    /// Failure body line — a red `✗` marker, then `msg`, at the body indent
658    /// beneath the current section. Shown at Normal and above. Use for a
659    /// failed unit of work that is reported inline (the run continues or the
660    /// error is surfaced separately via [`Self::error`]).
661    pub fn failure(&self, msg: &str) {
662        if self.verbosity >= Verbosity::Normal {
663            flush_pending();
664            eprintln!(
665                "{}",
666                Self::render_body(&MARKER_FAILURE.red().to_string(), msg)
667            );
668        }
669        #[cfg(feature = "test-helpers")]
670        if let Some(cap) = &self.capture {
671            cap.record(LogLevel::Status, msg);
672        }
673    }
674
675    /// Key/value meta row — a `•` detail line whose lowercase dimmed `key` is
676    /// left-padded to `key_width` so the values line up within a group, then
677    /// the `value`. Shown at Normal and above.
678    ///
679    /// Lowercase keys must never sit in the verb gutter (that column is for
680    /// bold capitalized verbs only), so meta rows render in the body
681    /// register. Callers that emit several rows pass the width of their
682    /// widest key as `key_width` so the values share a column:
683    ///
684    /// ```rust,ignore
685    /// let w = ["targets", "stages", "runs"].iter().map(|k| k.len()).max().unwrap();
686    /// log.kv("targets", "aarch64-pc-windows-msvc", w);
687    /// log.kv("stages", "build, source, sign", w);
688    /// log.kv("runs", "2", w);
689    /// //   • targets  aarch64-pc-windows-msvc
690    /// //   • stages   build, source, sign
691    /// //   • runs     2
692    /// ```
693    pub fn kv(&self, key: &str, value: &str, key_width: usize) {
694        if self.verbosity >= Verbosity::Normal {
695            // Pad the PLAIN key to width before coloring — padding the
696            // already-dimmed string would count the ANSI escape bytes toward
697            // the field width and misalign the value column. Two spaces after
698            // the padded key give a readable gutter without a separator glyph.
699            let padded = format!("{key:<key_width$}");
700            let row = format!("{}  {}", padded.dimmed(), value);
701            flush_pending();
702            eprintln!(
703                "{}",
704                Self::render_body(&MARKER_DETAIL.cyan().to_string(), &row)
705            );
706        }
707        #[cfg(feature = "test-helpers")]
708        if let Some(cap) = &self.capture {
709            cap.record(LogLevel::Status, format!("{key} = {value}"));
710        }
711    }
712
713    /// Cargo-style status line: a capitalized, right-aligned, bold-green
714    /// `verb` in a fixed-width gutter followed by `msg`
715    /// (`   Building binaries`, `   Signing artifacts`). Shown at Normal and
716    /// above. Use for section/stage headers where there is a natural
717    /// verb; plain key-action lines stay on [`StageLogger::status`].
718    pub fn step(&self, verb: &str, msg: &str) {
719        if self.verbosity >= Verbosity::Normal {
720            eprintln!(
721                "{}{} {}",
722                indent(),
723                format!("{verb:>VERB_COLUMN$}").green().bold(),
724                msg
725            );
726        }
727        #[cfg(feature = "test-helpers")]
728        if let Some(cap) = &self.capture {
729            cap.record(LogLevel::Status, msg);
730        }
731    }
732
733    /// Open a log section for stage `title`.
734    ///
735    /// The Cargo-style header (derived from [`stage_header`]: the phrase's
736    /// leading verb bold-green and right-aligned in the [`VERB_COLUMN`]
737    /// gutter, then one space and the remaining words — `   Building binaries`,
738    /// ` Publishing` for a single-word phrase) is *deferred*: it prints only
739    /// when this section emits its first real body line, matching GoReleaser
740    /// (a section header appears only once the section has output). A stage
741    /// that does nothing therefore prints no header at all — no bare
742    /// `Verifying release` over an empty body. The header renders identically
743    /// everywhere — locally and under GitHub Actions — because anodizer streams
744    /// one continuous log; the body indentation (not a collapsible `::group::`
745    /// block) conveys nesting. Every subsequent log line is indented two spaces
746    /// until the guard drops. Sections nest.
747    ///
748    /// ```rust,ignore
749    /// let _section = log.group("build");                 // header pending…
750    /// log.status("compiling x86_64-unknown-linux-gnu");  //    Building binaries
751    ///                                                     //    • compiling …
752    /// // section closes here as `_section` drops
753    /// ```
754    #[must_use = "the section stays open only while the guard is alive"]
755    pub fn group(&self, title: &str) -> SectionGuard {
756        // Defer the header: push it onto the pending stack at the CURRENT depth
757        // (before incrementing) and print it only when this section actually
758        // emits a body line via `flush_pending`. A stage that does nothing
759        // therefore prints no header at all.
760        let (verb, msg) = self.split_header(title);
761        let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
762        pending.push(PendingHeader {
763            depth: SECTION_DEPTH.load(Ordering::Relaxed),
764            verb: verb.to_string(),
765            msg: msg.to_string(),
766            flushed: false,
767        });
768        // Track depth even at Quiet verbosity so any line that DOES print
769        // (errors) indents correctly and the guard's decrement is balanced.
770        SECTION_DEPTH.fetch_add(1, Ordering::Relaxed);
771        SectionGuard { _private: () }
772    }
773
774    /// Split a stage's [`stage_header`] phrase into the `(verb, message)`
775    /// pair [`Self::group`] feeds to [`Self::step`]. The verb is everything
776    /// up to the first space; the message is the remainder (empty for a
777    /// single-word phrase, which renders as a bare gutter verb). An unknown
778    /// stage (default `"Running"`) takes the stage name itself as the
779    /// message, so it reads `   Running myfancystage`.
780    fn split_header<'a>(&self, title: &'a str) -> (&'a str, &'a str) {
781        let phrase = stage_header(title);
782        match phrase.split_once(' ') {
783            Some((verb, rest)) => (verb, rest),
784            // Single-word phrase: the default "Running" echoes the stage name
785            // as its object; any other single word renders verb-only.
786            None if phrase == "Running" => (phrase, title),
787            None => (phrase, ""),
788        }
789    }
790
791    /// Detail message — shown only at Verbose and above. Renders as a `•`
792    /// detail body line beneath the current section.
793    /// Use for: command output on success, env vars, file paths, template vars.
794    pub fn verbose(&self, msg: &str) {
795        if self.verbosity >= Verbosity::Verbose {
796            flush_pending();
797            eprintln!(
798                "{}",
799                Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
800            );
801        }
802        #[cfg(feature = "test-helpers")]
803        if let Some(cap) = &self.capture {
804            cap.record(LogLevel::Verbose, msg);
805        }
806    }
807
808    /// Debug message — shown only at Debug level. Renders as a dimmed `•`
809    /// detail body line beneath the current section.
810    /// Use for: HTTP request/response details, full template contexts, resolved config.
811    pub fn debug(&self, msg: &str) {
812        if self.verbosity >= Verbosity::Debug {
813            flush_pending();
814            eprintln!(
815                "{}",
816                Self::render_body(
817                    &MARKER_DETAIL.dimmed().to_string(),
818                    &msg.dimmed().to_string()
819                )
820            );
821        }
822        #[cfg(feature = "test-helpers")]
823        if let Some(cap) = &self.capture {
824            cap.record(LogLevel::Debug, msg);
825        }
826    }
827
828    /// Return the current verbosity level.
829    pub fn verbosity(&self) -> Verbosity {
830        self.verbosity
831    }
832
833    /// Check if verbose output is enabled.
834    pub fn is_verbose(&self) -> bool {
835        self.verbosity >= Verbosity::Verbose
836    }
837
838    /// Check if debug output is enabled.
839    pub fn is_debug(&self) -> bool {
840        self.verbosity >= Verbosity::Debug
841    }
842
843    /// Check command output, log stderr/stdout on failure, and bail with context.
844    /// On success, log stdout at verbose level. Returns `Ok(output)` on success.
845    ///
846    /// Stderr and stdout are passed through [`StageLogger::redact`] before
847    /// they reach the log sink, so any secret env-var values present in the
848    /// subprocess output are replaced with `$KEY_NAME` (and inline
849    /// `https://<user>:<pass>@host` URL credentials are scrubbed) without
850    /// callers having to remember to redact at each call site. Mirrors
851    /// a safe-stderr pattern at every subprocess
852    /// boundary.
853    pub fn check_output(
854        &self,
855        output: std::process::Output,
856        label: &str,
857    ) -> anyhow::Result<std::process::Output> {
858        let (stderr_line, stdout_line) = self.format_output_lines(&output, label);
859        if !output.status.success() {
860            if let Some(line) = stderr_line {
861                self.error(&line);
862            }
863            if let Some(line) = stdout_line {
864                self.error(&line);
865            }
866            // Embed a (truncated, redacted) stderr tail in the bubbled
867            // error so operators reading the final anyhow chain see
868            // something more actionable than just an exit code. The
869            // separately-emitted `log.error` lines above remain the
870            // primary surface; this is defense in depth for callers
871            // that propagate the error past the StageLogger context.
872            let stderr_raw = String::from_utf8_lossy(&output.stderr);
873            let stderr_tail = if stderr_raw.is_empty() {
874                String::from("<no stderr>")
875            } else {
876                let redacted = self.redact(&stderr_raw);
877                let trimmed = redacted.trim();
878                // Cap at 2 KiB to keep error chains scannable.
879                const MAX: usize = 2048;
880                if trimmed.len() > MAX {
881                    let cut = trimmed
882                        .char_indices()
883                        .nth(MAX)
884                        .map(|(i, _)| i)
885                        .unwrap_or(MAX);
886                    format!("{}…", &trimmed[..cut])
887                } else {
888                    trimmed.to_string()
889                }
890            };
891            anyhow::bail!(
892                "{} failed with exit code: {}; stderr: {}",
893                label,
894                output.status.code().unwrap_or(-1),
895                stderr_tail
896            );
897        }
898        if self.is_verbose()
899            && let Some(line) = stdout_line
900        {
901            self.verbose(&line);
902        }
903        Ok(output)
904    }
905
906    /// Compose the redacted stderr / stdout log lines that
907    /// [`StageLogger::check_output`] would emit for `output`. Returned as
908    /// `(stderr_line, stdout_line)` where each `Option` is `Some` only when
909    /// the corresponding stream had any content. Exposed via
910    /// `pub(crate)` so the redaction logic can be unit-tested without
911    /// having to capture stderr (`eprintln!` cannot be intercepted from
912    /// the same process portably).
913    pub(crate) fn format_output_lines(
914        &self,
915        output: &std::process::Output,
916        label: &str,
917    ) -> (Option<String>, Option<String>) {
918        let stderr_raw = String::from_utf8_lossy(&output.stderr);
919        let stderr_line = if stderr_raw.is_empty() {
920            None
921        } else {
922            let stderr = self.redact(&stderr_raw);
923            let prefix = if output.status.success() {
924                "output"
925            } else {
926                "stderr"
927            };
928            // Failure messages format stderr separately from stdout (under
929            // the "stderr" label); success uses one "output" label for
930            // stdout only.
931            if output.status.success() {
932                // success path: stderr is never surfaced through check_output
933                None
934            } else {
935                Some(format!("{label} {prefix}:\n{stderr}"))
936            }
937        };
938        let stdout_raw = String::from_utf8_lossy(&output.stdout);
939        let stdout_line = if stdout_raw.is_empty() {
940            None
941        } else {
942            let stdout = self.redact(&stdout_raw);
943            let prefix = if output.status.success() {
944                "output"
945            } else {
946                "stdout"
947            };
948            Some(format!("{label} {prefix}:\n{stdout}"))
949        };
950        (stderr_line, stdout_line)
951    }
952}
953
954#[cfg(test)]
955mod tests {
956    use super::*;
957
958    /// Serializes the section-depth tests: `SECTION_DEPTH` is a
959    /// process-global atomic, so two grouping tests running on parallel
960    /// threads would observe each other's increments.
961    static SECTION_TEST_LOCK: Mutex<()> = Mutex::new(());
962
963    #[test]
964    fn test_group_guard_balances_depth_locally() {
965        // `group()` increments depth on open and the guard decrements on
966        // drop, so nested sections always balance back to the start depth.
967        let _guard = SECTION_TEST_LOCK.lock().unwrap();
968        let log = StageLogger::new("build", Verbosity::Normal);
969        let start = SECTION_DEPTH.load(Ordering::Relaxed);
970        {
971            let _outer = log.group("build");
972            assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
973            {
974                let _inner = log.group("sign");
975                assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 2);
976            }
977            assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
978        }
979        assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start);
980    }
981
982    #[test]
983    fn test_group_quiet_still_tracks_local_depth() {
984        // Even at Quiet verbosity the indent depth must stay balanced so
985        // any status lines that DO print (errors) indent correctly and the
986        // guard's decrement has a matching increment.
987        let _guard = SECTION_TEST_LOCK.lock().unwrap();
988        let log = StageLogger::new("build", Verbosity::Quiet);
989        let start = SECTION_DEPTH.load(Ordering::Relaxed);
990        {
991            let _s = log.group("build");
992            assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
993        }
994        assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start);
995    }
996
997    #[test]
998    fn test_group_with_body_flushes_header_once() {
999        // A section that emits a real body line flushes its deferred header:
1000        // the pending entry is marked `flushed` exactly once and stays at its
1001        // own depth. (`flush_pending` writes the header to stderr; we assert
1002        // the state transition rather than capture the uncapturable eprintln.)
1003        let _guard = SECTION_TEST_LOCK.lock().unwrap();
1004        let log = StageLogger::new("build", Verbosity::Normal);
1005        {
1006            let _section = log.group("build");
1007            // Header is pending, not yet printed.
1008            assert!(!PENDING.lock().unwrap().last().unwrap().flushed);
1009            log.status("compiling x86_64-unknown-linux-gnu");
1010            // The body line flushed the header.
1011            let pending = PENDING.lock().unwrap();
1012            let entry = pending.last().unwrap();
1013            assert!(entry.flushed, "body line must flush the header");
1014            assert_eq!(entry.verb, "Building");
1015            assert_eq!(entry.msg, "binaries");
1016        }
1017        // Guard drop popped the (flushed) entry.
1018        assert!(PENDING.lock().unwrap().is_empty());
1019    }
1020
1021    #[test]
1022    fn test_noop_group_prints_no_header() {
1023        // A section that emits NOTHING leaves its pending entry unflushed, and
1024        // the guard drop pops it without ever printing — a no-op stage shows
1025        // no bare header (the GoReleaser behavior). A blank `status("")` spacer
1026        // is NOT a real body line, so it does not flush either.
1027        let _guard = SECTION_TEST_LOCK.lock().unwrap();
1028        let log = StageLogger::new("verify-release", Verbosity::Normal);
1029        {
1030            let _section = log.group("verify-release");
1031            log.status(""); // blank spacer — must not flush
1032            assert!(
1033                !PENDING.lock().unwrap().last().unwrap().flushed,
1034                "a no-op section's header must stay unflushed"
1035            );
1036        }
1037        assert!(PENDING.lock().unwrap().is_empty());
1038    }
1039
1040    #[test]
1041    fn test_nested_groups_flush_in_ancestor_order() {
1042        // A body line in a nested section flushes BOTH the ancestor and the
1043        // nested header (each at its own stored depth), so the deferred
1044        // headers appear in correct order above the first line.
1045        let _guard = SECTION_TEST_LOCK.lock().unwrap();
1046        let log = StageLogger::new("publish", Verbosity::Normal);
1047        let start = SECTION_DEPTH.load(Ordering::Relaxed);
1048        {
1049            let _outer = log.group("publish");
1050            {
1051                let _inner = log.group("blob");
1052                log.status("uploading blob");
1053                let pending = PENDING.lock().unwrap();
1054                assert_eq!(pending.len(), 2);
1055                assert!(pending[0].flushed, "ancestor header must flush");
1056                assert!(pending[1].flushed, "nested header must flush");
1057                assert_eq!(pending[0].depth, start);
1058                assert_eq!(pending[1].depth, start + 1);
1059            }
1060        }
1061        assert!(PENDING.lock().unwrap().is_empty());
1062    }
1063
1064    #[test]
1065    fn test_indent_reflects_section_depth() {
1066        // Indentation tracks the open-section depth (2 spaces per level)
1067        // identically everywhere — anodizer streams one continuous log, so
1068        // indentation (not a collapsible `::group::` block) conveys nesting.
1069        let _guard = SECTION_TEST_LOCK.lock().unwrap();
1070        let log = StageLogger::new("build", Verbosity::Normal);
1071        assert_eq!(indent(), "");
1072        {
1073            let _outer = log.group("build");
1074            assert_eq!(indent(), "  ");
1075            {
1076                let _inner = log.group("sign");
1077                assert_eq!(indent(), "    ");
1078            }
1079            assert_eq!(indent(), "  ");
1080        }
1081        assert_eq!(indent(), "");
1082    }
1083
1084    #[test]
1085    fn test_stage_header_splits_into_verb_and_message() {
1086        // A multi-word phrase splits on the FIRST space: the verb feeds the
1087        // right-aligned gutter, the remainder is the section message.
1088        let log = StageLogger::new("build", Verbosity::Normal);
1089        assert_eq!(log.split_header("build"), ("Building", "binaries"));
1090        assert_eq!(log.split_header("sign"), ("Signing", "artifacts"));
1091        assert_eq!(log.split_header("source"), ("Archiving", "source"));
1092    }
1093
1094    #[test]
1095    fn test_stage_header_single_word_renders_verb_only() {
1096        // A known single-word phrase ("Publishing") renders just the gutter
1097        // verb with an empty message — no stage-name echo.
1098        let log = StageLogger::new("publish", Verbosity::Normal);
1099        assert_eq!(log.split_header("publish"), ("Publishing", ""));
1100    }
1101
1102    #[test]
1103    fn test_stage_header_unknown_stage_uses_running_plus_name() {
1104        // An unknown stage falls back to "Running" + the stage name, so it
1105        // still renders in the system vocabulary (`   Running myfancystage`).
1106        let log = StageLogger::new("x", Verbosity::Normal);
1107        assert_eq!(
1108            log.split_header("myfancystage"),
1109            ("Running", "myfancystage")
1110        );
1111    }
1112
1113    #[test]
1114    fn test_verbosity_from_flags_default() {
1115        assert_eq!(
1116            Verbosity::from_flags(false, false, false),
1117            Verbosity::Normal
1118        );
1119    }
1120
1121    #[test]
1122    fn test_verbosity_from_flags_quiet() {
1123        assert_eq!(Verbosity::from_flags(true, false, false), Verbosity::Quiet);
1124    }
1125
1126    #[test]
1127    fn test_verbosity_from_flags_verbose() {
1128        assert_eq!(
1129            Verbosity::from_flags(false, true, false),
1130            Verbosity::Verbose
1131        );
1132    }
1133
1134    #[test]
1135    fn test_verbosity_from_flags_debug() {
1136        assert_eq!(Verbosity::from_flags(false, false, true), Verbosity::Debug);
1137    }
1138
1139    #[test]
1140    fn test_verbosity_from_flags_debug_wins_over_verbose() {
1141        assert_eq!(Verbosity::from_flags(false, true, true), Verbosity::Debug);
1142    }
1143
1144    #[test]
1145    fn test_verbosity_from_flags_debug_wins_over_quiet() {
1146        assert_eq!(Verbosity::from_flags(true, false, true), Verbosity::Debug);
1147    }
1148
1149    #[test]
1150    fn test_verbosity_from_flags_quiet_overrides_verbose() {
1151        assert_eq!(Verbosity::from_flags(true, true, false), Verbosity::Quiet);
1152    }
1153
1154    #[test]
1155    fn test_verbosity_ordering() {
1156        assert!(Verbosity::Quiet < Verbosity::Normal);
1157        assert!(Verbosity::Normal < Verbosity::Verbose);
1158        assert!(Verbosity::Verbose < Verbosity::Debug);
1159    }
1160
1161    #[test]
1162    fn test_stage_logger_is_verbose() {
1163        let log = StageLogger::new("test", Verbosity::Verbose);
1164        assert!(log.is_verbose());
1165        assert!(!log.is_debug());
1166    }
1167
1168    #[test]
1169    fn test_stage_logger_is_debug() {
1170        let log = StageLogger::new("test", Verbosity::Debug);
1171        assert!(log.is_verbose());
1172        assert!(log.is_debug());
1173    }
1174
1175    #[test]
1176    fn test_stage_logger_normal_not_verbose() {
1177        let log = StageLogger::new("test", Verbosity::Normal);
1178        assert!(!log.is_verbose());
1179        assert!(!log.is_debug());
1180    }
1181
1182    #[test]
1183    fn test_default_verbosity_is_normal() {
1184        assert_eq!(Verbosity::default(), Verbosity::Normal);
1185    }
1186
1187    // -----------------------------------------------------------------
1188    // Redaction inside check_output
1189    // -----------------------------------------------------------------
1190
1191    #[cfg(unix)]
1192    fn fake_output(stdout: &[u8], stderr: &[u8], code: i32) -> std::process::Output {
1193        use std::os::unix::process::ExitStatusExt;
1194        std::process::Output {
1195            status: std::process::ExitStatus::from_raw(code << 8),
1196            stdout: stdout.to_vec(),
1197            stderr: stderr.to_vec(),
1198        }
1199    }
1200
1201    #[test]
1202    fn test_redact_uses_attached_env() {
1203        // A logger built via `with_env` must scrub configured secrets.
1204        let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
1205            "GITHUB_TOKEN".to_string(),
1206            "ghp_real_secret_token".to_string(),
1207        )]);
1208        let out = log.redact("auth header: ghp_real_secret_token");
1209        assert_eq!(out, "auth header: $GITHUB_TOKEN");
1210        assert!(!out.contains("ghp_real_secret_token"));
1211    }
1212
1213    #[test]
1214    fn test_redact_without_env_only_scrubs_inline_urls() {
1215        // A logger constructed without `with_env` still scrubs inline URL
1216        // credentials, even if the bare token is not in env (the env-pair
1217        // list is empty).
1218        let log = StageLogger::new("test", Verbosity::Normal);
1219        let out = log.redact("fetched from https://user:tok@example.com/path");
1220        assert_eq!(out, "fetched from https://<redacted>@example.com/path");
1221    }
1222
1223    #[test]
1224    fn test_redact_combines_env_and_url_credentials() {
1225        let log = StageLogger::new("test", Verbosity::Normal)
1226            .with_env(vec![("API_TOKEN".to_string(), "ghp_tok123".to_string())]);
1227        // Both the env-value token AND the inline URL credential should be
1228        // scrubbed in a single call.
1229        let out = log.redact("remote: https://ghp_tok123@github.com/x/y");
1230        // URL credential strip runs first, so the `ghp_tok123` between
1231        // `://` and `@` becomes `<redacted>`. The path / host text never
1232        // contains `ghp_tok123`, so the env-value pass is a no-op here.
1233        assert_eq!(out, "remote: https://<redacted>@github.com/x/y");
1234        assert!(!out.contains("ghp_tok123"));
1235    }
1236
1237    #[cfg(unix)]
1238    #[test]
1239    fn test_check_output_redacts_stderr_on_failure() {
1240        // Stderr from a failing subprocess must be redacted before
1241        // the logger surfaces it, so secrets present in `output.stderr`
1242        // never reach the eprintln sink (or any future log appender).
1243        let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
1244            "REGISTRY_PASSWORD".to_string(),
1245            "supersecret_pw_123".to_string(),
1246        )]);
1247        let output = fake_output(
1248            b"",
1249            b"docker login failed: invalid password 'supersecret_pw_123'",
1250            1,
1251        );
1252        let (stderr_line, _) = log.format_output_lines(&output, "docker login");
1253        let line = stderr_line.expect("stderr should be present on failure");
1254        assert!(
1255            !line.contains("supersecret_pw_123"),
1256            "stderr must be redacted: {line}"
1257        );
1258        assert!(line.contains("$REGISTRY_PASSWORD"));
1259    }
1260
1261    #[cfg(unix)]
1262    #[test]
1263    fn test_check_output_redacts_stdout_on_failure() {
1264        // Stdout on the failure path must be redacted alongside
1265        // stderr. Some tools dump credentials onto stdout (e.g. helm
1266        // login prints a warning to stdout, not stderr).
1267        let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
1268            "DOCKER_PASSWORD".to_string(),
1269            "tok_dckr_abc".to_string(),
1270        )]);
1271        let output = fake_output(b"echoed config: DOCKER_PASSWORD=tok_dckr_abc\n", b"", 2);
1272        let (_, stdout_line) = log.format_output_lines(&output, "docker");
1273        let line = stdout_line.expect("stdout should be present on failure");
1274        assert!(!line.contains("tok_dckr_abc"));
1275        assert!(line.contains("$DOCKER_PASSWORD"));
1276    }
1277
1278    #[cfg(unix)]
1279    #[test]
1280    fn test_check_output_redacts_stdout_on_verbose_success() {
1281        // At verbose level, successful subprocess stdout is logged
1282        // too; it must also be redacted.
1283        let log = StageLogger::new("test", Verbosity::Verbose).with_env(vec![(
1284            "MY_API_KEY".to_string(),
1285            "key-abcdef-123".to_string(),
1286        )]);
1287        let output = fake_output(b"echo: key-abcdef-123 OK\n", b"", 0);
1288        let (_, stdout_line) = log.format_output_lines(&output, "echo");
1289        let line = stdout_line.expect("stdout should be present on success");
1290        assert!(!line.contains("key-abcdef-123"));
1291        assert!(line.contains("$MY_API_KEY"));
1292    }
1293
1294    #[cfg(unix)]
1295    #[test]
1296    fn test_check_output_strips_inline_url_credentials_without_env() {
1297        // A logger built without env still strips URL credentials,
1298        // so even when the user did not export a matching env var, an
1299        // inline `https://<user>:<pw>@host` in stderr is scrubbed.
1300        let log = StageLogger::new("test", Verbosity::Normal);
1301        let output = fake_output(
1302            b"",
1303            b"fatal: cannot read https://user:p4ssw0rd@example.com/repo.git\n",
1304            128,
1305        );
1306        let (stderr_line, _) = log.format_output_lines(&output, "git fetch");
1307        let line = stderr_line.expect("stderr should be present on failure");
1308        assert!(
1309            !line.contains("p4ssw0rd"),
1310            "userinfo must be redacted: {line}"
1311        );
1312        assert!(line.contains("<redacted>@example.com"));
1313    }
1314
1315    #[cfg(unix)]
1316    #[test]
1317    fn test_check_output_bail_message_excludes_raw_secret() {
1318        // The bail message embeds the (truncated, redacted) stderr tail
1319        // so an operator reading the bubbled anyhow chain sees something
1320        // more actionable than the bare exit code. That redaction must
1321        // still strip env-resolved secrets — otherwise the new tail
1322        // would leak whatever stderr the subprocess emitted.
1323        let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
1324            "AUTH_TOKEN".to_string(),
1325            "secret_zzz_yyy".to_string(),
1326        )]);
1327        let output = fake_output(b"", b"401 Unauthorized: secret_zzz_yyy\n", 1);
1328        let err = log
1329            .check_output(output, "curl")
1330            .expect_err("non-zero exit should bail");
1331        let msg = format!("{err:#}");
1332        assert!(
1333            !msg.contains("secret_zzz_yyy"),
1334            "bail message leaks secret: {msg}"
1335        );
1336        assert!(
1337            msg.contains("stderr:") && msg.contains("401 Unauthorized"),
1338            "bail message should embed redacted stderr tail: {msg}"
1339        );
1340    }
1341
1342    #[cfg(unix)]
1343    #[test]
1344    fn test_check_output_bail_includes_no_stderr_marker_when_empty() {
1345        // Subprocess failed with empty stderr — the bail still wants
1346        // SOMETHING after `stderr:` so a grep on operator logs sees a
1347        // deterministic marker rather than blank text.
1348        let log = StageLogger::new("test", Verbosity::Normal);
1349        let output = fake_output(b"", b"", 7);
1350        let err = log
1351            .check_output(output, "tool")
1352            .expect_err("non-zero exit should bail");
1353        let msg = format!("{err:#}");
1354        assert!(
1355            msg.contains("stderr: <no stderr>"),
1356            "expected explicit <no stderr> marker: {msg}"
1357        );
1358    }
1359
1360    #[cfg(unix)]
1361    #[test]
1362    fn test_check_output_bail_truncates_long_stderr() {
1363        // Stderr larger than the 2 KiB cap is truncated with an ellipsis
1364        // so the operator's error chain remains scannable.
1365        let log = StageLogger::new("test", Verbosity::Normal);
1366        // 3 KiB of stderr.
1367        let big = vec![b'x'; 3072];
1368        let output = fake_output(b"", &big, 1);
1369        let err = log
1370            .check_output(output, "tool")
1371            .expect_err("non-zero exit should bail");
1372        let msg = format!("{err:#}");
1373        assert!(
1374            msg.ends_with('…'),
1375            "expected ellipsis on truncated stderr: {msg}"
1376        );
1377        // Truncation must keep the surface manageable — well under
1378        // 3 KiB of raw stderr should make it into the bail.
1379        assert!(
1380            msg.len() < 2500,
1381            "bail message too long: {} bytes",
1382            msg.len()
1383        );
1384    }
1385
1386    #[test]
1387    fn test_with_env_is_arc_shared() {
1388        // Cloning a logger should share the env vec via Arc, not deep-copy.
1389        // Verified by pointer equality on the inner Vec backing the Arc.
1390        let env = vec![("K".to_string(), "v_long_enough_to_be_a_token".to_string())];
1391        let a = StageLogger::new("a", Verbosity::Normal).with_env(env);
1392        let b = a.clone();
1393        let pa: *const Vec<(String, String)> = a.env.as_ref().unwrap().as_ref();
1394        let pb: *const Vec<(String, String)> = b.env.as_ref().unwrap().as_ref();
1395        assert_eq!(pa, pb);
1396    }
1397
1398    #[test]
1399    fn test_with_stage_rebinds_stage_field() {
1400        // The per-line `[stage]` tag is gone from rendered output, but
1401        // `with_stage` still rebinds the `stage` field a logger carries (it
1402        // drives redaction env inheritance, not line formatting now).
1403        let log = StageLogger::new("release", Verbosity::Normal);
1404        assert_eq!(log.stage, "release");
1405        assert_eq!(log.with_stage("finalize").stage, "finalize");
1406    }
1407
1408    #[test]
1409    fn test_body_markers_render_at_body_indent() {
1410        // Body lines sit at the 3-space body indent (top level: no section
1411        // nesting) behind a colored marker glyph. ANSI codes are stripped
1412        // for the assertion so the test pins the visible shape, not palette.
1413        let _guard = SECTION_TEST_LOCK.lock().unwrap();
1414        // SAFETY: single-threaded under SECTION_TEST_LOCK.
1415        unsafe {
1416            std::env::remove_var("GITHUB_ACTIONS");
1417        }
1418        let strip = |s: String| {
1419            // Drop CSI sequences so the assertion is palette-independent.
1420            let mut out = String::new();
1421            let mut chars = s.chars().peekable();
1422            while let Some(c) = chars.next() {
1423                if c == '\u{1b}' {
1424                    for n in chars.by_ref() {
1425                        if n == 'm' {
1426                            break;
1427                        }
1428                    }
1429                } else {
1430                    out.push(c);
1431                }
1432            }
1433            out
1434        };
1435        assert_eq!(
1436            strip(StageLogger::render_body(MARKER_DETAIL, "x")),
1437            "   • x"
1438        );
1439        assert_eq!(
1440            strip(StageLogger::render_body(MARKER_SUCCESS, "ok")),
1441            "   ✓ ok"
1442        );
1443        assert_eq!(
1444            strip(StageLogger::render_body(MARKER_FAILURE, "bad")),
1445            "   ✗ bad"
1446        );
1447    }
1448
1449    #[test]
1450    fn test_kv_pads_plain_key_so_values_align() {
1451        // The padded key width counts the PLAIN key, not the ANSI-dimmed
1452        // bytes, so a short key and a long key share the same value column.
1453        let (log, cap) = StageLogger::with_capture("check", Verbosity::Normal);
1454        let w = ["targets", "runs"].iter().map(|k| k.len()).max().unwrap();
1455        log.kv("targets", "aarch64", w);
1456        log.kv("runs", "2", w);
1457        // The capture stores a normalized `key = value` form regardless of
1458        // the rendered padding/palette.
1459        assert_eq!(
1460            cap.all_messages(),
1461            vec![
1462                (LogLevel::Status, "targets = aarch64".to_string()),
1463                (LogLevel::Status, "runs = 2".to_string()),
1464            ]
1465        );
1466    }
1467
1468    #[test]
1469    fn test_retag_helpers_record_under_shared_capture() {
1470        // The retagged clone shares the capture sink, and the plain
1471        // delegations still record at the right level — locking the plumbing
1472        // independent of the rendered tag (which the capture does not store).
1473        let (log, cap) = StageLogger::with_capture("release", Verbosity::Normal);
1474
1475        log.with_stage("finalize").status("x");
1476        log.error("y");
1477        log.status("own-status");
1478        log.error("own-error");
1479
1480        assert_eq!(
1481            cap.all_messages(),
1482            vec![
1483                (LogLevel::Status, "x".to_string()),
1484                (LogLevel::Error, "y".to_string()),
1485                (LogLevel::Status, "own-status".to_string()),
1486                (LogLevel::Error, "own-error".to_string()),
1487            ]
1488        );
1489    }
1490}