lib

Core libraries for Radroots
git clone https://radroots.dev/git/lib.git
Log | Files | Refs | README

commit bf25385982a2d8cf6f0f1d6471fb8221d7c16700
parent 8de30640731b40dc3135fdae781efc3a096047b9
Author: triesap <tyson@radroots.org>
Date:   Fri, 17 Jul 2026 21:53:40 +0000

log: harden structured service logging

- emit service and run identity on JSON events
- reject conflicting global initialization
- bound file size, retention, and writer memory
- expose explicit shutdown flushing

Diffstat:
MCargo.lock | 1+
Mcrates/log/Cargo.toml | 3+++
Mcrates/log/README | 10+++++++---
Mcrates/log/src/error.rs | 16++++++++++++----
Acrates/log/src/format.rs | 158+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
Mcrates/log/src/init.rs | 398++++++++++++++++++++++++++++++++++++++++++++++---------------------------------
Mcrates/log/src/lib.rs | 8++++++--
Mcrates/log/src/options.rs | 142+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++--------------------
Acrates/log/src/writer.rs | 243+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
Mcrates/net/src/logging.rs | 7++++---
Mcrates/runtime/src/tracing.rs | 3++-
11 files changed, 775 insertions(+), 214 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock @@ -4379,6 +4379,7 @@ name = "radroots_log" version = "0.1.0-alpha.2" dependencies = [ "chrono", + "serde_json", "thiserror 1.0.69", "tracing", "tracing-appender", diff --git a/crates/log/Cargo.toml b/crates/log/Cargo.toml @@ -15,8 +15,10 @@ readme = "README" [features] default = ["std"] std = [ + "tracing/std", "dep:chrono", "dep:thiserror", + "dep:serde_json", "dep:tracing-subscriber", "dep:tracing-appender", ] @@ -30,3 +32,4 @@ tracing-subscriber = { workspace = true, optional = true, features = [ "env-filter", ] } tracing-appender = { workspace = true, optional = true } +serde_json = { workspace = true, optional = true, features = ["std"] } diff --git a/crates/log/README b/crates/log/README @@ -8,9 +8,13 @@ primitives for the `radroots` core libraries. * basic `log_info`, `log_error`, and `log_debug` helpers available across builds; * typed error and result definitions for logging initialization paths; - * `std` initializers for default, stdout, and file-backed tracing setups; - * optional chrono- and tracing-subscriber-based formatting and rotation - support through feature gates. + * `std` initializers for default, structured stdout, and file-backed tracing; + * service, run, and environment identity on every structured JSON event; + * fail-closed initialization when a different global configuration is active; + * size-bounded files with deterministic retention and private file modes; + * explicit shutdown flushing for non-blocking file output; + * optional chrono-, serde-, and tracing-subscriber support through feature + gates. ## Copyright diff --git a/crates/log/src/error.rs b/crates/log/src/error.rs @@ -10,16 +10,24 @@ pub enum Error { Msg(String), #[cfg(feature = "std")] - #[error(transparent)] - Init(#[from] tracing_subscriber::util::TryInitError), + #[error("logging is already initialized with a different configuration")] + ConflictingInitialization, + + #[cfg(feature = "std")] + #[error("logging cannot be initialized after it has been shut down")] + InitializationAfterShutdown, + + #[cfg(feature = "std")] + #[error("logging cannot be shut down before it is initialized")] + ShutdownBeforeInitialization, #[cfg(feature = "std")] #[error(transparent)] - Io(#[from] std::io::Error), + Init(#[from] tracing_subscriber::util::TryInitError), #[cfg(feature = "std")] #[error(transparent)] - RollingInit(#[from] tracing_appender::rolling::InitError), + Io(#[from] std::io::Error), } pub type Result<T> = core::result::Result<T, Error>; diff --git a/crates/log/src/format.rs b/crates/log/src/format.rs @@ -0,0 +1,158 @@ +use std::fmt; + +use chrono::{SecondsFormat, Utc}; +use serde_json::{Map, Number, Value}; +use tracing::field::{Field, Visit}; +use tracing::{Event, Subscriber}; +use tracing_subscriber::fmt::format::Writer; +use tracing_subscriber::fmt::{FmtContext, FormatEvent, FormatFields}; +use tracing_subscriber::registry::LookupSpan; + +use crate::LogIdentity; + +#[derive(Debug, Clone)] +pub(crate) struct JsonEventFormatter { + identity: LogIdentity, +} + +impl JsonEventFormatter { + pub(crate) fn new(identity: LogIdentity) -> Self { + Self { identity } + } +} + +impl<S, N> FormatEvent<S, N> for JsonEventFormatter +where + S: Subscriber + for<'lookup> LookupSpan<'lookup>, + N: for<'writer> FormatFields<'writer> + 'static, +{ + fn format_event( + &self, + _context: &FmtContext<'_, S, N>, + mut writer: Writer<'_>, + event: &Event<'_>, + ) -> fmt::Result { + let metadata = event.metadata(); + let mut fields = Map::new(); + event.record(&mut JsonVisitor(&mut fields)); + let mut document = Map::new(); + document.insert( + "timestamp".to_owned(), + Value::String(Utc::now().to_rfc3339_opts(SecondsFormat::Millis, true)), + ); + document.insert( + "level".to_owned(), + Value::String(metadata.level().as_str().to_owned()), + ); + document.insert( + "target".to_owned(), + Value::String(metadata.target().to_owned()), + ); + document.insert( + "service".to_owned(), + Value::String(self.identity.service.clone()), + ); + document.insert( + "run_id".to_owned(), + Value::String(self.identity.run_id.clone()), + ); + document.insert( + "environment".to_owned(), + Value::String(self.identity.environment.clone()), + ); + document.insert("fields".to_owned(), Value::Object(fields)); + let encoded = serde_json::to_string(&Value::Object(document)).map_err(|_| fmt::Error)?; + writeln!(writer, "{encoded}") + } +} + +struct JsonVisitor<'map>(&'map mut Map<String, Value>); + +impl Visit for JsonVisitor<'_> { + fn record_f64(&mut self, field: &Field, value: f64) { + let value = Number::from_f64(value) + .map(Value::Number) + .unwrap_or_else(|| Value::String(format!("{value:?}"))); + self.0.insert(field.name().to_owned(), value); + } + + fn record_i64(&mut self, field: &Field, value: i64) { + self.0 + .insert(field.name().to_owned(), Value::Number(value.into())); + } + + fn record_u64(&mut self, field: &Field, value: u64) { + self.0 + .insert(field.name().to_owned(), Value::Number(value.into())); + } + + fn record_bool(&mut self, field: &Field, value: bool) { + self.0.insert(field.name().to_owned(), Value::Bool(value)); + } + + fn record_str(&mut self, field: &Field, value: &str) { + self.0 + .insert(field.name().to_owned(), Value::String(value.to_owned())); + } + + fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) { + self.0 + .insert(field.name().to_owned(), Value::String(value.to_string())); + } + + fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) { + self.0 + .insert(field.name().to_owned(), Value::String(format!("{value:?}"))); + } +} + +#[cfg(test)] +mod tests { + use super::JsonEventFormatter; + use crate::LogIdentity; + use std::io::{self, Write}; + use std::sync::{Arc, Mutex}; + use tracing::info; + + struct CapturedWriter(Arc<Mutex<Vec<u8>>>); + + impl Write for CapturedWriter { + fn write(&mut self, buffer: &[u8]) -> io::Result<usize> { + self.0 + .lock() + .map_err(|_| io::Error::other("capture lock is poisoned"))? + .extend_from_slice(buffer); + Ok(buffer.len()) + } + + fn flush(&mut self) -> io::Result<()> { + Ok(()) + } + } + + #[test] + fn json_events_include_identity_and_typed_fields() { + let output = Arc::new(Mutex::new(Vec::new())); + let capture = output.clone(); + let subscriber = tracing_subscriber::fmt() + .event_format(JsonEventFormatter::new(LogIdentity::new( + "global_relay", + "run-1", + "localhost", + ))) + .with_writer(move || CapturedWriter(capture.clone())) + .finish(); + tracing::subscriber::with_default(subscriber, || { + info!(ready = true, records = 3_u64, "service ready"); + }); + + let encoded = output.lock().expect("capture").clone(); + let document: serde_json::Value = serde_json::from_slice(&encoded).expect("JSON log"); + assert_eq!(document["service"], "global_relay"); + assert_eq!(document["run_id"], "run-1"); + assert_eq!(document["environment"], "localhost"); + assert_eq!(document["fields"]["ready"], true); + assert_eq!(document["fields"]["records"], 3); + assert!(document["fields"]["message"].is_string()); + } +} diff --git a/crates/log/src/init.rs b/crates/log/src/init.rs @@ -1,59 +1,211 @@ use std::fs; -use std::sync::OnceLock; +use std::path::{Component, Path}; +use std::sync::Mutex; use tracing::info; -use tracing_appender::rolling::{RollingFileAppender, Rotation}; +use tracing_appender::non_blocking::WorkerGuard; use tracing_subscriber::prelude::*; use tracing_subscriber::{EnvFilter, fmt}; -use crate::Result; -use crate::options::{LogFileLayout, LoggingOptions}; +use crate::format::JsonEventFormatter; +use crate::options::{LogFileLayout, LogFormat, LoggingOptions}; +use crate::writer::SizeRotatingWriter; +use crate::{Error, Result}; -static GUARD: OnceLock<tracing_appender::non_blocking::WorkerGuard> = OnceLock::new(); -static INIT: OnceLock<()> = OnceLock::new(); +struct InitializedLogging { + options: LoggingOptions, + _file_guard: Option<WorkerGuard>, +} + +enum LoggingState { + Uninitialized, + Active(Box<InitializedLogging>), + Shutdown, +} + +static LOGGING_STATE: Mutex<LoggingState> = Mutex::new(LoggingState::Uninitialized); pub fn init_logging(opts: LoggingOptions) -> Result<()> { - if INIT.get().is_some() { - return Ok(()); - } - - let writer = if let Some(dir) = &opts.dir { - fs::create_dir_all(dir)?; - let file_appender = build_file_appender(dir, &opts)?; - let (non_blocking, guard) = tracing_appender::non_blocking(file_appender); - let _ = GUARD.set(guard); - Some(non_blocking) - } else { - None + validate_options(&opts)?; + let mut state = LOGGING_STATE + .lock() + .map_err(|_| Error::Msg("logging initialization state is poisoned".to_owned()))?; + match &*state { + LoggingState::Active(active) => { + return initialization_decision(Some(&active.options), &opts).map(|_| ()); + } + LoggingState::Shutdown => return Err(Error::InitializationAfterShutdown), + LoggingState::Uninitialized => {} + } + + let (file_writer, file_guard) = build_file_writer(&opts)?; + let filter = resolve_env_filter(opts.default_level.as_deref()); + match opts.format { + LogFormat::Compact => { + let file_layer = file_writer.as_ref().map(|writer| { + fmt::layer() + .with_writer(writer.clone()) + .with_ansi(false) + .with_target(false) + }); + let stdout_layer = opts + .also_stdout() + .then(|| fmt::layer().with_writer(std::io::stdout).with_target(false)); + tracing_subscriber::registry() + .with(filter) + .with(file_layer) + .with(stdout_layer) + .try_init()?; + } + LogFormat::Json => { + let identity = opts + .identity + .as_ref() + .cloned() + .ok_or_else(|| Error::Msg("validated JSON identity is missing".to_owned()))?; + let file_layer = file_writer.as_ref().map(|writer| { + fmt::layer() + .event_format(JsonEventFormatter::new(identity.clone())) + .with_writer(writer.clone()) + .with_ansi(false) + }); + let stdout_layer = opts.also_stdout().then(|| { + fmt::layer() + .event_format(JsonEventFormatter::new(identity)) + .with_writer(std::io::stdout) + .with_ansi(false) + }); + tracing_subscriber::registry() + .with(filter) + .with(file_layer) + .with(stdout_layer) + .try_init()?; + } + } + let file_path = opts.resolved_current_log_file_path(); + *state = LoggingState::Active(Box::new(InitializedLogging { + options: opts.clone(), + _file_guard: file_guard, + })); + info!( + file_enabled = file_path.is_some(), + stdout_enabled = opts.also_stdout(), + "logging initialized" + ); + Ok(()) +} + +pub fn flush_and_shutdown() -> Result<()> { + let active = { + let mut state = LOGGING_STATE + .lock() + .map_err(|_| Error::Msg("logging initialization state is poisoned".to_owned()))?; + match std::mem::replace(&mut *state, LoggingState::Shutdown) { + LoggingState::Active(active) => Some(active), + LoggingState::Shutdown => None, + LoggingState::Uninitialized => { + *state = LoggingState::Uninitialized; + return Err(Error::ShutdownBeforeInitialization); + } + } }; + drop(active); + Ok(()) +} + +fn initialization_decision( + active: Option<&LoggingOptions>, + requested: &LoggingOptions, +) -> Result<bool> { + match active { + Some(active) if active == requested => Ok(true), + Some(_) => Err(Error::ConflictingInitialization), + None => Ok(false), + } +} - let env = resolve_env_filter(opts.default_level.as_deref()); - let fmt_layer_file = writer.as_ref().map(|w| { - fmt::layer() - .with_writer(w.clone()) - .with_ansi(false) - .with_target(false) - }); - let fmt_layer_stdout = if opts.also_stdout() { - Some(fmt::layer().with_writer(std::io::stdout).with_target(false)) - } else { - None +fn build_file_writer( + opts: &LoggingOptions, +) -> Result<( + Option<tracing_appender::non_blocking::NonBlocking>, + Option<WorkerGuard>, +)> { + let Some(dir) = &opts.dir else { + return Ok((None, None)); }; + fs::create_dir_all(dir)?; + let metadata = fs::symlink_metadata(dir)?; + if metadata.file_type().is_symlink() || !metadata.is_dir() { + return Err(Error::Msg( + "log directory is not a safe directory".to_owned(), + )); + } + let path = opts + .resolved_current_log_file_path() + .ok_or_else(|| Error::Msg("log file path could not be resolved".to_owned()))?; + let writer = SizeRotatingWriter::new(path, opts.rotation)?; + let (writer, guard) = tracing_appender::non_blocking::NonBlockingBuilder::default() + .buffered_lines_limit(8192) + .lossy(false) + .thread_name("radroots-log-writer") + .finish(writer); + Ok((Some(writer), Some(guard))) +} - let subscriber = tracing_subscriber::registry() - .with(env) - .with(fmt_layer_file) - .with(fmt_layer_stdout); +fn validate_options(opts: &LoggingOptions) -> Result<()> { + if opts.dir.is_none() && !opts.stdout { + return Err(Error::Msg( + "logging requires at least one configured output".to_owned(), + )); + } + if opts.file_name.is_empty() + || Path::new(&opts.file_name).components().count() != 1 + || !matches!( + Path::new(&opts.file_name).components().next(), + Some(Component::Normal(_)) + ) + { + return Err(Error::Msg( + "log file_name must be a safe basename".to_owned(), + )); + } + if opts.dir.is_some() && opts.file_layout != LogFileLayout::StableFileName { + return Err(Error::Msg( + "bounded file logging requires StableFileName layout".to_owned(), + )); + } + if opts.rotation.max_file_bytes == 0 || opts.rotation.retained_files == 0 { + return Err(Error::Msg( + "log rotation limits must be greater than zero".to_owned(), + )); + } + match (&opts.format, &opts.identity) { + (LogFormat::Json, Some(identity)) => { + validate_identity_value("service", &identity.service)?; + validate_identity_value("run_id", &identity.run_id)?; + validate_identity_value("environment", &identity.environment)?; + } + (LogFormat::Json, None) => { + return Err(Error::Msg( + "JSON logging requires service, run, and environment identity".to_owned(), + )); + } + (LogFormat::Compact, _) => {} + } + Ok(()) +} - subscriber.try_init()?; - let _ = INIT.set(()); - info!( - "logging initialized (file: {}, stdout: {})", - opts.resolved_current_log_file_path() - .map(|path| path.display().to_string()) - .unwrap_or_else(|| "<disabled>".into()), - opts.also_stdout() - ); +fn validate_identity_value(label: &str, value: &str) -> Result<()> { + if value.is_empty() + || value.len() > 128 + || !value + .bytes() + .all(|byte| byte.is_ascii_alphanumeric() || matches!(byte, b'_' | b'-' | b'.')) + { + return Err(Error::Msg(format!( + "log {label} identity must use 1-128 ASCII identifier characters" + ))); + } Ok(()) } @@ -65,147 +217,63 @@ fn resolve_env_filter(default_level: Option<&str>) -> EnvFilter { } pub fn init_stdout() -> Result<()> { - init_logging(LoggingOptions { - dir: None, - file_name: "radroots.log".into(), - stdout: true, - default_level: None, - file_layout: LogFileLayout::PrefixedDate, - }) -} - -fn build_file_appender( - dir: &std::path::Path, - opts: &LoggingOptions, -) -> Result<RollingFileAppender> { - let builder = RollingFileAppender::builder().rotation(Rotation::DAILY); - let builder = match opts.file_layout { - LogFileLayout::PrefixedDate => builder.filename_prefix(opts.file_name.as_str()), - LogFileLayout::DatedFileName => builder.filename_suffix(opts.file_name.as_str()), - }; - Ok(builder.build(dir)?) + init_logging(LoggingOptions::default()) } #[cfg(test)] mod tests { - use super::{build_file_appender, init_logging, resolve_env_filter}; - use crate::{LogFileLayout, LoggingOptions}; + use super::{initialization_decision, resolve_env_filter, validate_options}; + use crate::{LogFileLayout, LogFormat, LoggingOptions}; use std::path::PathBuf; - use std::time::{SystemTime, UNIX_EPOCH}; - use tracing_subscriber::fmt::MakeWriter; - - fn temp_log_dir(name: &str) -> PathBuf { - let nanos = SystemTime::now() - .duration_since(UNIX_EPOCH) - .expect("system time") - .as_nanos(); - let dir = std::env::temp_dir().join(format!("radroots_log-{name}-{nanos}")); - let _ = std::fs::remove_dir_all(&dir); - dir - } #[test] - fn prefixed_date_layout_keeps_existing_filename_shape() { - let dir = temp_log_dir("prefixed-date"); - let appender = build_file_appender( - dir.as_path(), - &LoggingOptions { - dir: Some(dir.clone()), - file_name: "myc.log".to_owned(), - stdout: false, - default_level: Some("info".to_owned()), - file_layout: LogFileLayout::PrefixedDate, - }, - ) - .expect("appender"); - - let writer = appender.make_writer(); - drop(writer); - - let names: Vec<String> = std::fs::read_dir(&dir) - .expect("read dir") - .map(|entry| { - entry - .expect("entry") - .file_name() - .to_string_lossy() - .to_string() - }) - .collect(); - assert_eq!(names.len(), 1); - assert!(names[0].starts_with("myc.log.")); - let _ = std::fs::remove_dir_all(&dir); - } + fn rejects_unbounded_or_identity_free_json_options() { + let mut options = LoggingOptions::json_service("service", "run-1", "test"); + options.identity = None; + assert!(validate_options(&options).is_err()); - #[test] - fn dated_file_name_layout_writes_date_named_log_files() { - let dir = temp_log_dir("dated-file-name"); - let appender = build_file_appender( - dir.as_path(), - &LoggingOptions { - dir: Some(dir.clone()), - file_name: "log".to_owned(), - stdout: false, - default_level: Some("info".to_owned()), - file_layout: LogFileLayout::DatedFileName, - }, - ) - .expect("appender"); - - let writer = appender.make_writer(); - drop(writer); - - let names: Vec<String> = std::fs::read_dir(&dir) - .expect("read dir") - .map(|entry| { - entry - .expect("entry") - .file_name() - .to_string_lossy() - .to_string() - }) - .collect(); - assert_eq!(names.len(), 1); - assert!(names[0].ends_with(".log")); - assert_eq!(names[0].matches('.').count(), 1); - let _ = std::fs::remove_dir_all(&dir); + options = LoggingOptions::json_service("service", "run-1", "test"); + options.rotation.retained_files = 0; + assert!(validate_options(&options).is_err()); + + options.rotation.retained_files = 1; + options.dir = Some(PathBuf::from("/tmp/logs")); + options.file_layout = LogFileLayout::PrefixedDate; + assert!(validate_options(&options).is_err()); } #[test] - fn init_paths_cover_layout_options() { - let dir = temp_log_dir("init-paths"); - std::fs::create_dir_all(&dir).expect("create dir"); - let invalid = dir.join("not-a-dir"); - std::fs::write(&invalid, "file").expect("write invalid path"); - let err_path = init_logging(LoggingOptions { - dir: Some(invalid), - file_name: "x.log".to_string(), - stdout: false, - default_level: None, - file_layout: LogFileLayout::PrefixedDate, - }); - assert!(err_path.is_err()); - - let first = build_file_appender( - &dir, - &LoggingOptions { - dir: Some(dir.clone()), - file_name: "service".to_string(), - stdout: false, - default_level: Some("info".to_string()), - file_layout: LogFileLayout::DatedFileName, - }, - ); - assert!(first.is_ok()); - let _ = std::fs::remove_dir_all(&dir); + fn rejects_unsafe_file_and_identity_values() { + let mut options = LoggingOptions::json_service("service", "run-1", "test"); + options.file_name = "../service.jsonl".to_owned(); + assert!(validate_options(&options).is_err()); + + options.file_name = "service.jsonl".to_owned(); + options.identity.as_mut().expect("identity").run_id = "contains space".to_owned(); + assert!(validate_options(&options).is_err()); } #[test] fn explicit_default_level_wins_over_ambient_rust_log() { - // Callers that pass an explicit service filter should not inherit the shell's RUST_LOG. let env = resolve_env_filter(Some("info,myc=info")); let rendered = env.to_string(); assert!(rendered.contains("info")); assert!(rendered.contains("myc=info")); } + + #[test] + fn compact_stdout_defaults_remain_valid() { + let options = LoggingOptions::default(); + assert_eq!(options.format, LogFormat::Compact); + assert!(validate_options(&options).is_ok()); + } + + #[test] + fn repeated_initialization_reuses_only_an_identical_configuration() { + let active = LoggingOptions::json_service("service", "run-1", "test"); + assert!(initialization_decision(Some(&active), &active).expect("reuse")); + let conflicting = LoggingOptions::json_service("service", "run-2", "test"); + assert!(initialization_decision(Some(&active), &conflicting).is_err()); + assert!(!initialization_decision(None, &active).expect("initialize")); + } } diff --git a/crates/log/src/lib.rs b/crates/log/src/lib.rs @@ -5,16 +5,20 @@ extern crate alloc; mod error; #[cfg(feature = "std")] +mod format; +#[cfg(feature = "std")] mod init; #[cfg(feature = "std")] mod options; +#[cfg(feature = "std")] +mod writer; pub use error::{Error, Result}; #[cfg(feature = "std")] -pub use init::{init_logging, init_stdout}; +pub use init::{flush_and_shutdown, init_logging, init_stdout}; #[cfg(feature = "std")] -pub use options::{LogFileLayout, LoggingOptions}; +pub use options::{LogFileLayout, LogFormat, LogIdentity, LogRotation, LoggingOptions}; use tracing::{debug, error, info}; diff --git a/crates/log/src/options.rs b/crates/log/src/options.rs @@ -1,19 +1,68 @@ -use chrono::Local; +use chrono::Utc; use std::path::PathBuf; +pub const DEFAULT_MAX_FILE_BYTES: u64 = 10 * 1024 * 1024; +pub const DEFAULT_RETAINED_FILES: usize = 5; + #[derive(Debug, Clone, Copy, PartialEq, Eq)] pub enum LogFileLayout { PrefixedDate, DatedFileName, + StableFileName, +} + +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum LogFormat { + Compact, + Json, +} + +#[derive(Debug, Clone, PartialEq, Eq)] +pub struct LogIdentity { + pub service: String, + pub run_id: String, + pub environment: String, +} + +impl LogIdentity { + pub fn new( + service: impl Into<String>, + run_id: impl Into<String>, + environment: impl Into<String>, + ) -> Self { + Self { + service: service.into(), + run_id: run_id.into(), + environment: environment.into(), + } + } } -#[derive(Debug, Clone)] +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub struct LogRotation { + pub max_file_bytes: u64, + pub retained_files: usize, +} + +impl Default for LogRotation { + fn default() -> Self { + Self { + max_file_bytes: DEFAULT_MAX_FILE_BYTES, + retained_files: DEFAULT_RETAINED_FILES, + } + } +} + +#[derive(Debug, Clone, PartialEq, Eq)] pub struct LoggingOptions { pub dir: Option<PathBuf>, pub file_name: String, pub stdout: bool, pub default_level: Option<String>, pub file_layout: LogFileLayout, + pub format: LogFormat, + pub identity: Option<LogIdentity>, + pub rotation: LogRotation, } impl LoggingOptions { @@ -21,16 +70,32 @@ impl LoggingOptions { self.stdout } + pub fn json_service( + service: impl Into<String>, + run_id: impl Into<String>, + environment: impl Into<String>, + ) -> Self { + let service = service.into(); + Self { + file_name: format!("{service}.jsonl"), + format: LogFormat::Json, + identity: Some(LogIdentity::new(service, run_id, environment)), + file_layout: LogFileLayout::StableFileName, + ..Self::default() + } + } + pub fn resolved_log_file_name_for_date(&self, date: &str) -> String { match self.file_layout { LogFileLayout::PrefixedDate => format!("{}.{}", self.file_name, date), LogFileLayout::DatedFileName => format!("{}.{}", date, self.file_name), + LogFileLayout::StableFileName => self.file_name.clone(), } } pub fn resolved_current_log_file_path(&self) -> Option<PathBuf> { let dir = self.dir.as_ref()?; - let date = Local::now().format("%Y-%m-%d").to_string(); + let date = Utc::now().format("%Y-%m-%d").to_string(); Some(dir.join(self.resolved_log_file_name_for_date(date.as_str()))) } } @@ -43,66 +108,71 @@ impl Default for LoggingOptions { stdout: true, default_level: None, file_layout: LogFileLayout::PrefixedDate, + format: LogFormat::Compact, + identity: None, + rotation: LogRotation::default(), } } } #[cfg(test)] mod tests { - use super::{LogFileLayout, LoggingOptions}; + use super::{LogFileLayout, LogFormat, LoggingOptions}; use std::path::PathBuf; #[test] - fn prefixed_date_layout_resolves_expected_file_name() { - let options = LoggingOptions { + fn layouts_resolve_expected_file_names() { + let mut options = LoggingOptions { dir: Some(PathBuf::from("/tmp/logs")), - file_name: "myc.log".to_owned(), - stdout: false, - default_level: None, - file_layout: LogFileLayout::PrefixedDate, + file_name: "service.log".to_owned(), + ..LoggingOptions::default() }; + assert_eq!( + options.resolved_log_file_name_for_date("2026-03-23"), + "service.log.2026-03-23" + ); + + options.file_layout = LogFileLayout::DatedFileName; + assert_eq!( + options.resolved_log_file_name_for_date("2026-03-23"), + "2026-03-23.service.log" + ); + options.file_layout = LogFileLayout::StableFileName; assert_eq!( options.resolved_log_file_name_for_date("2026-03-23"), - "myc.log.2026-03-23" + "service.log" ); } #[test] - fn dated_file_name_layout_resolves_expected_file_name() { - let options = LoggingOptions { - dir: Some(PathBuf::from("/tmp/logs")), - file_name: "log".to_owned(), - stdout: false, - default_level: None, - file_layout: LogFileLayout::DatedFileName, - }; - + fn json_service_has_bounded_production_defaults() { + let options = LoggingOptions::json_service("global_relay", "run-1", "localhost"); + assert_eq!(options.file_name, "global_relay.jsonl"); + assert_eq!(options.file_layout, LogFileLayout::StableFileName); + assert_eq!(options.format, LogFormat::Json); assert_eq!( - options.resolved_log_file_name_for_date("2026-03-23"), - "2026-03-23.log" + options + .identity + .as_ref() + .map(|identity| identity.service.as_str()), + Some("global_relay") ); + assert!(options.rotation.max_file_bytes > 0); + assert!(options.rotation.retained_files > 0); } #[test] fn current_log_file_path_joins_dir_and_layout_shape() { let options = LoggingOptions { dir: Some(PathBuf::from("/tmp/logs")), - file_name: "log".to_owned(), - stdout: false, - default_level: None, - file_layout: LogFileLayout::DatedFileName, + file_name: "service.jsonl".to_owned(), + file_layout: LogFileLayout::StableFileName, + ..LoggingOptions::default() }; - - let path = options - .resolved_current_log_file_path() - .expect("resolved path"); - - assert_eq!(path.parent(), Some(PathBuf::from("/tmp/logs").as_path())); - assert!( - path.file_name() - .and_then(|value| value.to_str()) - .is_some_and(|value| value.ends_with(".log")) + assert_eq!( + options.resolved_current_log_file_path(), + Some(PathBuf::from("/tmp/logs/service.jsonl")) ); } } diff --git a/crates/log/src/writer.rs b/crates/log/src/writer.rs @@ -0,0 +1,243 @@ +use std::fs::{self, File, OpenOptions}; +use std::io::{self, Write}; +use std::path::{Path, PathBuf}; + +use crate::options::LogRotation; + +pub(crate) struct SizeRotatingWriter { + path: PathBuf, + file: Option<File>, + bytes_written: u64, + policy: LogRotation, +} + +impl SizeRotatingWriter { + pub(crate) fn new(path: PathBuf, policy: LogRotation) -> io::Result<Self> { + validate_policy(policy)?; + reject_unsafe_target(&path)?; + let file = open_append(&path)?; + let bytes_written = file.metadata()?.len(); + let mut writer = Self { + path, + file: Some(file), + bytes_written, + policy, + }; + if writer.bytes_written >= writer.policy.max_file_bytes { + writer.rotate()?; + } + Ok(writer) + } + + fn rotate(&mut self) -> io::Result<()> { + if let Some(mut file) = self.file.take() { + file.flush()?; + file.sync_data()?; + } + if self.policy.retained_files == 1 { + remove_if_present(&self.path)?; + } else { + let oldest = rotated_path(&self.path, self.policy.retained_files - 1); + remove_if_present(&oldest)?; + for index in (2..self.policy.retained_files).rev() { + let source = rotated_path(&self.path, index - 1); + let target = rotated_path(&self.path, index); + rename_if_present(&source, &target)?; + } + rename_if_present(&self.path, &rotated_path(&self.path, 1))?; + } + self.file = Some(open_append(&self.path)?); + self.bytes_written = 0; + Ok(()) + } + + fn file_mut(&mut self) -> io::Result<&mut File> { + self.file + .as_mut() + .ok_or_else(|| io::Error::other("log file is unavailable")) + } +} + +impl Write for SizeRotatingWriter { + fn write(&mut self, buffer: &[u8]) -> io::Result<usize> { + let incoming = u64::try_from(buffer.len()) + .map_err(|_| io::Error::new(io::ErrorKind::InvalidInput, "log event is too large"))?; + if incoming > self.policy.max_file_bytes { + return Err(io::Error::new( + io::ErrorKind::InvalidData, + "log event exceeds the configured file limit", + )); + } + if self.bytes_written > 0 + && self.bytes_written.saturating_add(incoming) > self.policy.max_file_bytes + { + self.rotate()?; + } + let written = self.file_mut()?.write(buffer)?; + self.bytes_written = self + .bytes_written + .saturating_add(u64::try_from(written).unwrap_or(u64::MAX)); + Ok(written) + } + + fn flush(&mut self) -> io::Result<()> { + self.file_mut()?.flush() + } +} + +fn validate_policy(policy: LogRotation) -> io::Result<()> { + if policy.max_file_bytes == 0 { + return Err(io::Error::new( + io::ErrorKind::InvalidInput, + "max_file_bytes must be greater than zero", + )); + } + if policy.retained_files == 0 { + return Err(io::Error::new( + io::ErrorKind::InvalidInput, + "retained_files must be greater than zero", + )); + } + Ok(()) +} + +fn reject_unsafe_target(path: &Path) -> io::Result<()> { + match fs::symlink_metadata(path) { + Ok(metadata) if metadata.file_type().is_symlink() || !metadata.is_file() => Err( + io::Error::new(io::ErrorKind::InvalidInput, "log target is not a safe file"), + ), + Ok(_) => Ok(()), + Err(error) if error.kind() == io::ErrorKind::NotFound => Ok(()), + Err(error) => Err(error), + } +} + +fn open_append(path: &Path) -> io::Result<File> { + let mut options = OpenOptions::new(); + options.create(true).append(true); + #[cfg(unix)] + { + use std::os::unix::fs::{OpenOptionsExt, PermissionsExt}; + options.mode(0o600); + let file = options.open(path)?; + file.set_permissions(fs::Permissions::from_mode(0o600))?; + Ok(file) + } + #[cfg(not(unix))] + options.open(path) +} + +fn rotated_path(path: &Path, index: usize) -> PathBuf { + let mut value = path.as_os_str().to_owned(); + value.push(format!(".{index}")); + PathBuf::from(value) +} + +fn remove_if_present(path: &Path) -> io::Result<()> { + match fs::remove_file(path) { + Ok(()) => Ok(()), + Err(error) if error.kind() == io::ErrorKind::NotFound => Ok(()), + Err(error) => Err(error), + } +} + +fn rename_if_present(source: &Path, target: &Path) -> io::Result<()> { + match fs::rename(source, target) { + Ok(()) => Ok(()), + Err(error) if error.kind() == io::ErrorKind::NotFound => Ok(()), + Err(error) => Err(error), + } +} + +#[cfg(test)] +mod tests { + use super::{SizeRotatingWriter, rotated_path}; + use crate::LogRotation; + use std::io::Write; + use std::path::PathBuf; + use std::sync::atomic::{AtomicU64, Ordering}; + + static NEXT_DIRECTORY: AtomicU64 = AtomicU64::new(1); + + fn temp_log_path(name: &str) -> PathBuf { + let sequence = NEXT_DIRECTORY.fetch_add(1, Ordering::Relaxed); + let dir = std::env::temp_dir().join(format!( + "radroots-log-{name}-{}-{sequence}", + std::process::id() + )); + let _ = std::fs::remove_dir_all(&dir); + std::fs::create_dir_all(&dir).expect("create log test directory"); + dir.join("service.jsonl") + } + + #[test] + fn rotates_before_crossing_limit_and_bounds_retention() { + let path = temp_log_path("rotation"); + let mut writer = SizeRotatingWriter::new( + path.clone(), + LogRotation { + max_file_bytes: 5, + retained_files: 3, + }, + ) + .expect("writer"); + writer.write_all(b"1111").expect("first"); + writer.write_all(b"2222").expect("second"); + writer.write_all(b"3333").expect("third"); + writer.write_all(b"4444").expect("fourth"); + writer.flush().expect("flush"); + + assert_eq!(std::fs::read(&path).expect("current"), b"4444"); + assert_eq!( + std::fs::read(rotated_path(&path, 1)).expect("first retained"), + b"3333" + ); + assert_eq!( + std::fs::read(rotated_path(&path, 2)).expect("second retained"), + b"2222" + ); + assert!(!rotated_path(&path, 3).exists()); + std::fs::remove_dir_all(path.parent().expect("parent")).expect("cleanup"); + } + + #[test] + fn rejects_an_event_larger_than_the_file_limit() { + let path = temp_log_path("oversized"); + let mut writer = SizeRotatingWriter::new( + path.clone(), + LogRotation { + max_file_bytes: 4, + retained_files: 2, + }, + ) + .expect("writer"); + let error = writer.write_all(b"12345").expect_err("oversized event"); + assert_eq!(error.kind(), std::io::ErrorKind::InvalidData); + assert_eq!(std::fs::metadata(&path).expect("metadata").len(), 0); + std::fs::remove_dir_all(path.parent().expect("parent")).expect("cleanup"); + } + + #[cfg(unix)] + #[test] + fn rejects_symlink_targets_and_uses_private_file_mode() { + use std::os::unix::fs::{PermissionsExt, symlink}; + + let path = temp_log_path("symlink"); + let writer = SizeRotatingWriter::new(path.clone(), LogRotation::default()).expect("writer"); + drop(writer); + assert_eq!( + std::fs::metadata(&path) + .expect("metadata") + .permissions() + .mode() + & 0o777, + 0o600 + ); + std::fs::remove_file(&path).expect("remove target"); + let outside = path.with_file_name("outside"); + std::fs::write(&outside, b"").expect("outside"); + symlink(&outside, &path).expect("symlink"); + assert!(SizeRotatingWriter::new(path.clone(), LogRotation::default()).is_err()); + std::fs::remove_dir_all(path.parent().expect("parent")).expect("cleanup"); + } +} diff --git a/crates/net/src/logging.rs b/crates/net/src/logging.rs @@ -25,7 +25,8 @@ pub fn init_logging(opts: LoggingOptions) -> Result<()> { file_name: opts.file_name.clone(), stdout: opts.also_stdout, default_level: None, - file_layout: radroots_log::LogFileLayout::PrefixedDate, + file_layout: radroots_log::LogFileLayout::StableFileName, + ..radroots_log::LoggingOptions::default() }; match radroots_log::init_logging(log_opts) { Ok(()) => {} @@ -73,11 +74,11 @@ mod tests { }); assert!(valid_with_dir.is_ok()); - let valid_without_dir = init_logging(LoggingOptions { + let conflicting = init_logging(LoggingOptions { dir: None, file_name: "ok2.log".to_string(), also_stdout: true, }); - assert!(valid_without_dir.is_ok()); + assert!(matches!(conflicting, Err(NetError::LoggingInit("init")))); } } diff --git a/crates/runtime/src/tracing.rs b/crates/runtime/src/tracing.rs @@ -40,7 +40,8 @@ pub fn init_with_logs_dir( file_name: env_file.unwrap_or_else(default_log_file_name), stdout: true, default_level: resolve_default_level(env_level, default_level), - file_layout: LogFileLayout::PrefixedDate, + file_layout: LogFileLayout::StableFileName, + ..LoggingOptions::default() }; radroots_log::init_logging(opts)?; Ok(())