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