diff --git a/crates/core/src/bin/commands/auto_update.rs b/crates/core/src/bin/commands/auto_update.rs index 5724eafc52..80ba973ef5 100644 --- a/crates/core/src/bin/commands/auto_update.rs +++ b/crates/core/src/bin/commands/auto_update.rs @@ -1046,15 +1046,34 @@ fn get_update_failure_count() -> u32 { /// directory. /// /// * Missing file → `0` (legitimate "no failures yet"). -/// * Present but unparseable → `MAX_UPDATE_FAILURES` (defensive: if the -/// counter file has been truncated or corrupted we must NOT silently -/// reset the lockout — that would be an amplification vector for any -/// process that can partially overwrite the file, defeating the -/// #3934 fix. Users can recover by explicitly deleting the file). +/// * Present but unparseable, OR unreadable for any reason other than being +/// absent → `MAX_UPDATE_FAILURES` (defensive: if the counter file has been +/// truncated, corrupted, or made unreadable we must NOT silently reset the +/// lockout — that would be an amplification vector for any process that can +/// partially overwrite or chmod the file, defeating the #3934 fix. Users can +/// recover by explicitly deleting the file). pub(crate) fn get_update_failure_count_at(dir: &std::path::Path) -> u32 { match fs::read_to_string(dir.join("update_failures")) { Ok(s) => s.trim().parse().unwrap_or(MAX_UPDATE_FAILURES), - Err(_) => 0, + // Genuinely absent: no failures yet. + Err(e) if e.kind() == std::io::ErrorKind::NotFound => 0, + // Present but unreadable (EACCES, EIO, a directory in its place) is the + // same situation as unparseable, and gets the same defensive answer. + // Reading it as zero would silently RESET the lockout — a fail-OPEN on + // the mechanism that bounds the #3934 restart loop, and an easier way to + // defeat it than the partial-overwrite this function's doc already + // guards against. + // + // Note this is NOT the read-only/full state dir case: EROFS and ENOSPC + // break writes, while reads still succeed or report NotFound, which is + // handled above. The states that land here are anomalous ones — a + // chmod'd or wrong-owner file, a directory in its place, a failing mount + // — and treating them as fully-failed is self-healing, because the gate + // re-reads every time and recovers the moment the file is readable again. + // + // `read_github_poll_bucket_at` in this file makes the same distinction + // for the same reason. + Err(_) => MAX_UPDATE_FAILURES, } } @@ -1073,10 +1092,34 @@ pub fn record_update_failure() { /// Testable variant of [`record_update_failure`] that writes into an /// explicit directory. Missing directories are created on demand. +/// What to persist after an install failure, given the raw read of the existing +/// counter — or `None` to write nothing at all. +/// +/// Split out from [`record_update_failure_at`] so the decision is testable +/// without contriving a filesystem that reads one way and writes another. +/// +/// The subtle case is the unreadable one. [`get_update_failure_count_at`] +/// deliberately reports an unreadable counter as [`MAX_UPDATE_FAILURES`] so the +/// GATE stays closed while the file cannot be read — that is transient and +/// self-healing, because the gate re-reads every time. Feeding that defensive +/// answer back into the file would be neither: it would bake `MAX + 1` into +/// disk and lock the node out of auto-update PERMANENTLY on one transient read +/// error (a flaky network mount, an EIO). That is a worse failure than the +/// fail-open it replaced, so an unreadable counter writes nothing. +fn next_failure_count(existing: std::io::Result) -> Option { + match existing { + Ok(s) => Some(s.trim().parse::().unwrap_or(0).saturating_add(1)), + Err(e) if e.kind() == std::io::ErrorKind::NotFound => Some(1), + Err(_) => None, + } +} + pub(crate) fn record_update_failure_at(dir: &std::path::Path) { let _mkdir = fs::create_dir_all(dir); - let count = get_update_failure_count_at(dir) + 1; - let _write = fs::write(dir.join("update_failures"), count.to_string()); + let path = dir.join("update_failures"); + if let Some(count) = next_failure_count(fs::read_to_string(&path)) { + let _write = fs::write(&path, count.to_string()); + } } /// Clear the update failure count. Called from the update command after a @@ -1609,6 +1652,78 @@ pub fn jittered_repoll_interval(base: Duration, jitter_fraction: f64, rand_unit: #[cfg(test)] mod tests { + /// A transient read error must not be persisted as a permanent lockout. + /// + /// `get_update_failure_count_at` answers MAX_UPDATE_FAILURES when the + /// counter cannot be read, which keeps the GATE closed while the condition + /// lasts and heals by itself. Recording a failure used to feed that answer + /// straight back through `+ 1`, so one transient EIO would write 4 to disk + /// and lock auto-update off forever — turning the fail-CLOSED read into a + /// permanent brick, which is worse than the fail-open it replaced (#5244). + #[test] + fn an_unreadable_counter_is_never_persisted_as_a_count() { + use std::io::{Error, ErrorKind}; + + assert_eq!( + super::next_failure_count(Err(Error::from(ErrorKind::PermissionDenied))), + None, + "an unreadable counter must write NOTHING: we cannot know the real count, and \ + inventing MAX+1 makes a transient error permanent" + ); + assert_eq!( + super::next_failure_count(Err(Error::from(ErrorKind::NotFound))), + Some(1), + "a genuinely absent counter is the first failure" + ); + assert_eq!( + super::next_failure_count(Ok("2".to_string())), + Some(3), + "the ordinary case still increments" + ); + assert_eq!( + super::next_failure_count(Ok("garbage".to_string())), + Some(1), + "an unparseable counter restarts the count rather than inventing a lockout" + ); + } + + /// An unreadable counter file must NOT read as "no failures". + /// + /// `Err(_) => 0` caught every read error, not just `NotFound`, so a counter + /// made unreadable (EACCES, EIO, a directory in its place) silently reset + /// the #3934 lockout — a fail-OPEN on the mechanism that bounds the + /// exit-42 → failed-install → restart loop. The doc comment above the + /// function promised the opposite and named the threat; only the parse path + /// was actually defended. See #5244. + /// + /// A directory is used rather than a chmod because it fails for root too, + /// so this cannot quietly degrade into a no-op in a container. + #[test] + fn an_unreadable_failure_counter_does_not_reset_the_lockout() { + let dir = tempfile::tempdir().unwrap(); + std::fs::create_dir(dir.path().join("update_failures")).unwrap(); + + assert_eq!( + super::get_update_failure_count_at(dir.path()), + super::MAX_UPDATE_FAILURES, + "an unreadable counter must be treated as fully-failed, not as zero: reading it as \ + zero re-enables the update loop the counter exists to stop" + ); + assert!( + !super::should_attempt_update_at(dir.path()), + "and the lockout it feeds must stay engaged" + ); + } + + /// The legitimate case still reads as zero, so a fresh node is not born + /// locked out. + #[test] + fn an_absent_failure_counter_reads_as_no_failures() { + let dir = tempfile::tempdir().unwrap(); + assert_eq!(super::get_update_failure_count_at(dir.path()), 0); + assert!(super::should_attempt_update_at(dir.path())); + } + use super::*; use freenet::transport::{ set_open_connection_count, signal_version_mismatch, version_mismatch_generation, diff --git a/crates/core/src/bin/commands/service/wrapper.rs b/crates/core/src/bin/commands/service/wrapper.rs index cfcf583935..ff596e641f 100644 --- a/crates/core/src/bin/commands/service/wrapper.rs +++ b/crates/core/src/bin/commands/service/wrapper.rs @@ -630,8 +630,19 @@ pub(super) fn run_wrapper(version: &str) -> Result<()> { /// update subprocess silently fails to start and the wrapper falls into /// the exit-42 / update-failed / backoff-relaunch loop documented in /// #3934 (which was also the root cause of "Check for Updates" being -/// broken in #3933). Null stdio is harmless on macOS/Linux because -/// `--quiet` already suppresses all output. +/// broken in #3933). +/// +/// KNOWN GAP (#5244): nulling stderr also discards everything `freenet update` +/// now reports about brick-safety — the WARN subscriber installed for the +/// subcommand, and the two unconditional messages saying crash-loop rollback +/// failed to arm. Under systemd those reach the journal; under this wrapper +/// (Windows, and the macOS tray path) they go nowhere. `--quiet` no longer +/// suppresses them, so the previous claim that nulling was harmless because +/// "--quiet already suppresses all output" is no longer true. Fixing it means +/// pointing stderr at the wrapper log (`log_wrapper_event`'s file) rather than +/// at null — the Windows constraint above is about INHERITED invalid handles, +/// not about needing null specifically — and threading a log dir through all +/// five call sites. /// /// `post_stop_exit_code` is `Some(code)` ONLY when this update runs as part of /// the node's restart cycle (the node exited `code` and the wrapper is applying diff --git a/crates/core/src/bin/commands/update.rs b/crates/core/src/bin/commands/update.rs index 6bb77c6fae..3fe4f6b57d 100644 --- a/crates/core/src/bin/commands/update.rs +++ b/crates/core/src/bin/commands/update.rs @@ -706,12 +706,20 @@ impl UpdateCommand { ) { Ok(prepared) => Some(prepared), Err(e) => { - if !self.quiet { - eprintln!( - "Warning: failed to snapshot known-good binary for crash-loop \ - rollback: {e}. Proceeding without rollback protection for this update." - ); - } + // NOT gated on `--quiet` (#5244). This is one of the two states + // where #4073's brick-safety machinery is silently OFF: the + // update is about to land with no rollback target, so a release + // that then crash-loops cannot be reverted. `--quiet` must mean + // "be less chatty", never "do not record safety events". + // Belt-and-braces alongside the subscriber installed in + // `freenet_main`, so this survives a later refactor that drops + // the subscriber. Matches `handle_post_stop`'s precedent above. + eprintln!( + "Freenet: failed to snapshot the known-good binary for crash-loop \ + rollback: {e}. PROCEEDING WITHOUT ROLLBACK PROTECTION for this update — if \ + this version crash-loops it will NOT be auto-reverted. Check the \ + permissions and free space on the Freenet state directory." + ); tracing::warn!(error = %e, "Failed to capture known-good rollback binary (#4073)"); None } @@ -749,12 +757,15 @@ impl UpdateCommand { ¤t_exe, &meta, ) { - if !self.quiet { - eprintln!( - "Warning: installed the update but failed to arm crash-loop rollback \ - protection: {e}. If this version crash-loops it will NOT auto-roll-back." - ); - } + // NOT gated on `--quiet` — see the sibling above (#5244). + // The update HAS landed and the probation marker is absent, so + // the post-stop hook will find nothing to count and this + // version can crash-loop indefinitely without being reverted. + eprintln!( + "Freenet: installed the update but FAILED TO ARM crash-loop rollback \ + protection: {e}. If this version crash-loops it will NOT be auto-reverted. \ + Check the permissions and free space on the Freenet state directory." + ); tracing::warn!(error = %e, "Failed to arm crash-loop rollback probation (#4073)"); } } diff --git a/crates/core/src/bin/freenet.rs b/crates/core/src/bin/freenet.rs index 83261fa712..1f80b9f027 100644 --- a/crates/core/src/bin/freenet.rs +++ b/crates/core/src/bin/freenet.rs @@ -870,10 +870,45 @@ async fn run_network_node_with_signals( } } } else { - tracing::debug!( - "Periodic re-poll: skipped — auto-update locked out after repeated \ + // Once per process, not once per 6h tick: the lockout + // persists until an operator acts, so this is a state to + // announce on each boot rather than a recurring alarm. + // Mirrors the existing `LOCKOUT_WARNED` pattern in + // `check_if_update_available`. + static LOCKOUT_REPORTED: std::sync::atomic::AtomicBool = + std::sync::atomic::AtomicBool::new(false); + if !LOCKOUT_REPORTED.swap(true, std::sync::atomic::Ordering::Relaxed) { + // The second state where the update machinery is silently + // OFF (#5244). This was `debug!`, which release builds + // compile out entirely (`release_max_level_info`), and the + // loud once-per-process warning in `check_if_update_available` + // is only reachable from the PEER-signal triggers — so on a + // node whose peers all share its version, nothing said this + // node would never update again. + // + // Once per process, mirroring that existing `LOCKOUT_WARNED` + // pattern: the condition is permanent until an operator + // acts, so repeating it every 6h forever is noise, and one + // line per restart is enough to find it. + // Names the file as well as the command: the lockout can + // also be reached with the counter UNREADABLE, and in that + // state `freenet update` cannot clear it (the removal is + // best-effort and fails the same way the read did), so + // "run freenet update" alone would be advice that does not + // work. `--force` bypasses the gate for a one-off recovery. + eprintln!( + "Freenet: auto-update is LOCKED OUT on this node (repeated failed \ + installs, #3934, or an unreadable failure counter). It will not detect \ + or apply any further release until this is cleared: run `freenet \ + update` manually, or delete `update_failures` in the Freenet state \ + directory (~/.local/state/freenet on Linux). `freenet update --force` \ + bypasses the gate for a single run." + ); + tracing::warn!( + "Periodic re-poll: skipped — auto-update locked out after repeated \ failed installs (#3934); run `freenet update` to recover" - ); + ); + } } } } @@ -1188,7 +1223,17 @@ fn freenet_main() -> anyhow::Result<()> { config_paths, ) } - Some(Command::Update(cmd)) => cmd.run(build_info::VERSION), + Some(Command::Update(cmd)) => { + // #5244: this process previously ran with NO subscriber installed — + // `set_logger` is called only on the node path — so every + // `tracing::warn!`/`error!` in the installer was a no-op. That is + // the process the supervisor runs from `ExecStopPost` to drive + // crash-loop rollback, so its warnings are exactly the ones an + // operator needs. WARN (not INFO) because this runs on every + // non-clean stop of a crash-looping node. + freenet::config::set_cli_logger(tracing::level_filters::LevelFilter::WARN); + cmd.run(build_info::VERSION) + } Some(Command::Uninstall(cmd)) => cmd.run(), Some(Command::Secrets(cfg)) => { // CLI utility; uses simple current-thread runtime (no diff --git a/crates/core/src/config.rs b/crates/core/src/config.rs index f1501185b6..e1f1d46708 100644 --- a/crates/core/src/config.rs +++ b/crates/core/src/config.rs @@ -5102,6 +5102,45 @@ impl GlobalTestMetrics { } } +/// Install the logger for a short-lived CLI subcommand: stderr only, at +/// `level`. +/// +/// Separate from [`set_logger`] on purpose. `set_logger` serves the node, where +/// output MUST keep going to the rolling log files (`freenet service report` +/// collects them, and on Windows nothing captures stdout). Adding a "log to +/// stderr instead" flag to that path would put a switch capable of silently +/// disabling file logging on the node's only logging call — so the CLI gets its +/// own entry point rather than a shared, mis-settable one. +/// +/// See `tracing::tracer::init_cli_stderr_tracer` for why stderr specifically +/// (#5244). +pub fn set_cli_logger(level: tracing::level_filters::LevelFilter) { + #[cfg(feature = "trace")] + { + static CLI_LOGGER_SET: AtomicBool = AtomicBool::new(false); + if CLI_LOGGER_SET + .compare_exchange( + false, + true, + std::sync::atomic::Ordering::Release, + std::sync::atomic::Ordering::SeqCst, + ) + .is_err() + { + return; + } + + // Best-effort: a CLI subcommand that cannot install a subscriber must + // still do its job. Failing the update because logging could not start + // would turn a diagnostics problem into an outage. + if let Err(e) = crate::tracing::tracer::init_cli_stderr_tracer(level) { + eprintln!("Warning: could not initialize logging for this command: {e}"); + } + } + #[cfg(not(feature = "trace"))] + let _ = level; +} + pub fn set_logger( level: Option, endpoint: Option, diff --git a/crates/core/src/tracing/tracer.rs b/crates/core/src/tracing/tracer.rs index 6bb8ae4926..de9b51f242 100644 --- a/crates/core/src/tracing/tracer.rs +++ b/crates/core/src/tracing/tracer.rs @@ -744,6 +744,89 @@ pub fn init_tracer( ) } +/// Install a stderr-only subscriber for a short-lived CLI subcommand. +/// +/// ## Why this exists (#5244) +/// +/// `freenet update` ran with **no subscriber at all**: `set_logger` is called +/// only on the node path (`run_node`), so every `tracing::warn!` / `error!` in +/// the installer was a no-op. Combined with the supervisor invoking it as +/// `freenet update --quiet`, sites whose only output was a `warn!` plus a +/// `!quiet`-gated `eprintln!` were completely silent in production — including +/// "installed the update but could not arm crash-loop rollback". +/// +/// ## Why not just call [`set_logger`] here +/// +/// Two traps, both of which produce a fix that looks done and changes nothing: +/// +/// 1. Passing a `log_dir` (the natural copy-paste from `run_node`) sets +/// `use_file_logging`, which routes everything into the rolling log files. +/// systemd captures stdout/stderr, NOT those files — that asymmetry is the +/// whole of #5232. Every `warn!` would start "working" and the journal would +/// stay exactly as blind. +/// 2. With no log dir, [`init_tracer`] still falls through to stdout unless the +/// `FREENET_LOG_TO_STDERR` env var happens to be set. +/// +/// So this is explicit rather than configuration-dependent: **stderr, always**. +/// Diagnostics belong there, it leaves the command's human-facing `println!` +/// output on stdout, and systemd records both. +/// +/// Deliberately minimal: no file appenders, no rate limiters. This is a +/// process that runs for seconds and exits, and the output it must not lose is +/// the handful of lines saying a safety mechanism did not engage. +/// +/// `FREENET_DISABLE_LOGS` is still honoured, and `RUST_LOG` still overrides +/// `level` via `from_env_lossy`. +pub fn init_cli_stderr_tracer(level: LevelFilter) -> anyhow::Result<()> { + if std::env::var("FREENET_DISABLE_LOGS").is_ok() { + return Ok(()); + } + let use_json = std::env::var("FREENET_LOG_FORMAT") + .map(|v| v.eq_ignore_ascii_case("json")) + .unwrap_or(false); + let filter_layer = tracing_subscriber::EnvFilter::builder() + .with_default_directive(level.into()) + .from_env_lossy() + .add_directive("moka=off".parse().expect("infallible")) + .add_directive("sqlx=error".parse().expect("infallible")); + + // ANSI only for a human at a terminal. journald stores what it is given + // byte for byte, so colouring unconditionally would write escape sequences + // into the journal — which is the destination this whole function exists to + // reach. The file layers in `init_tracer` set `.with_ansi(false)` for the + // same reason. + let ansi = std::io::stderr().is_terminal(); + + use tracing_subscriber::layer::SubscriberExt; + let registry = Registry::default().with(filter_layer); + // `compact` rather than the `pretty` multi-line format `init_stdout_tracer` + // uses: one journal entry per event is far easier to read (and to grep) + // than an event split across several. + let result = if use_json { + tracing::subscriber::set_global_default( + registry.with( + tracing_subscriber::fmt::layer() + .json() + .with_ansi(false) + .with_writer(std::io::stderr), + ), + ) + } else { + tracing::subscriber::set_global_default( + registry.with( + tracing_subscriber::fmt::layer() + .compact() + .with_ansi(ansi) + .with_writer(std::io::stderr), + ), + ) + }; + // Returned, not `expect`ed. `init_stdout_tracer` panics here, which for a + // CLI would turn "a subscriber was already installed" into a failed update + // — trading a diagnostics problem for an outage. + result.map_err(|e| anyhow::anyhow!("could not install the CLI subscriber: {e}")) +} + fn init_stdout_tracer( _default_filter: LevelFilter, to_stderr: bool, diff --git a/crates/core/tests/update_command_is_not_mute.rs b/crates/core/tests/update_command_is_not_mute.rs new file mode 100644 index 0000000000..ad6aff2c26 --- /dev/null +++ b/crates/core/tests/update_command_is_not_mute.rs @@ -0,0 +1,196 @@ +//! Guards for #5244: the `freenet update` process must not be mute. +//! +//! `set_logger` is installed only on the node path, so the `freenet update` +//! process ran with **no tracing subscriber at all** and every `tracing::warn!` +//! / `error!` in the installer was a no-op. The supervisor runs it as `freenet +//! update --quiet`, so sites whose only output was a `warn!` plus a +//! `!quiet`-gated `eprintln!` produced nothing at all in production — including +//! "installed the update but could not arm crash-loop rollback", which is +//! #4073's brick-safety machinery reporting that it is off. +//! +//! `crates/core/src/tracing/tracer.rs::init_cli_stderr_tracer` carries the +//! rationale for the shape of the fix, including the two traps that produce a +//! version of it that looks done and changes nothing. + +#![cfg(unix)] + +use std::path::{Path, PathBuf}; +use std::process::Command; +use std::time::{SystemTime, UNIX_EPOCH}; + +/// The binary Cargo built for THIS test run. +/// +/// Deliberately not a hand-rolled `target/debug/...` lookup: those prefer a +/// debug binary even under `--release` and silently assert against whatever was +/// left there by an earlier build. For a test whose entire job is to prove the +/// current binary is not mute, testing a stale one is the "verification that +/// cannot fail" failure mode. `tests/graceful_shutdown_exit_code.rs` uses this +/// same env var for the same reason. +const FREENET_BIN: &str = env!("CARGO_BIN_EXE_freenet"); + +fn workspace_root() -> PathBuf { + PathBuf::from(env!("CARGO_MANIFEST_DIR")) + .parent() + .and_then(|p| p.parent()) + .expect("workspace layout: crates/core/../../ should resolve") + .to_path_buf() +} + +/// Put the installer's GitHub cooldown far enough in the future that +/// `probe_latest_tag` defers, and near enough that it is not discarded as +/// implausible. +/// +/// This is what makes the test below deterministic and offline. Without it, +/// `update --check` reaches api.github.com, so the test would depend on the +/// network being up AND GitHub not rate-limiting a shared CI egress IP — and it +/// would spend real quota on every run, which #5102 went to some trouble to +/// conserve. With it, the command takes the cooldown branch, emits exactly one +/// known WARN, and exits before any HTTP. +fn arm_github_cooldown(home: &Path) { + let dir = home.join(".local/state/freenet"); + std::fs::create_dir_all(&dir).expect("create state dir"); + let until = SystemTime::now() + .duration_since(UNIX_EPOCH) + .expect("clock after epoch") + .as_secs() + + 600; + std::fs::write(dir.join("github_ratelimit_cooldown"), until.to_string()) + .expect("write cooldown"); +} + +fn run_update_check(home: &Path, rust_log: Option<&str>) -> (String, String) { + let mut cmd = Command::new(FREENET_BIN); + cmd.args(["update", "--check", "--quiet"]) + .env("HOME", home) + .env("FREENET_TELEMETRY_ENABLED", "false") + // A developer with any of these set must not get a vacuous pass. + .env_remove("FREENET_DISABLE_LOGS") + .env_remove("FREENET_LOG_FORMAT") + .env_remove("FREENET_LOG_TO_STDERR") + .env_remove("FREENET_POST_STOP_EXIT_CODE"); + match rust_log { + Some(v) => cmd.env("RUST_LOG", v), + None => cmd.env_remove("RUST_LOG"), + }; + let out = cmd.output().expect("run freenet update --check"); + ( + String::from_utf8_lossy(&out.stdout).into_owned(), + String::from_utf8_lossy(&out.stderr).into_owned(), + ) +} + +/// A WARN from the update process must reach stderr. +/// +/// The cooldown fixture guarantees exactly one WARN (`"Update check deferred"`, +/// `commands/update.rs`) on a path that makes no network call. Asserting on a +/// WARN rather than on TRACE matters: release builds set +/// `release_max_level_info`, which compiles `debug!`/`trace!` out entirely, so a +/// TRACE-based assertion would pass in CI's debug build and fail in the build we +/// actually ship. +/// +/// Before the fix this produced zero bytes on both streams — there was no +/// subscriber to read the event. +#[test] +fn a_warning_from_the_update_process_reaches_stderr() { + let home = tempfile::tempdir().expect("tempdir"); + arm_github_cooldown(home.path()); + + let (stdout, stderr) = run_update_check(home.path(), None); + + assert!( + stderr.contains("Update check deferred"), + "#5244: the update process emitted no WARN, so it has no subscriber installed and every \ + warn!/error! in the installer is a no-op — including the ones reporting that crash-loop \ + rollback failed to arm.\nstderr was:\n{stderr}\nstdout was:\n{stdout}" + ); + assert!( + stderr.contains("WARN"), + "the line reached stderr but without a level, so it came from somewhere other than the \ + subscriber:\n{stderr}" + ); + // Diagnostics on stderr keeps the command's own output stream clean, and + // systemd records both. + assert!( + stdout.trim().is_empty(), + "tracing output must not land on stdout:\n{stdout}" + ); +} + +/// The subscriber must not colour its output when stderr is not a terminal. +/// +/// journald stores what it is given byte for byte, so ANSI escapes would end up +/// in the journal this change exists to reach. `Command::output` gives the child +/// a pipe, never a tty, so this is the non-interactive case. +#[test] +fn the_update_process_does_not_write_ansi_escapes_to_a_pipe() { + let home = tempfile::tempdir().expect("tempdir"); + arm_github_cooldown(home.path()); + + let (_stdout, stderr) = run_update_check(home.path(), None); + + assert!( + !stderr.contains('\u{1b}'), + "ANSI escape sequences must not reach a non-terminal stderr — they would be stored \ + verbatim in the journal:\n{stderr:?}" + ); +} + +/// The `Update` arm must install the CLI logger, at WARN, and must NOT reach for +/// `set_logger`. +/// +/// Three separate regressions, none of which the runtime tests above can see: +/// +/// * No subscriber — they would catch that, but this fails faster and says why. +/// * `set_logger(None, None, Some(log_dir))`, the natural copy-paste from +/// `run_node`, sets `use_file_logging` and routes everything into the rolling +/// log files. systemd captures stdout/stderr, NOT those files — the asymmetry +/// that caused #5232 to be misdiagnosed. A terminal would still show output, +/// so the runtime tests would stay green while the journal stayed blind. +/// * A promotion to INFO or DEBUG. Nothing on the `--check` path logs at INFO +/// today, so a runtime test asserting "quiet at the default level" would pass +/// under that mutation and prove nothing. The level is pinned here, where it +/// is a fact about the code rather than about which paths happen to log. +/// +/// Scraped ACROSS files (test in `tests/`, source in `src/bin/`) so it can never +/// be satisfied by its own assertion strings, and with comments stripped so it +/// cannot be satisfied by a comment ABOUT the call — both failure modes are +/// documented in `.claude/rules/bug-prevention-patterns.md`. +#[test] +fn the_update_arm_installs_the_cli_logger_at_warn_and_not_a_file_logger() { + let src = std::fs::read_to_string(workspace_root().join("crates/core/src/bin/freenet.rs")) + .expect("read bin/freenet.rs"); + + let arm_start = src + .find("Some(Command::Update(cmd)) =>") + .expect("the Update dispatch arm must still exist"); + let arm = &src[arm_start..]; + let arm_end = arm + .find("Some(Command::Uninstall(cmd))") + .expect("the Uninstall arm must still follow Update; re-anchor this pin if it moved"); + let code: String = arm[..arm_end] + .lines() + .map(|l| match l.find("//") { + Some(i) => &l[..i], + None => l, + }) + .collect::>() + .join("\n"); + + assert!( + code.contains("set_cli_logger"), + "#5244: the Update arm must install a subscriber, or every warn!/error! in the \ + installer is a no-op. Arm code (comments stripped):\n{code}" + ); + assert!( + !code.contains("set_logger("), + "the Update arm must use `set_cli_logger`, NOT `set_logger`: the latter's log-dir \ + argument routes output into the rolling log files, which systemd does not capture, so \ + the journal would stay exactly as blind while the fix looked done. Arm code:\n{code}" + ); + assert!( + code.contains("LevelFilter::WARN"), + "the level must stay WARN: this runs on every non-clean stop, so INFO would flood the \ + journal of exactly the crash-looping node whose journal we need to read. Arm code:\n\ + {code}" + ); +}