Add CLI verbositiy logging

examples/unifiedlog_iterator/Cargo.toml

@@ -6,7 +6,6 @@ edition = "2024"
 # See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
 
 [dependencies]
-simplelog = "0.12.2"
 csv = "1.4.0"
 chrono = "0.4.44"
 log = "0.4.29"
@@ -15,3 +14,8 @@ macos-unifiedlogs = { path = "../../" }
 clap = { version = "4.6.1", features = ["derive"] }
 serde = { version = "1.0.228", features = ["derive"] }
 libc = "0.2.186"
+# JSON logging (term + optional file output)
+tracing = "0.1"
+tracing-subscriber = { version = "0.3", features = ["fmt", "json"] }
+tracing-log = "0.1"
+tracing-appender = "0.2"

examples/unifiedlog_iterator/src/logger.rs

@@ -0,0 +1,202 @@
+// Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at
+// http://www.apache.org/licenses/LICENSE-2.0
+// Unless required by applicable law or agreed to in writing, software distributed under the License
+// is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and limitations under the License.
+
+use chrono::Utc;
+use clap::ValueEnum;
+use serde_json::{Map, Value};
+use std::fmt;
+use std::fs::OpenOptions;
+use std::path::Path;
+use tracing::field::{Field, Visit};
+use tracing::{Event, Subscriber};
+use tracing_log::LogTracer;
+use tracing_subscriber::fmt as tracing_fmt;
+use tracing_subscriber::registry::LookupSpan;
+use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
+
+// Field visitor to convert event fields into a JSON map, while filtering out unwanted log crate fields.
+struct JsonFieldVisitor {
+    map: Map<String, Value>,
+}
+
+impl Visit for JsonFieldVisitor {
+    fn record_i64(&mut self, field: &Field, value: i64) {
+        self.insert(field, Value::from(value));
+    }
+
+    fn record_u64(&mut self, field: &Field, value: u64) {
+        self.insert(field, Value::from(value));
+    }
+
+    fn record_bool(&mut self, field: &Field, value: bool) {
+        self.insert(field, Value::from(value));
+    }
+
+    fn record_str(&mut self, field: &Field, value: &str) {
+        self.insert(field, Value::from(value));
+    }
+
+    fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
+        self.insert(field, Value::String(format!("{:?}", value)));
+    }
+}
+
+impl JsonFieldVisitor {
+    fn insert(&mut self, field: &Field, value: Value) {
+        let name = field.name();
+
+        // Filter unwanted log crate fields
+        if matches!(
+            name,
+            "log.target" | "log.module_path" | "log.file" | "log.line"
+        ) {
+            return;
+        }
+
+        self.map.insert(name.to_string(), value);
+    }
+}
+
+// Custom event formatter that output structured JSON  with event fields and span context.
+// Filters out unwanted log crate fields as per the JsonFieldVisitor and includes timestamp and log level in the output.
+struct FilteredJson;
+
+impl<S, N> tracing_fmt::FormatEvent<S, N> for FilteredJson
+where
+    S: Subscriber + for<'a> LookupSpan<'a>,
+    N: for<'a> tracing_fmt::FormatFields<'a> + 'static,
+{
+    fn format_event(
+        &self,
+        ctx: &tracing_fmt::FmtContext<'_, S, N>,
+        mut writer: tracing_fmt::format::Writer<'_>,
+        event: &Event<'_>,
+    ) -> fmt::Result {
+        let mut out = Map::new();
+        // ---- Base fields ----
+        out.insert("datetime".into(), Value::String(Utc::now().to_rfc3339()));
+        out.insert(
+            "level".into(),
+            Value::String(event.metadata().level().to_string()),
+        );
+        // ---- Event fields ----
+        let mut visitor = JsonFieldVisitor { map: Map::new() };
+        event.record(&mut visitor);
+
+        for (k, v) in visitor.map {
+            out.insert(k, v);
+        }
+
+        // ---- Span context ----
+        if let Some(scope) = ctx.event_scope() {
+            let mut spans = Vec::new();
+
+            for span in scope.from_root() {
+                let mut span_obj = Map::new();
+
+                span_obj.insert("name".into(), Value::String(span.name().to_string()));
+
+                // Capture span fields (if any)
+                let mut fields = Map::new();
+                if let Some(f) = span
+                    .extensions()
+                    .get::<tracing_subscriber::fmt::FormattedFields<N>>()
+                {
+                    fields.insert("fields".into(), Value::String(f.to_string()));
+                }
+
+                if !fields.is_empty() {
+                    span_obj.insert("fields".into(), Value::Object(fields));
+                }
+
+                spans.push(Value::Object(span_obj));
+            }
+
+            out.insert("spans".into(), Value::Array(spans));
+        }
+
+        writeln!(writer, "{}", serde_json::to_string(&out).unwrap())
+    }
+}
+
+/// Log level configuration for CLI.
+///
+/// This is separate from `log::LevelFilter` to get nice clap `ValueEnum` support.
+#[derive(ValueEnum, Clone, Debug)]
+pub enum VerbosityLevel {
+    Off,
+    Error,
+    Warn,
+    Info,
+    Debug,
+    Trace,
+}
+
+impl From<VerbosityLevel> for tracing_subscriber::filter::LevelFilter {
+    fn from(level: VerbosityLevel) -> Self {
+        match level {
+            VerbosityLevel::Off => tracing_subscriber::filter::LevelFilter::OFF,
+            VerbosityLevel::Error => tracing_subscriber::filter::LevelFilter::ERROR,
+            VerbosityLevel::Warn => tracing_subscriber::filter::LevelFilter::WARN,
+            VerbosityLevel::Info => tracing_subscriber::filter::LevelFilter::INFO,
+            VerbosityLevel::Debug => tracing_subscriber::filter::LevelFilter::DEBUG,
+            VerbosityLevel::Trace => tracing_subscriber::filter::LevelFilter::TRACE,
+        }
+    }
+}
+
+impl std::fmt::Display for VerbosityLevel {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        let s = match self {
+            VerbosityLevel::Off => "off",
+            VerbosityLevel::Error => "error",
+            VerbosityLevel::Warn => "warn",
+            VerbosityLevel::Info => "info",
+            VerbosityLevel::Debug => "debug",
+            VerbosityLevel::Trace => "trace",
+        };
+        write!(f, "{}", s)
+    }
+}
+
+/// Initialize tracing-based logging.
+///
+/// Always logs to stderr/terminal, and optionally also writes structured JSON to a file.
+pub fn init_logging(
+    log_file: Option<&Path>,
+    level: VerbosityLevel,
+) -> Result<Option<tracing_appender::non_blocking::WorkerGuard>, Box<dyn std::error::Error>> {
+    // Forward `log` records (log crate macros) into tracing
+    let _ = LogTracer::init();
+
+    let level_filter: tracing_subscriber::filter::LevelFilter = level.into();
+
+    let stdout_layer = tracing_fmt::layer().with_writer(std::io::stderr);
+
+    let (json_layer, guard) = if let Some(path) = log_file {
+        let file = OpenOptions::new()
+            .create(true)
+            .write(true)
+            .truncate(true)
+            .open(path)?;
+        let (non_blocking, guard) = tracing_appender::non_blocking(file);
+
+        let json_layer = tracing_fmt::layer()
+            .with_writer(non_blocking)
+            .event_format(FilteredJson);
+
+        (Some(json_layer), Some(guard))
+    } else {
+        (None, None)
+    };
+
+    let _ = tracing_subscriber::registry()
+        .with(level_filter)
+        .with(stdout_layer)
+        .with(json_layer)
+        .try_init();
+    Ok(guard)
+}

examples/unifiedlog_iterator/src/main.rs

@@ -6,14 +6,12 @@
 // See the License for the specific language governing permissions and limitations under the License.
 
 use chrono::{SecondsFormat, TimeZone, Utc};
-use log::{debug, error, info, warn, LevelFilter};
 use macos_unifiedlogs::filesystem::{LiveSystemProvider, LogarchiveProvider};
 use macos_unifiedlogs::iterator::UnifiedLogIterator;
 use macos_unifiedlogs::parser::{build_log, collect_timesync, parse_log};
 use macos_unifiedlogs::timesync::TimesyncBoot;
 use macos_unifiedlogs::traits::FileProvider;
 use macos_unifiedlogs::unified_log::{LogData, UnifiedLogData};
-use simplelog::{ColorChoice, Config, TermLogger, TerminalMode};
 use std::collections::HashMap;
 use std::error::Error;
 use std::fmt::Display;
@@ -22,8 +20,9 @@ use std::io::{Read, Write};
 use std::path::{Path, PathBuf};
 use std::sync::atomic::{AtomicBool, Ordering};
 use std::sync::{Arc, Mutex};
+use tracing::{debug, error, info, warn};
 
-use clap::{builder, Parser, ValueEnum};
+use clap::{Parser, ValueEnum, builder};
 use csv::Writer;
 
 /// Global atomic flag to track SIGINT signal
@@ -35,8 +34,10 @@ extern "C" fn handle_sigint(_sig: libc::c_int) {
 }
 
 use crate::bookmark::Bookmark;
+use crate::logger::{VerbosityLevel, init_logging};
 
 mod bookmark;
+mod logger;
 
 struct IterationContext {
     missing_data: Vec<UnifiedLogData>,
@@ -89,7 +90,9 @@ fn filter_and_update_bookmark(
         .collect();
 
     // Update bookmark with max timestamp seen (not just filtered) to avoid re-scanning
-    if let Some(max_time) = max_seen_timestamp && let Ok(mut book) = bookmark.lock() {
+    if let Some(max_time) = max_seen_timestamp
+        && let Ok(mut book) = bookmark.lock()
+    {
         book.update_timestamp(max_time);
     }
 
@@ -152,6 +155,14 @@ struct Args {
     #[clap(short, long, default_value = "false")]
     append: bool,
 
+    /// Log verbosity level (off, error, warn, info, debug, trace)
+    #[clap(short, long, default_value_t = VerbosityLevel::Warn)]
+    verbosity_level: VerbosityLevel,
+
+    /// Path to JSONL file to write internal logs to
+    #[clap(long = "log-file", value_name = "FILE")]
+    log_file_path: Option<PathBuf>,
+
     /// Resume from last position using bookmark
     #[clap(long, default_value = "false")]
     resume: bool,
@@ -193,16 +204,17 @@ impl From<Format> for &str {
 }
 
 fn main() {
-    TermLogger::init(
-        LevelFilter::Warn,
-        Config::default(),
-        TerminalMode::Stderr,
-        ColorChoice::Auto,
-    )
-    .expect("Failed to initialize simple logger");
+    let args = Args::parse();
+
+    let log_file_opt = args.log_file_path.as_deref();
+
+    let _log_guard = init_logging(log_file_opt, args.verbosity_level).unwrap_or_else(|e| {
+        eprintln!("Failed to initialize logger: {e}");
+        std::process::exit(1);
+    });
+
     info!("Starting Unified Log parser...");
 
-    let args = Args::parse();
     let output_format = args.format;
 
     // Determine source ID for bookmark
@@ -296,7 +308,9 @@ fn main() {
                 }
             }
             Err(_) => {
-                eprintln!("Warning: Could not acquire bookmark lock (mutex poisoned). Bookmark not saved.");
+                eprintln!(
+                    "Warning: Could not acquire bookmark lock (mutex poisoned). Bookmark not saved."
+                );
             }
         }
         std::process::exit(0);
@@ -336,9 +350,11 @@ fn parse_single_file(
             message: e.to_string(),
         })
         .and_then(|mut reader| {
-            parse_log(&mut reader, path.to_str().unwrap_or_default()).map_err(|err| RuntimeError::FileParse {
-                path: path.to_string_lossy().to_string(),
-                message: format!("{err}"),
+            parse_log(&mut reader, path.to_str().unwrap_or_default()).map_err(|err| {
+                RuntimeError::FileParse {
+                    path: path.to_string_lossy().to_string(),
+                    message: format!("{err}"),
+                }
             })
         })
         .map(|ref log| {
@@ -379,7 +395,9 @@ fn parse_single_file(
         }
 
         // Update bookmark with max timestamp seen (not just written) to avoid re-scanning
-        if max_seen_timestamp > 0.0 && let Ok(mut bookmark) = bookmark.lock() {
+        if max_seen_timestamp > 0.0
+            && let Ok(mut bookmark) = bookmark.lock()
+        {
             bookmark.update_timestamp(max_seen_timestamp);
         }
     } else {
@@ -466,10 +484,7 @@ fn parse_trace_file(
         },
     };
     let resume_timestamp = if resume {
-        bookmark
-            .lock()
-            .map(|b| b.last_timestamp)
-            .unwrap_or(0.0)
+        bookmark.lock().map(|b| b.last_timestamp).unwrap_or(0.0)
     } else {
         0.0
     };