From bafb54a8ccb0d0316f196f301c1d49f57f2c8aa4 Mon Sep 17 00:00:00 2001 From: Michael Taylor Date: Fri, 28 Aug 2026 16:26:00 -0700 Subject: [PATCH 1/2] feat(logging): report file-sink health on control.status `dig-logging` 0.1.4 made `init` all-or-nothing: when the rolling file appender could not be built it returned `Err` and the stderr layer was never installed either, so the process ran with NO tracing subscriber at all. A user running `dig-node run` interactively on a host where the machine log dir belongs to the service account got silence, which reads as a dead subsystem rather than a broken one. `dig-logging` 0.2.0 (already declared on main) degrades to console-only logging instead and reports the reason via `LogGuard::file_error()`. This wires that signal through: - `logging::{health, file_error, log_dir, initialized}` expose the guard state; `health` is pure in its inputs so both arms are testable without a process-global subscriber. - `control.status` gains a `logging` object (`initialized`, `dir`, `file_logging`, `file_error`). A node serving while writing nothing to disk no longer reports healthy file logging. - `tests/logging_degraded.rs` proves the property end to end. The fixture is a path whose PARENT is a regular file, so `create_dir_all` cannot succeed on any platform -- it does not depend on running unprivileged, on ACLs, or on a read-only mount, the three things that make a permission fixture pass for the wrong reason. - SPEC.md records the degraded contract (SS20.1). Additive only: a new JSON field on an existing method, no signature changed. `logging::init`'s two callers (entrypoint.rs, win_service.rs) are untouched. Co-Authored-By: Claude --- Cargo.lock | 2 +- Cargo.toml | 2 +- SPEC.md | 10 ++- crates/dig-node-service/src/control.rs | 8 ++ crates/dig-node-service/src/logging.rs | 86 ++++++++++++++++++- .../tests/logging_degraded.rs | 81 +++++++++++++++++ 6 files changed, 181 insertions(+), 8 deletions(-) create mode 100644 crates/dig-node-service/tests/logging_degraded.rs diff --git a/Cargo.lock b/Cargo.lock index 2ee66565..6c76d329 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -3067,7 +3067,7 @@ dependencies = [ [[package]] name = "dig-node-service" -version = "0.164.0" +version = "0.165.0" dependencies = [ "async-trait", "axum", diff --git a/Cargo.toml b/Cargo.toml index 68de8916..6e3e5238 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -32,7 +32,7 @@ edition = "2021" # the ROOT manifest (`[workspace.package].version`), so it MUST be set here for a # release to fire (§3.6). The library crates (dig-node-core/dig-runtime/dig-wallet) # keep their own independent versions — only the released binary tracks the workspace version. -version = "0.164.0" +version = "0.165.0" # Release hardening, matching digstore: keep integer-overflow checks ON in release. # The node parses untrusted serialized input and does offset/length arithmetic over diff --git a/SPEC.md b/SPEC.md index e69dca3c..8c3093b0 100644 --- a/SPEC.md +++ b/SPEC.md @@ -1589,7 +1589,7 @@ lowercase 64-hex; a capsule reference is `storeId:rootHash`. Malformed refs yiel | Method | Params | Result (essentials) | |---|---|---| -| `control.status` | — | `running`, `service`, `version`, `commit`, `protocol`, `uptime_secs`, `addr`, `upstream`, `cache`, `hosted_store_count`, `cached_capsule_count`, `pinned_store_count`, `sync.available` | +| `control.status` | — | `running`, `service`, `version`, `commit`, `protocol`, `uptime_secs`, `addr`, `upstream`, `cache`, `hosted_store_count`, `cached_capsule_count`, `pinned_store_count`, `sync.available`, `logging` (`initialized`, `dir`, `file_logging`, `file_error` — §20.1) | | `control.config.get` | — | `addr`, `port`, `upstream`, `upstream_override`, `cache_dir`, `cache_shared`, `config_path`, `sync_available` | | `control.config.setUpstream` | `upstream` (URL string; blank clears) | `upstream` (normalized), `requires_restart: true` — persisted, effective on next start (§3.4) | | `control.log.setLevel` | `filter` (an `EnvFilter` directive, e.g. `debug` or `info,dig_node_core=debug`) | `filter` (echoed) — live-applied via the `dig-logging` reload handle, effective immediately, NOT persisted (§11); `INVALID_PARAMS` on a missing/malformed directive, `CONTROL_ERROR` when logging is not installed in the process | @@ -6702,7 +6702,13 @@ returned guard for the process lifetime: A one-shot CLI command (`status`, `pair`, `config`, …) does NOT install the subscriber: it neither needs a rolling log file nor the maintenance thread. Installation is best-effort — a logging failure -(unwritable dir, subscriber already set) is reported on stderr and MUST NOT stop the node serving. +(subscriber already set) is reported on stderr and MUST NOT stop the node serving. + +An UNWRITABLE log directory MUST NOT cost the console sink. `dig-logging` 0.2.0 degrades to +console-only logging and reports the reason via `LogGuard::file_error()`; the node MUST keep serving +and MUST report that condition on `control.status` (`logging.file_logging: false` plus +`logging.file_error`). A node that is serving while writing nothing to disk MUST NOT report healthy +file logging. The log directory follows `dig-logging` SPEC §3: the machine root `<…>/DigNetwork/logs/dig-node` (`C:\ProgramData\DigNetwork\logs\dig-node`, `/Library/Logs/DigNetwork/dig-node`, diff --git a/crates/dig-node-service/src/control.rs b/crates/dig-node-service/src/control.rs index 90281a0b..2e47b42c 100644 --- a/crates/dig-node-service/src/control.rs +++ b/crates/dig-node-service/src/control.rs @@ -978,6 +978,14 @@ async fn status(ctx: &ControlCtx) -> Value { // The Sage-parity wallet mTLS listener (dig-node#260). Its bind is best-effort, so // an operator needs somewhere to SEE that it lost its port — silence was the defect. "wallet_mtls": crate::wallet_mtls::status_json(), + // #553/dig-logging 0.2.0: a degraded file sink no longer fails `init`, so the node can be + // serving and logging to the console while writing nothing to disk. Report that here + // rather than letting an operator infer healthy logging from a healthy node. + "logging": crate::logging::health( + crate::logging::initialized(), + crate::logging::log_dir().as_deref(), + crate::logging::file_error().as_deref(), + ), }) } diff --git a/crates/dig-node-service/src/logging.rs b/crates/dig-node-service/src/logging.rs index 3a938e91..2420a5ea 100644 --- a/crates/dig-node-service/src/logging.rs +++ b/crates/dig-node-service/src/logging.rs @@ -28,6 +28,7 @@ use std::sync::OnceLock; use dig_logging::{LogGuard, RunContext, Service}; +use serde_json::{json, Value}; use crate::meta::{SERVICE_NAME, VERSION}; @@ -61,9 +62,20 @@ pub fn run_context() -> RunContext { /// Install the shared logging stack for a SERVE run (SPEC §1) and hold the guard for the /// process lifetime. Idempotent + best-effort: a second call (e.g. a test that serves twice -/// in one process) is a silent no-op, and a failure to install — the log dir is unwritable, -/// or a subscriber is already set — is reported on stderr and swallowed, because a logging -/// problem must NEVER stop the node from serving. +/// in one process) is a silent no-op. +/// +/// Since `dig-logging` 0.2.0 an unwritable log directory is NO LONGER an `init` failure: the +/// crate degrades to console-only logging and reports the reason via +/// [`dig_logging::LogGuard::file_error`], which this module re-exports as [`file_error`] and +/// `control.status` surfaces. That is the whole point of the uplift — under 0.1.x the same +/// condition returned `Err`, the stderr layer was never installed, and an interactive +/// `dig-node run` on a host whose machine log dir belongs to the service account ran with NO +/// subscriber at all, i.e. completely silent. +/// +/// The remaining `Err` arm is therefore narrow — a subscriber is already installed by this +/// process, or (per the crate's docs, not reachable in practice) an unparseable filter. It is +/// still reported on stderr and swallowed, because a logging problem must NEVER stop the node +/// from serving. pub fn init(run_context: RunContext) { if GUARD.get().is_some() { return; @@ -78,12 +90,48 @@ pub fn init(run_context: RunContext) { Err(e) => { eprintln!( "dig-node: WARN could not install structured logging ({e}); \ - continuing without a log file" + continuing without a subscriber" ); } } } +/// Why the rolling JSONL file sink is disabled for this process, or `None` when it is live (or +/// when this process never installed logging at all — see [`initialized`]). +/// +/// Console logging is installed either way, so this is a health signal, not a failure: a node +/// that reported healthy logging while writing to nothing would be the exact untruth the +/// `dig-logging` 0.2.0 uplift exists to remove. +pub fn file_error() -> Option { + GUARD.get()?.file_error().map(str::to_owned) +} + +/// The log directory this process resolved. When [`file_error`] is set, NOTHING is being written +/// there — it is the directory that could not be opened, which is what makes it worth reporting. +pub fn log_dir() -> Option { + GUARD.get().map(|g| g.log_dir().to_path_buf()) +} + +/// Whether a serve path installed the logging stack in this process. +pub fn initialized() -> bool { + GUARD.get().is_some() +} + +/// The node's own logging health, as reported by `control.status`. Pure in its inputs so both +/// arms are testable without a process-global subscriber: `file_error` is +/// [`dig_logging::LogGuard::file_error`], `dir` the resolved directory. +/// +/// The nearest wrong implementation reports `file_logging: true` whenever logging initialised — +/// which is precisely the lie a degraded file sink makes possible. +pub fn health(initialized: bool, dir: Option<&std::path::Path>, file_error: Option<&str>) -> Value { + json!({ + "initialized": initialized, + "dir": dir.map(|d| d.display().to_string()), + "file_logging": initialized && file_error.is_none(), + "file_error": file_error, + }) +} + /// Record one JSON-RPC dispatch for per-request diagnosis (SPEC §6), at `DEBUG` so it stays off /// the default `INFO` operator view. A fresh `op_id` correlates every log line emitted while /// serving this request. @@ -125,4 +173,34 @@ mod tests { // `control.log.setLevel` on a non-serving process fails cleanly.) assert!(set_level("debug").is_err()); } + + #[test] + fn health_reports_file_logging_off_and_names_the_reason() { + // The degraded case the 0.2.0 uplift exists for: the subscriber IS installed (console + // logging works) but nothing reaches the file. A surface that reported `file_logging: + // true` here would be the untruth being removed. + let dir = std::path::Path::new("/var/log/dig-node"); + let value = health(true, Some(dir), Some("permission denied")); + assert_eq!(value["initialized"], true); + assert_eq!(value["file_logging"], false); + assert_eq!(value["file_error"], "permission denied"); + assert_eq!(value["dir"], dir.display().to_string()); + } + + #[test] + fn health_reports_file_logging_on_when_the_sink_is_live() { + // The honest control for the test above: same shape, no error, so a `file_logging: false` + // constant would fail here and a `true` constant fails there. + let value = health(true, Some(std::path::Path::new("/tmp/logs")), None); + assert_eq!(value["file_logging"], true); + assert_eq!(value["file_error"], Value::Null); + } + + #[test] + fn health_never_claims_file_logging_when_logging_was_never_installed() { + let value = health(false, None, None); + assert_eq!(value["initialized"], false); + assert_eq!(value["file_logging"], false); + assert_eq!(value["dir"], Value::Null); + } } diff --git a/crates/dig-node-service/tests/logging_degraded.rs b/crates/dig-node-service/tests/logging_degraded.rs new file mode 100644 index 00000000..ef1bd200 --- /dev/null +++ b/crates/dig-node-service/tests/logging_degraded.rs @@ -0,0 +1,81 @@ +//! The property the `dig-logging` 0.2.0 adoption exists for: when the log directory cannot be +//! opened, the node still logs to stderr AND knows its file sink is off. +//! +//! Under `dig-logging` 0.1.x the same condition returned `Err` from `init`, so the console layer +//! was never installed and the process ran with NO tracing subscriber at all — an interactive +//! `dig-node run` on a host whose machine log dir belongs to the service account was completely +//! silent, which read as a dead subsystem rather than a broken one. +//! +//! ## Why this is an integration test, and why it is the whole file +//! +//! `tracing` has exactly ONE global subscriber per process and `logging::init` stores its guard +//! in a `OnceLock`, so the installed/degraded state can be established exactly once. This test +//! therefore owns its process: it sets `DIG_LOG_DIR` to an UNOPENABLE path before the only +//! `init` call, and every assertion reads that one outcome. +//! +//! The fixture is an unopenable directory in the strongest available sense: a path whose PARENT +//! is a regular FILE. `create_dir_all` cannot succeed under a file on any platform, so this does +//! not depend on running unprivileged, on ACLs, or on a read-only mount — the three things that +//! quietly make a permission fixture pass for the wrong reason (or, under a test runner elevated +//! to Administrator, not fail at all). + +use std::io::Write; + +use dig_logging::RunContext; +use dig_node_service::logging; +use tracing::level_filters::LevelFilter; + +/// A log-dir root that cannot be created: a path nested inside a regular file. +fn unopenable_log_root() -> std::path::PathBuf { + let base = std::env::temp_dir().join(format!("dig-node-logtest-{}", std::process::id())); + let mut file = std::fs::File::create(&base).expect("create the blocking regular file"); + file.write_all(b"not a directory").unwrap(); + base.join("root") +} + +#[test] +fn unwritable_log_dir_leaves_console_logging_live_and_the_file_sink_reported_off() { + let root = unopenable_log_root(); + // SAFETY: single-threaded test body, set before the process's only `init`. + unsafe { std::env::set_var("DIG_LOG_DIR", &root) }; + + logging::init(RunContext::Cli); + + // (1) The console sink is live. With no subscriber installed — the 0.1.x outcome for this + // exact input — `LevelFilter::current()` is `OFF`, so this assertion fails for the right + // reason on the unadopted crate rather than merely compiling differently. + assert!( + logging::initialized(), + "init must succeed and hold a guard even when the file sink cannot be opened" + ); + assert_ne!( + LevelFilter::current(), + LevelFilter::OFF, + "a subscriber must be installed, i.e. the node still logs to stderr" + ); + + // (2) The node KNOWS the file sink is off, and says why. + let file_error = logging::file_error(); + assert!( + file_error.is_some(), + "an unopenable log dir must be reported via file_error(), got None (log_dir: {:?})", + logging::log_dir() + ); + + // (3) The health surface `control.status` reports is consistent with (2): a degraded sink is + // never dressed up as healthy file logging. + let health = logging::health( + logging::initialized(), + logging::log_dir().as_deref(), + file_error.as_deref(), + ); + assert_eq!(health["initialized"], true); + assert_eq!(health["file_logging"], false); + assert!(health["file_error"].is_string()); + + // Emitting through the live subscriber must not panic; this is the behaviour the silent-node + // incident was missing. + tracing::info!(test = "degraded", "node still speaks on the console"); + + let _ = std::fs::remove_file(root.parent().unwrap()); +} From 193e7119cd95e9bb505d16ff0d924eb1a0793bc9 Mon Sep 17 00:00:00 2001 From: Michael Taylor Date: Fri, 28 Aug 2026 17:34:29 -0700 Subject: [PATCH 2/2] docs(logging): report file-sink health as a start-up verdict, not a live one The SPEC clause added by this PR ("a node serving while writing nothing to disk MUST NOT report healthy file logging") is not enforceable by the code that ships alongside it. dig-logging 0.2.0 computes `file_error` once during `init` (src/init.rs:91, moved into the guard at :139) and exposes a private field with a read-only accessor and no mutator (:41/:55), so after a post-init sink failure -- log dir deleted, volume full, rotation failure -- `file_error()` stays `None` and `control.status` keeps reporting `logging.file_logging: true`. Correct the claim to what the code can actually assert: file-sink health is determined at logger initialization and reported as of that point. The `logging` object stays -- the capability is real and worth reporting; only the strength of the claim was wrong. The doc-comments on `logging::health` and `logging::file_error` carried the same over-claim and now say plainly that a post-init failure is not detected, and the control.status method table flags the field as a start-up verdict where a reader meets it. No runtime behaviour change. Live file-sink health is tracked as DIG-Network/dig-logging#7. Co-Authored-By: Claude --- SPEC.md | 13 +++++++++--- crates/dig-node-service/src/logging.rs | 28 +++++++++++++++++--------- 2 files changed, 29 insertions(+), 12 deletions(-) diff --git a/SPEC.md b/SPEC.md index 8c3093b0..3c9d16fd 100644 --- a/SPEC.md +++ b/SPEC.md @@ -1589,7 +1589,7 @@ lowercase 64-hex; a capsule reference is `storeId:rootHash`. Malformed refs yiel | Method | Params | Result (essentials) | |---|---|---| -| `control.status` | — | `running`, `service`, `version`, `commit`, `protocol`, `uptime_secs`, `addr`, `upstream`, `cache`, `hosted_store_count`, `cached_capsule_count`, `pinned_store_count`, `sync.available`, `logging` (`initialized`, `dir`, `file_logging`, `file_error` — §20.1) | +| `control.status` | — | `running`, `service`, `version`, `commit`, `protocol`, `uptime_secs`, `addr`, `upstream`, `cache`, `hosted_store_count`, `cached_capsule_count`, `pinned_store_count`, `sync.available`, `logging` (`initialized`, `dir`, `file_logging`, `file_error` — a START-UP verdict; see §20.1) | | `control.config.get` | — | `addr`, `port`, `upstream`, `upstream_override`, `cache_dir`, `cache_shared`, `config_path`, `sync_available` | | `control.config.setUpstream` | `upstream` (URL string; blank clears) | `upstream` (normalized), `requires_restart: true` — persisted, effective on next start (§3.4) | | `control.log.setLevel` | `filter` (an `EnvFilter` directive, e.g. `debug` or `info,dig_node_core=debug`) | `filter` (echoed) — live-applied via the `dig-logging` reload handle, effective immediately, NOT persisted (§11); `INVALID_PARAMS` on a missing/malformed directive, `CONTROL_ERROR` when logging is not installed in the process | @@ -6707,8 +6707,15 @@ needs a rolling log file nor the maintenance thread. Installation is best-effort An UNWRITABLE log directory MUST NOT cost the console sink. `dig-logging` 0.2.0 degrades to console-only logging and reports the reason via `LogGuard::file_error()`; the node MUST keep serving and MUST report that condition on `control.status` (`logging.file_logging: false` plus -`logging.file_error`). A node that is serving while writing nothing to disk MUST NOT report healthy -file logging. +`logging.file_error`). + +`logging.file_logging` is a START-UP verdict, not a live one. `dig-logging` 0.2.0 determines file-sink +health ONCE, while installing the subscriber, and exposes no way to revise it afterwards, so +`control.status` MUST report it as of logger initialization: `logging.file_logging: true` asserts only +that the rolling JSONL sink OPENED SUCCESSFULLY at start-up, and `logging.file_error` names the reason +it did not. A sink failure that occurs AFTER initialization — the log directory deleted, the volume +filled, a rotation failure — is NOT detected, and the node MUST NOT be read as claiming otherwise. +Live file-sink health becomes reportable only once `dig-logging` can revise `file_error` after init. The log directory follows `dig-logging` SPEC §3: the machine root `<…>/DigNetwork/logs/dig-node` (`C:\ProgramData\DigNetwork\logs\dig-node`, `/Library/Logs/DigNetwork/dig-node`, diff --git a/crates/dig-node-service/src/logging.rs b/crates/dig-node-service/src/logging.rs index 2420a5ea..75989af3 100644 --- a/crates/dig-node-service/src/logging.rs +++ b/crates/dig-node-service/src/logging.rs @@ -96,12 +96,16 @@ pub fn init(run_context: RunContext) { } } -/// Why the rolling JSONL file sink is disabled for this process, or `None` when it is live (or -/// when this process never installed logging at all — see [`initialized`]). +/// Why the rolling JSONL file sink FAILED TO OPEN when this process installed logging, or `None` +/// when it opened successfully (or when this process never installed logging at all — see +/// [`initialized`]). /// -/// Console logging is installed either way, so this is a health signal, not a failure: a node -/// that reported healthy logging while writing to nothing would be the exact untruth the -/// `dig-logging` 0.2.0 uplift exists to remove. +/// This is a START-UP verdict and never changes. `dig-logging` 0.2.0 computes `file_error` once +/// during `init` and exposes no mutator, so a sink failure that happens LATER — the log directory +/// deleted, the volume filled, a rotation failure — is NOT detected here and this stays `None`. +/// Reading it as "the file sink is working right now" over-claims. +/// +/// Console logging is installed either way, so this is a health signal, not a failure. pub fn file_error() -> Option { GUARD.get()?.file_error().map(str::to_owned) } @@ -117,12 +121,18 @@ pub fn initialized() -> bool { GUARD.get().is_some() } -/// The node's own logging health, as reported by `control.status`. Pure in its inputs so both -/// arms are testable without a process-global subscriber: `file_error` is -/// [`dig_logging::LogGuard::file_error`], `dir` the resolved directory. +/// The node's own logging health AS OF LOGGER INITIALIZATION, as reported by `control.status`. +/// Pure in its inputs so both arms are testable without a process-global subscriber: `file_error` +/// is [`dig_logging::LogGuard::file_error`], `dir` the resolved directory. +/// +/// `file_logging: true` asserts that the rolling JSONL sink OPENED SUCCESSFULLY at start-up — not +/// that it is writing now. `dig-logging` 0.2.0 fixes `file_error` at init and offers no way to +/// revise it, so a post-init sink failure (directory deleted, volume full, rotation failure) is +/// NOT detected and this keeps reporting `true`. Widening that to live health needs post-init +/// revalidation in `dig-logging` first. /// /// The nearest wrong implementation reports `file_logging: true` whenever logging initialised — -/// which is precisely the lie a degraded file sink makes possible. +/// ignoring `file_error` entirely, which is the lie a start-up sink failure would then tell. pub fn health(initialized: bool, dir: Option<&std::path::Path>, file_error: Option<&str>) -> Value { json!({ "initialized": initialized,