diff --git a/Cargo.lock b/Cargo.lock index 51a69be25..f10684eac 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -591,6 +591,15 @@ dependencies = [ "cfg-if", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.13" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "33480d6946193aa8033910124896ca395333cae7e2d1113d1fef6c3272217df2" +dependencies = [ + "crossbeam-utils", +] + [[package]] name = "crossbeam-utils" version = "0.8.20" @@ -2921,6 +2930,7 @@ dependencies = [ "time", "tokio", "tracing", + "tracing-appender", "tracing-opentelemetry", "tracing-subscriber", "url", @@ -3142,10 +3152,12 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "5dfd88e563464686c916c7e46e623e520ddc6d79fa6641390f2e3fa86e83e885" dependencies = [ "deranged", + "itoa", "num-conv", "powerfmt", "serde", "time-core", + "time-macros", ] [[package]] @@ -3154,6 +3166,16 @@ version = "0.1.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "ef927ca75afb808a4d64dd374f00a2adf8d0fcff8e7b184af886c3c87ec4a3f3" +[[package]] +name = "time-macros" +version = "0.2.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3f252a68540fde3a3877aeea552b832b40ab9a69e318efd078774a01ddee1ccf" +dependencies = [ + "num-conv", + "time-core", +] + [[package]] name = "tinyvec" version = "1.8.0" @@ -3373,6 +3395,18 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-appender" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3566e8ce28cc0a3fe42519fc80e6b4c943cc4c8cef275620eb8dac2d3d4e06cf" +dependencies = [ + "crossbeam-channel", + "thiserror", + "time", + "tracing-subscriber", +] + [[package]] name = "tracing-attributes" version = "0.1.27" @@ -3423,6 +3457,16 @@ dependencies = [ "web-time", ] +[[package]] +name = "tracing-serde" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" +dependencies = [ + "serde", + "tracing-core", +] + [[package]] name = "tracing-subscriber" version = "0.3.18" @@ -3433,12 +3477,15 @@ dependencies = [ "nu-ansi-term", "once_cell", "regex", + "serde", + "serde_json", "sharded-slab", "smallvec", "thread_local", "tracing", "tracing-core", "tracing-log", + "tracing-serde", ] [[package]] diff --git a/Cargo.toml b/Cargo.toml index fa59b05fe..34dac5691 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -68,8 +68,9 @@ tokio-test = "0.4.4" tower = "0.4.13" tower-http = { version = "0.5.2", features = ["trace"] } tracing = "0.1.40" +tracing-appender = "0.2.3" tracing-opentelemetry = "0.24.0" -tracing-subscriber = { version = "0.3.18", features = ["env-filter"] } +tracing-subscriber = { version = "0.3.18", features = ["env-filter", "json"] } url = { version = "2.5.2", features = ["serde"] } x509-cert = { version = "0.2.5", features = ["builder"] } zeroize = "1.8.1" diff --git a/crates/stackable-operator/CHANGELOG.md b/crates/stackable-operator/CHANGELOG.md index 1e86ad945..33eefab24 100644 --- a/crates/stackable-operator/CHANGELOG.md +++ b/crates/stackable-operator/CHANGELOG.md @@ -4,6 +4,16 @@ All notable changes to this project will be documented in this file. ## [Unreleased] +### Added + +- Added support for logging to files ([#814]). + +### Changed + +- Changed OPA Bundle Builder Vector config to read from the new log-to-file setup ([#814]). + +[#814]: https://github.com/stackabletech/operator-rs/pull/814 + ## [0.70.0] - 2024-07-10 ### Added diff --git a/crates/stackable-operator/Cargo.toml b/crates/stackable-operator/Cargo.toml index f7bbd60dd..c391896a6 100644 --- a/crates/stackable-operator/Cargo.toml +++ b/crates/stackable-operator/Cargo.toml @@ -38,9 +38,10 @@ snafu.workspace = true strum.workspace = true time = { workspace = true, optional = true } tokio.workspace = true +tracing.workspace = true +tracing-appender.workspace = true tracing-opentelemetry.workspace = true tracing-subscriber.workspace = true -tracing.workspace = true url.workspace = true [dev-dependencies] diff --git a/crates/stackable-operator/src/logging/mod.rs b/crates/stackable-operator/src/logging/mod.rs index 00296b8fd..e9c5eb5b4 100644 --- a/crates/stackable-operator/src/logging/mod.rs +++ b/crates/stackable-operator/src/logging/mod.rs @@ -1,4 +1,7 @@ +use std::path::PathBuf; + use tracing; +use tracing_appender::rolling::{RollingFileAppender, Rotation}; use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, EnvFilter, Registry}; pub mod controller; @@ -22,6 +25,9 @@ impl Default for TracingTarget { /// We force users to provide a variable name so it can be different per product. /// We encourage it to be the product name plus `_LOG`, e.g. `FOOBAR_OPERATOR_LOG`. /// If no environment variable is provided, the maximum log level is set to INFO. +/// +/// Log output can be copied to a file by setting `{env}_DIRECTORY` (e.g. `FOOBAR_OPERATOR_DIRECTORY`) +/// to a directory path. This file will be rotated regularly. pub fn initialize_logging(env: &str, app_name: &str, tracing_target: TracingTarget) { let filter = match EnvFilter::try_from_env(env) { Ok(env_filter) => env_filter, @@ -29,11 +35,23 @@ pub fn initialize_logging(env: &str, app_name: &str, tracing_target: TracingTarg .expect("Failed to initialize default tracing level to INFO"), }; - let fmt = tracing_subscriber::fmt::layer(); - let registry = Registry::default().with(filter).with(fmt); + let terminal_fmt = tracing_subscriber::fmt::layer(); + + let file_appender_directory = std::env::var_os(format!("{env}_DIRECTORY")).map(PathBuf::from); + let file_fmt = file_appender_directory.as_deref().map(|log_dir| { + let file_appender = RollingFileAppender::builder() + .rotation(Rotation::HOURLY) + .filename_prefix(app_name.to_string()) + .filename_suffix("tracing-rs.json") + .max_log_files(6) + .build(log_dir) + .expect("failed to initialize rolling file appender"); + tracing_subscriber::fmt::layer() + .json() + .with_writer(file_appender) + }); - match tracing_target { - TracingTarget::None => registry.init(), + let jaeger = match tracing_target { TracingTarget::Jaeger => { // FIXME (@Techassi): Replace with opentelemetry_otlp #[allow(deprecated)] @@ -42,8 +60,22 @@ pub fn initialize_logging(env: &str, app_name: &str, tracing_target: TracingTarg .install_batch(opentelemetry_sdk::runtime::Tokio) .expect("Failed to initialize Jaeger pipeline"); let opentelemetry = tracing_opentelemetry::layer().with_tracer(jaeger); - registry.with(opentelemetry).init(); + Some(opentelemetry) } + TracingTarget::None => None, + }; + + Registry::default() + .with(filter) + .with(terminal_fmt) + .with(file_fmt) + .with(jaeger) + .init(); + + // need to delay logging until after tracing is initialized + match file_appender_directory { + Some(dir) => tracing::info!(directory = %dir.display(), "file logging enabled"), + None => tracing::debug!("file logging disabled, because no log directory set"), } } diff --git a/crates/stackable-operator/src/product_logging/framework.rs b/crates/stackable-operator/src/product_logging/framework.rs index a4afcd52b..72d699e72 100644 --- a/crates/stackable-operator/src/product_logging/framework.rs +++ b/crates/stackable-operator/src/product_logging/framework.rs @@ -752,11 +752,10 @@ sources: include: - {STACKABLE_LOG_DIR}/*/*.airlift.json - files_opa_bundle_builder: + files_tracing_rs: type: file include: - - {STACKABLE_LOG_DIR}/bundle-builder/current - - {STACKABLE_LOG_DIR}/bundle-builder/test + - {STACKABLE_LOG_DIR}/*/*.tracing-rs.json files_opa_json: type: file @@ -765,9 +764,9 @@ sources: - {STACKABLE_LOG_DIR}/opa/test transforms: - processed_files_opa_bundle_builder: + processed_files_tracing_rs: inputs: - - files_opa_bundle_builder + - files_tracing_rs type: remap source: | raw_message = string!(.message) @@ -778,33 +777,58 @@ transforms: .message = "" .errors = [] - event, err = parse_regex(strip_whitespace(strip_ansi_escape_codes(raw_message)), r'(?P[0-9-:.TZ]+)[ ]+(?P\w+)[ ]+(?P.+):[ ]*(?P.*)') + parsed_event, err = parse_json(raw_message) if err != null {{ - error = "Log event not parsable: " + err + error = "JSON not parsable: " + err + .errors = push(.errors, error) + log(error, level: "warn") + .message = raw_message + }} else if !is_object(parsed_event) {{ + error = "Parsed event is not a JSON object." .errors = push(.errors, error) log(error, level: "warn") .message = raw_message }} else {{ - parsed_timestamp, err = parse_timestamp(event.timestamp, "%Y-%m-%dT%H:%M:%S.%6fZ") + event = object!(parsed_event) + + timestamp_string, err = string(event.timestamp) if err == null {{ - .timestamp = parsed_timestamp - }} else {{ - .errors = push(.errors, "Timestamp not parsable, using current time instead: " + err) + parsed_timestamp, err = parse_timestamp(timestamp_string, "%+") + if err == null {{ + .timestamp = parsed_timestamp + }} else {{ + .errors = push(.errors, "Timestamp not parsable, trying current time instead: " + err) + }} }} - level = string!(event.level) - if includes(["TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL"], level) {{ - .level = level - }} else {{ + .logger, err = string(event.target) + if err != null || is_empty(.logger) {{ + .errors = push(.errors, "Logger/target not found.") + }} + + level, err = string(event.level) + if err != null {{ + .errors = push(.errors, "Level not found, using \"" + .level + "\" instead.") + }} else if !includes(["TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL"], upcase(level)) {{ .errors = push(.errors, "Level \"" + level + "\" unknown, using \"" + .level + "\" instead.") + }} else {{ + .level = upcase(level) }} - .logger = string!(event.logger) + fields, err = object(event.fields) + if err != null {{ + .errors = push(.errors, "Fields are not an object.") + }} - .message = string!(event.message) - if is_empty(.message) {{ + .message, err = string(fields.message) + if err != null || is_empty(.message) {{ .errors = push(.errors, "Message not found.") }} + + del(fields.message) + + other_fields = encode_key_value(fields, field_delimiter: "\n") + .message = join!(compact([.message, other_fields]), "\n\n") }} processed_files_opa_json: