diff --git a/Cargo.lock b/Cargo.lock index 59298b2c..51bd6ec1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2168,9 +2168,9 @@ dependencies = [ [[package]] name = "dig-logging" -version = "0.1.4" +version = "0.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c9c3a71bbd1b2784c5d7e2eea47edb57785a97da17fbcc9cd4f8339c9978cbf7" +checksum = "9c9f4a20dafd185b1b4a80eb7330765de129d7e188a5d19954d509030ef0b27c" dependencies = [ "bip39", "clap", @@ -2310,7 +2310,7 @@ dependencies = [ [[package]] name = "dig-node-service" -version = "0.124.1" +version = "0.125.0" dependencies = [ "async-trait", "axum", diff --git a/Cargo.toml b/Cargo.toml index 324f5500..cc08dea1 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.124.1" +version = "0.125.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 2b74392a..8aeaf409 100644 --- a/SPEC.md +++ b/SPEC.md @@ -1493,7 +1493,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 | @@ -5538,7 +5538,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/Cargo.toml b/crates/dig-node-service/Cargo.toml index e457c83e..2f856985 100644 --- a/crates/dig-node-service/Cargo.toml +++ b/crates/dig-node-service/Cargo.toml @@ -146,7 +146,7 @@ serde_json = "1" # reusable `logs` CLI verbs + the bundle-time redaction engine. Every DIG service binary # gets logging from HERE rather than hand-rolling a subscriber. Sourced from crates.io (no # git/path dep) per the ecosystem crates.io policy (#681). -dig-logging = "0.1" +dig-logging = "0.2" # The logging facade the shell emits through. dig-node-core already depends on `tracing`; # the service shell now emits its own bring-up/lifecycle events through it, captured by the # `dig-logging` subscriber installed at the serve entrypoints. diff --git a/crates/dig-node-service/src/control.rs b/crates/dig-node-service/src/control.rs index 33e37918..adca1d46 100644 --- a/crates/dig-node-service/src/control.rs +++ b/crates/dig-node-service/src/control.rs @@ -875,6 +875,14 @@ async fn status(ctx: &ControlCtx) -> Value { "sync": { "available": ctx.sync_available, }, + // #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()); +}