Add option to log to file (#814)

* Add environment variable for logging to file

Fixes #795

* Actually print log directory

* Reconfigure Vector to read OPA bundle builder logs without multilog

* Log to file as JSON

* Changelog

* Move tracing-appender dependency to workspace

* Reenable hourly rotation

* Move changelog entry to unreleased

* Generalize bundle builder Vector rule

* More changelog fixup

* Update crates/stackable-operator/src/logging/mod.rs

Co-authored-by: Siegfried Weber <[email protected]>

---------

Co-authored-by: Siegfried Weber <[email protected]>

Author: nightkr

Cargo.lock

@@ -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"

Cargo.toml

@@ -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

crates/stackable-operator/CHANGELOG.md

@@ -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]

crates/stackable-operator/Cargo.toml

@@ -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,18 +25,33 @@ 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,
         _ => EnvFilter::try_new(tracing::Level::INFO.to_string())
             .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"),
     }
 }
 

crates/stackable-operator/src/logging/mod.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<timestamp>[0-9-:.TZ]+)[ ]+(?P<level>\w+)[ ]+(?P<logger>.+):[ ]*(?P<message>.*)')
+      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: