use std::sync::Arc;
use std::sync::Mutex;
use std::sync::OnceLock;
use std::sync::atomic::{AtomicUsize, Ordering};
use colored::Colorize;
static SECTION_DEPTH: AtomicUsize = AtomicUsize::new(0);
pub const LOG_DEPTH_ENV: &str = "ANODIZER_LOG_DEPTH";
static BASE_DEPTH: OnceLock<usize> = OnceLock::new();
fn parse_base_depth(raw: Option<&str>) -> usize {
raw.and_then(|v| v.trim().parse().ok()).unwrap_or(0)
}
fn base_depth() -> usize {
*BASE_DEPTH.get_or_init(|| parse_base_depth(std::env::var(LOG_DEPTH_ENV).ok().as_deref()))
}
pub fn current_depth() -> usize {
base_depth() + SECTION_DEPTH.load(Ordering::Relaxed)
}
struct PendingHeader {
depth: usize,
verb: String,
msg: String,
flushed: bool,
}
static PENDING: Mutex<Vec<PendingHeader>> = Mutex::new(Vec::new());
fn flush_pending() {
let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
for entry in pending.iter_mut() {
if entry.flushed {
continue;
}
eprintln!("{}", render_header(entry.depth, &entry.verb, &entry.msg));
entry.flushed = true;
}
}
fn render_header(depth: usize, verb: &str, msg: &str) -> String {
render_gutter(&" ".repeat(depth), verb, |s| s.green().bold(), msg)
}
fn render_gutter(
prefix: &str,
label: &str,
paint: impl Fn(String) -> colored::ColoredString,
msg: &str,
) -> String {
let label = paint(format!("{label:>VERB_COLUMN$}"));
if msg.is_empty() {
format!("{prefix}{label}")
} else {
format!("{prefix}{label} {msg}")
}
}
const VERB_COLUMN: usize = 12;
const BODY_INDENT: &str = " ";
const MARKER_DETAIL: &str = "•";
const MARKER_SUCCESS: &str = "✓";
const MARKER_FAILURE: &str = "✗";
pub fn stage_header(stage: &str) -> &'static str {
match stage {
"setup" => "Preparing release",
"build" => "Building binaries",
"archive" => "Creating archives",
"checksum" => "Computing checksums",
"sbom" => "Cataloging dependencies",
"templatefiles" => "Rendering templates",
"changelog" => "Generating changelog",
"attest" => "Generating attestations",
"binary-sign" => "Signing binaries",
"sign" => "Signing artifacts",
"docker" => "Building images",
"docker-sign" => "Signing images",
"upx" => "Compressing binaries",
"nfpm" => "Building packages",
"snapcraft" => "Building snap",
"flatpak" => "Building Flatpak",
"msi" => "Building MSI",
"nsis" => "Building installer",
"dmg" => "Building DMG",
"pkg" => "Building pkg",
"notarize" => "Notarizing app",
"makeself" => "Building installer",
"srpm" => "Building source RPM",
"appbundle" => "Building app bundle",
"appimage" => "Building AppImage",
"universal" => "Merging binaries",
"source" => "Archiving source",
"release" => "Creating release",
"before-publish" => "Preparing publishers",
"emission-validate" => "Validating output",
"publish" => "Publishing",
"blob" => "Uploading blobs",
"snapcraft-publish" => "Publishing snap",
"announce" => "Announcing release",
"verify-release" => "Verifying release",
"publisher-summary" => "Summary",
"check-determinism" => "Checking determinism",
"finalize" => "Finalizing",
"prepare" => "Preparing",
_ => "Running",
}
}
pub fn render_warning(msg: &str) -> String {
render_gutter(&label_indent(), "Warning", |s| s.yellow().bold(), msg)
}
pub fn render_error(msg: &str) -> String {
render_gutter(&label_indent(), "Error", |s| s.red().bold(), msg)
}
pub fn render_note(msg: &str) -> String {
render_gutter(&label_indent(), "Note", |s| s.green().bold(), msg)
}
pub fn indent() -> String {
" ".repeat(current_depth())
}
fn label_indent() -> String {
" ".repeat(current_depth().saturating_sub(1).max(base_depth()))
}
#[must_use = "dropping the guard immediately removes the extra indent"]
pub struct IndentGuard {
_private: (),
}
impl Drop for IndentGuard {
fn drop(&mut self) {
SECTION_DEPTH.fetch_sub(1, Ordering::Relaxed);
}
}
pub fn indent_one_level() -> IndentGuard {
SECTION_DEPTH.fetch_add(1, Ordering::Relaxed);
IndentGuard { _private: () }
}
#[must_use = "dropping the guard immediately ends the section"]
pub struct SectionGuard {
_private: (),
}
impl Drop for SectionGuard {
fn drop(&mut self) {
let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
SECTION_DEPTH.fetch_sub(1, Ordering::Relaxed);
pending.pop();
}
}
#[cfg(feature = "test-helpers")]
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub enum LogLevel {
Error,
Warn,
Status,
Heartbeat,
Verbose,
Debug,
}
#[cfg(feature = "test-helpers")]
#[derive(Clone, Default)]
pub struct LogCapture {
inner: Arc<Mutex<Vec<(LogLevel, String)>>>,
}
#[cfg(feature = "test-helpers")]
impl LogCapture {
pub fn new() -> Self {
Self::default()
}
pub(crate) fn record(&self, level: LogLevel, msg: impl Into<String>) {
if let Ok(mut guard) = self.inner.lock() {
guard.push((level, msg.into()));
}
}
pub fn status_count(&self) -> usize {
self.count(LogLevel::Status)
}
pub fn debug_count(&self) -> usize {
self.count(LogLevel::Debug)
}
pub fn verbose_count(&self) -> usize {
self.count(LogLevel::Verbose)
}
pub fn warn_count(&self) -> usize {
self.count(LogLevel::Warn)
}
pub fn heartbeat_count(&self) -> usize {
self.count(LogLevel::Heartbeat)
}
pub fn error_count(&self) -> usize {
self.count(LogLevel::Error)
}
pub fn total_count(&self) -> usize {
self.inner.lock().map(|g| g.len()).unwrap_or(0)
}
fn count(&self, level: LogLevel) -> usize {
self.inner
.lock()
.map(|g| g.iter().filter(|(l, _)| *l == level).count())
.unwrap_or(0)
}
pub fn all_messages(&self) -> Vec<(LogLevel, String)> {
self.inner.lock().map(|g| g.clone()).unwrap_or_default()
}
pub fn warn_messages(&self) -> Vec<String> {
self.inner
.lock()
.map(|g| {
g.iter()
.filter(|(lvl, _)| *lvl == LogLevel::Warn)
.map(|(_, m)| m.clone())
.collect()
})
.unwrap_or_default()
}
}
#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Default)]
pub enum Verbosity {
Quiet,
#[default]
Normal,
Verbose,
Debug,
}
impl Verbosity {
pub fn from_flags(quiet: bool, verbose: bool, debug: bool) -> Self {
if debug {
Verbosity::Debug
} else if quiet {
Verbosity::Quiet
} else if verbose {
Verbosity::Verbose
} else {
Verbosity::Normal
}
}
}
#[derive(Clone)]
pub struct StageLogger {
#[allow(dead_code)]
stage: &'static str,
verbosity: Verbosity,
env: Option<Arc<Vec<(String, String)>>>,
#[cfg(feature = "test-helpers")]
capture: Option<LogCapture>,
}
impl StageLogger {
pub fn new(stage: &'static str, verbosity: Verbosity) -> Self {
Self {
stage,
verbosity,
env: None,
#[cfg(feature = "test-helpers")]
capture: None,
}
}
#[cfg(feature = "test-helpers")]
pub fn with_capture(stage: &'static str, verbosity: Verbosity) -> (Self, LogCapture) {
let capture = LogCapture::new();
let logger = Self {
stage,
verbosity,
env: None,
capture: Some(capture.clone()),
};
(logger, capture)
}
#[cfg(feature = "test-helpers")]
pub fn with_capture_handle(mut self, capture: LogCapture) -> Self {
self.capture = Some(capture);
self
}
pub fn with_env(mut self, env: Vec<(String, String)>) -> Self {
self.env = Some(Arc::new(env));
self
}
pub fn with_stage(&self, stage: &'static str) -> Self {
Self {
stage,
verbosity: self.verbosity,
env: self.env.clone(),
#[cfg(feature = "test-helpers")]
capture: self.capture.clone(),
}
}
pub fn redact(&self, s: &str) -> String {
match self.env.as_deref() {
Some(env) => crate::redact::with_env(s, env),
None => crate::redact::redact_url_credentials(s),
}
}
fn render_body(marker: &str, text: &str) -> String {
format!("{}{}{} {}", indent(), BODY_INDENT, marker, text)
}
pub fn error(&self, msg: &str) {
flush_pending();
eprintln!("{}", render_error(msg));
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Error, msg);
}
}
pub fn warn(&self, msg: &str) {
if self.verbosity >= Verbosity::Normal {
flush_pending();
eprintln!("{}", render_warning(msg));
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Warn, msg);
}
}
pub fn status(&self, msg: &str) {
if self.verbosity >= Verbosity::Normal {
if msg.is_empty() {
eprintln!();
} else {
flush_pending();
eprintln!(
"{}",
Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
);
}
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Status, msg);
}
}
pub fn detail(&self, msg: &str) {
if self.verbosity >= Verbosity::Normal {
flush_pending();
eprintln!(
"{}",
Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
);
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Status, msg);
}
}
pub fn success(&self, msg: &str) {
if self.verbosity >= Verbosity::Normal {
flush_pending();
eprintln!(
"{}",
Self::render_body(&MARKER_SUCCESS.green().to_string(), msg)
);
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Status, msg);
}
}
pub fn failure(&self, msg: &str) {
if self.verbosity >= Verbosity::Normal {
flush_pending();
eprintln!(
"{}",
Self::render_body(&MARKER_FAILURE.red().to_string(), msg)
);
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Status, msg);
}
}
pub fn heartbeats_enabled(&self) -> bool {
self.verbosity == Verbosity::Normal
}
pub fn heartbeat(&self, msg: &str) {
if !self.heartbeats_enabled() {
return;
}
flush_pending();
eprintln!(
"{}",
Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
);
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Heartbeat, msg);
}
}
pub fn kv(&self, key: &str, value: &str, key_width: usize) {
if self.verbosity >= Verbosity::Normal {
let padded = format!("{key:<key_width$}");
let row = format!("{} {}", padded.dimmed(), value);
flush_pending();
eprintln!(
"{}",
Self::render_body(&MARKER_DETAIL.cyan().to_string(), &row)
);
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Status, format!("{key} = {value}"));
}
}
pub fn step(&self, verb: &str, msg: &str) {
if self.verbosity >= Verbosity::Normal {
eprintln!("{}", render_header(current_depth(), verb, msg));
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Status, msg);
}
}
#[must_use = "the section stays open only while the guard is alive"]
pub fn group(&self, title: &str) -> SectionGuard {
let (verb, msg) = self.split_header(title);
let mut pending = PENDING.lock().unwrap_or_else(|e| e.into_inner());
pending.push(PendingHeader {
depth: current_depth(),
verb: verb.to_string(),
msg: msg.to_string(),
flushed: false,
});
SECTION_DEPTH.fetch_add(1, Ordering::Relaxed);
SectionGuard { _private: () }
}
fn split_header<'a>(&self, title: &'a str) -> (&'a str, &'a str) {
let phrase = stage_header(title);
match phrase.split_once(' ') {
Some((verb, rest)) => (verb, rest),
None if phrase == "Running" => (phrase, title),
None => (phrase, ""),
}
}
pub fn verbose(&self, msg: &str) {
if self.verbosity >= Verbosity::Verbose {
flush_pending();
eprintln!(
"{}",
Self::render_body(&MARKER_DETAIL.cyan().to_string(), msg)
);
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Verbose, msg);
}
}
pub fn debug(&self, msg: &str) {
if self.verbosity >= Verbosity::Debug {
flush_pending();
eprintln!(
"{}",
Self::render_body(
&MARKER_DETAIL.dimmed().to_string(),
&msg.dimmed().to_string()
)
);
}
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
cap.record(LogLevel::Debug, msg);
}
}
pub fn skip_line(&self, show: bool, msg: &str) {
if show {
self.status(msg);
} else {
self.debug(msg);
}
}
pub fn verbosity(&self) -> Verbosity {
self.verbosity
}
pub fn redaction_env(&self) -> Vec<(String, String)> {
self.env.as_deref().cloned().unwrap_or_default()
}
pub fn is_verbose(&self) -> bool {
self.verbosity >= Verbosity::Verbose
}
pub fn is_debug(&self) -> bool {
self.verbosity >= Verbosity::Debug
}
pub fn stream_child_stdout(&self, line: &str) {
self.stream_child_line(line, false);
}
pub fn stream_child_stderr(&self, line: &str) {
self.stream_child_line(line, true);
}
fn stream_child_line(&self, line: &str, from_stderr: bool) {
let redacted = self.redact(line);
flush_pending();
eprintln!("{redacted}");
#[cfg(feature = "test-helpers")]
if let Some(cap) = &self.capture {
let level = if from_stderr {
LogLevel::Error
} else {
LogLevel::Verbose
};
cap.record(level, redacted);
}
#[cfg(not(feature = "test-helpers"))]
let _ = from_stderr;
}
pub fn check_output(
&self,
output: std::process::Output,
label: &str,
) -> anyhow::Result<std::process::Output> {
self.check_output_inner(output, label, false)
}
pub fn check_output_streamed(
&self,
output: std::process::Output,
label: &str,
) -> anyhow::Result<std::process::Output> {
self.check_output_inner(output, label, true)
}
fn check_output_inner(
&self,
output: std::process::Output,
label: &str,
already_streamed: bool,
) -> anyhow::Result<std::process::Output> {
let (stderr_line, stdout_line) = self.format_output_lines(&output, label);
if !output.status.success() {
if !already_streamed {
if let Some(line) = stderr_line {
self.error(&line);
}
if let Some(line) = stdout_line {
self.error(&line);
}
}
let stderr_raw = String::from_utf8_lossy(&output.stderr);
let stderr_tail = if stderr_raw.is_empty() {
String::from("<no stderr>")
} else {
let stripped = strip_ansi(&stderr_raw);
let redacted = self.redact(&stripped);
let trimmed = redacted.trim();
const MAX: usize = 2048;
if trimmed.len() > MAX {
let cut = trimmed
.char_indices()
.nth(MAX)
.map(|(i, _)| i)
.unwrap_or(MAX);
format!("{}…", &trimmed[..cut])
} else {
trimmed.to_string()
}
};
anyhow::bail!(
"{} failed with exit code: {}; stderr: {}",
label,
output.status.code().unwrap_or(-1),
stderr_tail
);
}
if !already_streamed
&& self.is_verbose()
&& let Some(line) = stdout_line
{
self.verbose(&line);
}
Ok(output)
}
pub(crate) fn format_output_lines(
&self,
output: &std::process::Output,
label: &str,
) -> (Option<String>, Option<String>) {
let stderr_raw = String::from_utf8_lossy(&output.stderr);
let stderr_line = if stderr_raw.is_empty() {
None
} else {
let stderr = self.redact(&stderr_raw);
let prefix = if output.status.success() {
"output"
} else {
"stderr"
};
if output.status.success() {
None
} else {
Some(format!("{label} {prefix}:\n{stderr}"))
}
};
let stdout_raw = String::from_utf8_lossy(&output.stdout);
let stdout_line = if stdout_raw.is_empty() {
None
} else {
let stdout = self.redact(&stdout_raw);
let prefix = if output.status.success() {
"output"
} else {
"stdout"
};
Some(format!("{label} {prefix}:\n{stdout}"))
};
(stderr_line, stdout_line)
}
}
pub(crate) fn strip_ansi(s: &str) -> String {
let mut out = String::with_capacity(s.len());
let mut chars = s.chars();
while let Some(c) = chars.next() {
if c == '\u{1b}' {
if chars.next() == Some('[') {
for ec in chars.by_ref() {
if ('\u{40}'..='\u{7e}').contains(&ec) {
break;
}
}
}
} else {
out.push(c);
}
}
out
}
#[cfg(test)]
mod tests {
use super::*;
static SECTION_TEST_LOCK: Mutex<()> = Mutex::new(());
#[test]
fn test_group_guard_balances_depth_locally() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("build", Verbosity::Normal);
let start = SECTION_DEPTH.load(Ordering::Relaxed);
{
let _outer = log.group("build");
assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
{
let _inner = log.group("sign");
assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 2);
}
assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
}
assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start);
}
#[test]
fn test_group_quiet_still_tracks_local_depth() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("build", Verbosity::Quiet);
let start = SECTION_DEPTH.load(Ordering::Relaxed);
{
let _s = log.group("build");
assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
}
assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start);
}
#[test]
fn test_group_with_body_flushes_header_once() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("build", Verbosity::Normal);
{
let _section = log.group("build");
assert!(!PENDING.lock().unwrap().last().unwrap().flushed);
log.status("compiling x86_64-unknown-linux-gnu");
let pending = PENDING.lock().unwrap();
let entry = pending.last().unwrap();
assert!(entry.flushed, "body line must flush the header");
assert_eq!(entry.verb, "Building");
assert_eq!(entry.msg, "binaries");
}
assert!(PENDING.lock().unwrap().is_empty());
}
#[test]
fn test_noop_group_prints_no_header() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("verify-release", Verbosity::Normal);
{
let _section = log.group("verify-release");
log.status(""); assert!(
!PENDING.lock().unwrap().last().unwrap().flushed,
"a no-op section's header must stay unflushed"
);
}
assert!(PENDING.lock().unwrap().is_empty());
}
#[test]
fn test_nested_groups_flush_in_ancestor_order() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("publish", Verbosity::Normal);
let start = SECTION_DEPTH.load(Ordering::Relaxed);
{
let _outer = log.group("publish");
{
let _inner = log.group("blob");
log.status("uploading blob");
let pending = PENDING.lock().unwrap();
assert_eq!(pending.len(), 2);
assert!(pending[0].flushed, "ancestor header must flush");
assert!(pending[1].flushed, "nested header must flush");
assert_eq!(pending[0].depth, start);
assert_eq!(pending[1].depth, start + 1);
}
}
assert!(PENDING.lock().unwrap().is_empty());
}
#[cfg(unix)]
fn capture_stderr(f: impl FnOnce()) -> Option<String> {
use std::io::{Read, Seek, SeekFrom, Write};
use std::os::unix::io::AsRawFd;
struct StderrRestore(libc::c_int);
impl Drop for StderrRestore {
fn drop(&mut self) {
unsafe {
libc::dup2(self.0, libc::STDERR_FILENO);
libc::close(self.0);
}
}
}
let mut file = tempfile::tempfile().expect("tempfile for stderr capture");
std::io::stderr().flush().ok();
let saved = unsafe { libc::dup(libc::STDERR_FILENO) };
assert!(saved >= 0, "dup(stderr) failed");
unsafe {
assert!(
libc::dup2(file.as_raw_fd(), libc::STDERR_FILENO) >= 0,
"dup2(tempfile, stderr) failed"
);
}
let _restore = StderrRestore(saved);
const SENTINEL: &str = "__anodizer_capture_probe__";
eprintln!("{SENTINEL}");
f();
std::io::stderr().flush().ok();
file.seek(SeekFrom::Start(0)).expect("rewind capture file");
let mut out = String::new();
file.read_to_string(&mut out).expect("read capture file");
let body = out.strip_prefix(SENTINEL)?.trim_start_matches('\n');
Some(body.to_string())
}
#[test]
#[cfg(unix)]
#[serial_test::serial]
fn test_header_paths_emit_identical_bytes() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("sign", Verbosity::Normal);
let depth = current_depth();
let flushed = capture_stderr(|| {
let _section = log.group("sign");
assert_eq!(
PENDING.lock().unwrap().last().unwrap().depth,
depth,
"pending header must sit at the pre-increment depth"
);
log.status("byte-equality probe"); });
assert!(
PENDING.lock().unwrap().is_empty(),
"guard must pop the entry"
);
assert_eq!(current_depth(), depth, "depth must return to start");
let stepped = capture_stderr(|| log.step("Signing", "artifacts"));
let prefix = " ".repeat(depth);
let expected = format!("{prefix}{:>VERB_COLUMN$} artifacts", "Signing");
match (flushed, stepped) {
(Some(flushed), Some(stepped)) => {
let flush_header = strip_ansi(
flushed
.lines()
.next()
.expect("flush_pending must emit a header line"),
);
let step_header = strip_ansi(stepped.trim_end_matches('\n'));
assert_eq!(
flush_header, step_header,
"flush_pending and step must emit byte-identical headers \
(flush={flush_header:?} step={step_header:?})"
);
assert_eq!(
step_header, expected,
"header must be indent + gutter verb + space + message"
);
}
(None, None) => {
assert_eq!(
strip_ansi(&render_header(depth, "Signing", "artifacts")),
expected
);
}
(flushed, stepped) => panic!(
"inconsistent stderr capture: flush={} step={}",
flushed.is_some(),
stepped.is_some()
),
}
}
#[test]
#[cfg(unix)]
#[serial_test::serial]
fn test_single_word_header_emits_no_trailing_space() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("publish", Verbosity::Normal);
let depth = current_depth();
let prefix = " ".repeat(depth);
match capture_stderr(|| log.step("Publishing", "")) {
Some(stepped) => {
let header = strip_ansi(stepped.trim_end_matches('\n'));
assert_eq!(header, format!("{prefix}{:>VERB_COLUMN$}", "Publishing"));
assert!(
!header.ends_with(' '),
"single-word header must not carry a trailing space: {header:?}"
);
}
None => {
let header = strip_ansi(&render_header(depth, "Publishing", ""));
assert_eq!(header, format!("{prefix}{:>VERB_COLUMN$}", "Publishing"));
assert!(!header.ends_with(' '));
}
}
}
#[test]
fn test_status_labels_gutter_aligned_without_colon() {
let header = strip_ansi(&render_header(0, "Building", "binaries"));
let header_msg_col = header.find("binaries");
for (rendered, label, msg) in [
(render_warning("oops"), "Warning", "oops"),
(render_error("boom"), "Error", "boom"),
(render_note("fyi"), "Note", "fyi"),
] {
let line = strip_ansi(&rendered);
assert!(
!line.contains(':'),
"status label must not carry a colon: {line:?}"
);
assert_eq!(line, strip_ansi(&render_header(0, label, msg)));
assert_eq!(
line.find(msg),
header_msg_col,
"status-label message must align with the header message column"
);
}
}
#[test]
#[serial_test::serial]
fn test_status_label_aligns_with_enclosing_header_not_body_depth() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("build", Verbosity::Normal);
let base = base_depth();
let _outer = log.group("preparing release");
let warn = strip_ansi(&render_warning("preflight skipped"));
assert_eq!(
warn,
strip_ansi(&render_header(base, "Warning", "preflight skipped")),
"in-section label must align with its enclosing header"
);
assert_ne!(
warn,
strip_ansi(&render_header(base + 1, "Warning", "preflight skipped")),
"in-section label must not float at the deeper body indent"
);
}
#[test]
#[cfg(unix)]
#[serial_test::serial]
fn test_capture_stderr_restores_fd_on_panic() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let panicked = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| {
capture_stderr(|| panic!("boom inside capture"));
}));
assert!(panicked.is_err(), "the injected panic must propagate");
let after = capture_stderr(|| eprintln!("after panic"));
if let Some(body) = after {
assert!(
body.contains("after panic"),
"stderr must work after a mid-capture panic: {body:?}"
);
}
}
#[test]
fn test_indent_reflects_section_depth() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("build", Verbosity::Normal);
let base = " ".repeat(base_depth());
assert_eq!(indent(), base);
{
let _outer = log.group("build");
assert_eq!(indent(), format!("{base} "));
{
let _inner = log.group("sign");
assert_eq!(indent(), format!("{base} "));
}
assert_eq!(indent(), format!("{base} "));
}
assert_eq!(indent(), base);
}
#[test]
fn test_indent_one_level_adds_depth_without_pending_header() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let start = SECTION_DEPTH.load(Ordering::Relaxed);
let pending_before = PENDING.lock().unwrap().len();
{
let _indent = indent_one_level();
assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start + 1);
assert_eq!(
PENDING.lock().unwrap().len(),
pending_before,
"indent_one_level must not push a pending header"
);
assert_eq!(indent(), " ".repeat(current_depth()));
}
assert_eq!(SECTION_DEPTH.load(Ordering::Relaxed), start);
}
#[test]
fn test_parse_base_depth_accepts_valid_and_degrades_invalid() {
assert_eq!(parse_base_depth(Some("3")), 3);
assert_eq!(parse_base_depth(Some(" 2 ")), 2);
assert_eq!(parse_base_depth(Some("0")), 0);
assert_eq!(parse_base_depth(Some("-1")), 0);
assert_eq!(parse_base_depth(Some("abc")), 0);
assert_eq!(parse_base_depth(Some("")), 0);
assert_eq!(parse_base_depth(None), 0);
}
#[test]
fn test_current_depth_tracks_sections() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let log = StageLogger::new("build", Verbosity::Normal);
let start = current_depth();
{
let _outer = log.group("build");
assert_eq!(current_depth(), start + 1);
}
assert_eq!(current_depth(), start);
}
#[test]
fn test_stage_header_splits_into_verb_and_message() {
let log = StageLogger::new("build", Verbosity::Normal);
assert_eq!(log.split_header("build"), ("Building", "binaries"));
assert_eq!(log.split_header("sign"), ("Signing", "artifacts"));
assert_eq!(log.split_header("source"), ("Archiving", "source"));
}
#[test]
fn test_stage_header_single_word_renders_verb_only() {
let log = StageLogger::new("publish", Verbosity::Normal);
assert_eq!(log.split_header("publish"), ("Publishing", ""));
}
#[test]
fn test_stage_header_unknown_stage_uses_running_plus_name() {
let log = StageLogger::new("x", Verbosity::Normal);
assert_eq!(
log.split_header("myfancystage"),
("Running", "myfancystage")
);
}
#[test]
fn test_verbosity_from_flags_default() {
assert_eq!(
Verbosity::from_flags(false, false, false),
Verbosity::Normal
);
}
#[test]
fn test_verbosity_from_flags_quiet() {
assert_eq!(Verbosity::from_flags(true, false, false), Verbosity::Quiet);
}
#[test]
fn test_verbosity_from_flags_verbose() {
assert_eq!(
Verbosity::from_flags(false, true, false),
Verbosity::Verbose
);
}
#[test]
fn test_verbosity_from_flags_debug() {
assert_eq!(Verbosity::from_flags(false, false, true), Verbosity::Debug);
}
#[test]
fn test_verbosity_from_flags_debug_wins_over_verbose() {
assert_eq!(Verbosity::from_flags(false, true, true), Verbosity::Debug);
}
#[test]
fn test_verbosity_from_flags_debug_wins_over_quiet() {
assert_eq!(Verbosity::from_flags(true, false, true), Verbosity::Debug);
}
#[test]
fn test_verbosity_from_flags_quiet_overrides_verbose() {
assert_eq!(Verbosity::from_flags(true, true, false), Verbosity::Quiet);
}
#[test]
fn test_verbosity_ordering() {
assert!(Verbosity::Quiet < Verbosity::Normal);
assert!(Verbosity::Normal < Verbosity::Verbose);
assert!(Verbosity::Verbose < Verbosity::Debug);
}
#[test]
fn test_stage_logger_is_verbose() {
let log = StageLogger::new("test", Verbosity::Verbose);
assert!(log.is_verbose());
assert!(!log.is_debug());
}
#[test]
fn test_stage_logger_is_debug() {
let log = StageLogger::new("test", Verbosity::Debug);
assert!(log.is_verbose());
assert!(log.is_debug());
}
#[test]
fn test_stage_logger_normal_not_verbose() {
let log = StageLogger::new("test", Verbosity::Normal);
assert!(!log.is_verbose());
assert!(!log.is_debug());
}
#[test]
fn test_default_verbosity_is_normal() {
assert_eq!(Verbosity::default(), Verbosity::Normal);
}
#[cfg(unix)]
fn fake_output(stdout: &[u8], stderr: &[u8], code: i32) -> std::process::Output {
use std::os::unix::process::ExitStatusExt;
std::process::Output {
status: std::process::ExitStatus::from_raw(code << 8),
stdout: stdout.to_vec(),
stderr: stderr.to_vec(),
}
}
#[test]
fn test_redact_uses_attached_env() {
let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
"GITHUB_TOKEN".to_string(),
"ghp_real_secret_token".to_string(),
)]);
let out = log.redact("auth header: ghp_real_secret_token");
assert_eq!(out, "auth header: $GITHUB_TOKEN");
assert!(!out.contains("ghp_real_secret_token"));
}
#[test]
fn test_redact_without_env_only_scrubs_inline_urls() {
let log = StageLogger::new("test", Verbosity::Normal);
let out = log.redact("fetched from https://user:tok@example.com/path");
assert_eq!(out, "fetched from https://<redacted>@example.com/path");
}
#[test]
fn test_redact_combines_env_and_url_credentials() {
let log = StageLogger::new("test", Verbosity::Normal)
.with_env(vec![("API_TOKEN".to_string(), "ghp_tok123".to_string())]);
let out = log.redact("remote: https://ghp_tok123@github.com/x/y");
assert_eq!(out, "remote: https://<redacted>@github.com/x/y");
assert!(!out.contains("ghp_tok123"));
}
#[cfg(unix)]
#[test]
fn test_check_output_redacts_stderr_on_failure() {
let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
"REGISTRY_PASSWORD".to_string(),
"supersecret_pw_123".to_string(),
)]);
let output = fake_output(
b"",
b"docker login failed: invalid password 'supersecret_pw_123'",
1,
);
let (stderr_line, _) = log.format_output_lines(&output, "docker login");
let line = stderr_line.expect("stderr should be present on failure");
assert!(
!line.contains("supersecret_pw_123"),
"stderr must be redacted: {line}"
);
assert!(line.contains("$REGISTRY_PASSWORD"));
}
#[cfg(unix)]
#[test]
fn test_check_output_redacts_stdout_on_failure() {
let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
"DOCKER_PASSWORD".to_string(),
"tok_dckr_abc".to_string(),
)]);
let output = fake_output(b"echoed config: DOCKER_PASSWORD=tok_dckr_abc\n", b"", 2);
let (_, stdout_line) = log.format_output_lines(&output, "docker");
let line = stdout_line.expect("stdout should be present on failure");
assert!(!line.contains("tok_dckr_abc"));
assert!(line.contains("$DOCKER_PASSWORD"));
}
#[cfg(unix)]
#[test]
fn test_check_output_redacts_stdout_on_verbose_success() {
let log = StageLogger::new("test", Verbosity::Verbose).with_env(vec![(
"MY_API_KEY".to_string(),
"key-abcdef-123".to_string(),
)]);
let output = fake_output(b"echo: key-abcdef-123 OK\n", b"", 0);
let (_, stdout_line) = log.format_output_lines(&output, "echo");
let line = stdout_line.expect("stdout should be present on success");
assert!(!line.contains("key-abcdef-123"));
assert!(line.contains("$MY_API_KEY"));
}
#[cfg(unix)]
#[test]
fn test_check_output_strips_inline_url_credentials_without_env() {
let log = StageLogger::new("test", Verbosity::Normal);
let output = fake_output(
b"",
b"fatal: cannot read https://user:p4ssw0rd@example.com/repo.git\n",
128,
);
let (stderr_line, _) = log.format_output_lines(&output, "git fetch");
let line = stderr_line.expect("stderr should be present on failure");
assert!(
!line.contains("p4ssw0rd"),
"userinfo must be redacted: {line}"
);
assert!(line.contains("<redacted>@example.com"));
}
#[cfg(unix)]
#[test]
fn test_check_output_bail_message_excludes_raw_secret() {
let log = StageLogger::new("test", Verbosity::Normal).with_env(vec![(
"AUTH_TOKEN".to_string(),
"secret_zzz_yyy".to_string(),
)]);
let output = fake_output(b"", b"401 Unauthorized: secret_zzz_yyy\n", 1);
let err = log
.check_output(output, "curl")
.expect_err("non-zero exit should bail");
let msg = format!("{err:#}");
assert!(
!msg.contains("secret_zzz_yyy"),
"bail message leaks secret: {msg}"
);
assert!(
msg.contains("stderr:") && msg.contains("401 Unauthorized"),
"bail message should embed redacted stderr tail: {msg}"
);
}
#[cfg(unix)]
#[test]
fn test_check_output_bail_message_strips_ansi_color_codes() {
let log = StageLogger::new("test", Verbosity::Normal);
let colorized =
b"\x1b[1mPackaging\x1b[0m foo \x1b[2mv\x1b[1m0.11.3\x1b[0m\n\x1b[31merror\x1b[0m: exit \x1b[33m101\x1b[0m\n";
let output = fake_output(b"", colorized, 101);
let err = log
.check_output(output, "cargo publish")
.expect_err("non-zero exit should bail");
let msg = format!("{err:#}");
assert!(
!msg.contains('\u{1b}'),
"bail message must contain no ANSI escape bytes: {msg:?}"
);
assert!(
msg.contains("Packaging") && msg.contains("0.11.3") && msg.contains("101"),
"plain-text content must survive ANSI stripping: {msg}"
);
}
#[cfg(unix)]
#[test]
fn test_check_output_bail_includes_no_stderr_marker_when_empty() {
let log = StageLogger::new("test", Verbosity::Normal);
let output = fake_output(b"", b"", 7);
let err = log
.check_output(output, "tool")
.expect_err("non-zero exit should bail");
let msg = format!("{err:#}");
assert!(
msg.contains("stderr: <no stderr>"),
"expected explicit <no stderr> marker: {msg}"
);
}
#[cfg(unix)]
#[test]
fn test_check_output_bail_truncates_long_stderr() {
let log = StageLogger::new("test", Verbosity::Normal);
let big = vec![b'x'; 3072];
let output = fake_output(b"", &big, 1);
let err = log
.check_output(output, "tool")
.expect_err("non-zero exit should bail");
let msg = format!("{err:#}");
assert!(
msg.ends_with('…'),
"expected ellipsis on truncated stderr: {msg}"
);
assert!(
msg.len() < 2500,
"bail message too long: {} bytes",
msg.len()
);
}
#[test]
fn test_with_env_is_arc_shared() {
let env = vec![("K".to_string(), "v_long_enough_to_be_a_token".to_string())];
let a = StageLogger::new("a", Verbosity::Normal).with_env(env);
let b = a.clone();
let pa: *const Vec<(String, String)> = a.env.as_ref().unwrap().as_ref();
let pb: *const Vec<(String, String)> = b.env.as_ref().unwrap().as_ref();
assert_eq!(pa, pb);
}
#[test]
fn test_with_stage_rebinds_stage_field() {
let log = StageLogger::new("release", Verbosity::Normal);
assert_eq!(log.stage, "release");
assert_eq!(log.with_stage("finalize").stage, "finalize");
}
#[test]
fn test_body_markers_render_at_body_indent() {
let _guard = SECTION_TEST_LOCK.lock().unwrap();
let strip = |s: String| {
let mut out = String::new();
let mut chars = s.chars().peekable();
while let Some(c) = chars.next() {
if c == '\u{1b}' {
for n in chars.by_ref() {
if n == 'm' {
break;
}
}
} else {
out.push(c);
}
}
out
};
let prefix = indent();
assert_eq!(
strip(StageLogger::render_body(MARKER_DETAIL, "x")),
format!("{prefix} • x")
);
assert_eq!(
strip(StageLogger::render_body(MARKER_SUCCESS, "ok")),
format!("{prefix} ✓ ok")
);
assert_eq!(
strip(StageLogger::render_body(MARKER_FAILURE, "bad")),
format!("{prefix} ✗ bad")
);
}
#[test]
fn test_kv_pads_plain_key_so_values_align() {
let _guard = SECTION_TEST_LOCK.lock().unwrap_or_else(|e| e.into_inner());
let (log, cap) = StageLogger::with_capture("check", Verbosity::Normal);
let w = ["targets", "runs"].iter().map(|k| k.len()).max().unwrap();
log.kv("targets", "aarch64", w);
log.kv("runs", "2", w);
assert_eq!(
cap.all_messages(),
vec![
(LogLevel::Status, "targets = aarch64".to_string()),
(LogLevel::Status, "runs = 2".to_string()),
]
);
}
#[test]
fn test_retag_helpers_record_under_shared_capture() {
let _guard = SECTION_TEST_LOCK.lock().unwrap_or_else(|e| e.into_inner());
let (log, cap) = StageLogger::with_capture("release", Verbosity::Normal);
log.with_stage("finalize").status("x");
log.error("y");
log.status("own-status");
log.error("own-error");
assert_eq!(
cap.all_messages(),
vec![
(LogLevel::Status, "x".to_string()),
(LogLevel::Error, "y".to_string()),
(LogLevel::Status, "own-status".to_string()),
(LogLevel::Error, "own-error".to_string()),
]
);
}
#[test]
fn skip_line_records_debug_when_not_shown() {
let _guard = SECTION_TEST_LOCK.lock().unwrap_or_else(|e| e.into_inner());
let (log, cap) = StageLogger::with_capture("homebrew", Verbosity::Normal);
log.skip_line(
false,
"skipped homebrew for crate 'demo' — no homebrew config block",
);
assert_eq!(cap.debug_count(), 1);
assert_eq!(cap.status_count(), 0);
assert_eq!(
cap.all_messages(),
vec![(
LogLevel::Debug,
"skipped homebrew for crate 'demo' — no homebrew config block".to_string()
)]
);
}
#[test]
fn skip_line_records_status_when_shown() {
let _guard = SECTION_TEST_LOCK.lock().unwrap_or_else(|e| e.into_inner());
let (log, cap) = StageLogger::with_capture("homebrew", Verbosity::Normal);
log.skip_line(
true,
"skipped homebrew for crate 'demo' — no homebrew config block",
);
assert_eq!(cap.status_count(), 1);
assert_eq!(cap.debug_count(), 0);
}
}