forc_tracing/

lib.rs

//! Utility items shared between forc crates.

#[cfg(feature = "telemetry")]
pub mod telemetry;

use ansiterm::Colour;
use std::str;
use std::sync::atomic::{AtomicBool, Ordering};
use std::{env, io};
use tracing::{Level, Metadata};
pub use tracing_subscriber::{
    self,
    filter::{filter_fn, EnvFilter, FilterExt, LevelFilter},
    fmt::{format::FmtSpan, MakeWriter},
    layer::{Layer, SubscriberExt},
    registry,
    util::SubscriberInitExt,
    Layer as LayerTrait,
};

#[cfg(feature = "telemetry")]
use fuel_telemetry::WorkerGuard;

const ACTION_COLUMN_WIDTH: usize = 12;

/// Filter to hide telemetry spans from regular application logs
#[derive(Clone)]
pub struct HideTelemetryFilter;

impl<S> tracing_subscriber::layer::Filter<S> for HideTelemetryFilter {
    fn enabled(
        &self,
        meta: &Metadata<'_>,
        _cx: &tracing_subscriber::layer::Context<'_, S>,
    ) -> bool {
        // Hide spans that are created by telemetry macros
        !meta.target().starts_with("fuel_telemetry")
    }
}

// Global flag to track if JSON output mode is active
static JSON_MODE_ACTIVE: AtomicBool = AtomicBool::new(false);

// Global flag to track if telemetry is disabled
static TELEMETRY_DISABLED: AtomicBool = AtomicBool::new(false);

/// Check if telemetry is disabled
pub fn is_telemetry_disabled() -> bool {
    TELEMETRY_DISABLED.load(Ordering::SeqCst)
}

/// Check if JSON mode is currently active
fn is_json_mode_active() -> bool {
    JSON_MODE_ACTIVE.load(Ordering::SeqCst)
}

/// Returns the indentation for the action prefix relative to [ACTION_COLUMN_WIDTH].
fn get_action_indentation(action: &str) -> String {
    if action.len() < ACTION_COLUMN_WIDTH {
        " ".repeat(ACTION_COLUMN_WIDTH - action.len())
    } else {
        String::new()
    }
}

enum TextStyle {
    Plain,
    Bold,
    Label(String),
    Action(String),
}

enum LogLevel {
    #[allow(dead_code)]
    Trace,
    Debug,
    Info,
    Warn,
    Error,
}

/// Common function to handle all kinds of output with color and styling
fn print_message(text: &str, color: Colour, style: TextStyle, level: LogLevel) {
    let log_msg = match (is_json_mode_active(), style) {
        // JSON mode formatting (no colors)
        (true, TextStyle::Plain | TextStyle::Bold) => text.to_string(),
        (true, TextStyle::Label(label)) => format!("{label}: {text}"),
        (true, TextStyle::Action(action)) => {
            let indent = get_action_indentation(&action);
            format!("{indent}{action} {text}")
        }

        // Normal mode formatting (with colors)
        (false, TextStyle::Plain) => format!("{}", color.paint(text)),
        (false, TextStyle::Bold) => format!("{}", color.bold().paint(text)),
        (false, TextStyle::Label(label)) => format!("{} {}", color.bold().paint(label), text),
        (false, TextStyle::Action(action)) => {
            let indent = get_action_indentation(&action);
            format!("{}{} {}", indent, color.bold().paint(action), text)
        }
    };

    match level {
        LogLevel::Trace => tracing::trace!("{}", log_msg),
        LogLevel::Debug => tracing::debug!("{}", log_msg),
        LogLevel::Info => tracing::info!("{}", log_msg),
        LogLevel::Warn => tracing::warn!("{}", log_msg),
        LogLevel::Error => tracing::error!("{}", log_msg),
    }
}

/// Prints a label with a green-bold label prefix like "Compiling ".
pub fn println_label_green(label: &str, txt: &str) {
    print_message(
        txt,
        Colour::Green,
        TextStyle::Label(label.to_string()),
        LogLevel::Info,
    );
}

/// Prints an action message with a green-bold prefix like "   Compiling ".
pub fn println_action_green(action: &str, txt: &str) {
    println_action(action, txt, Colour::Green);
}

/// Prints a label with a red-bold label prefix like "error: ".
pub fn println_label_red(label: &str, txt: &str) {
    print_message(
        txt,
        Colour::Red,
        TextStyle::Label(label.to_string()),
        LogLevel::Info,
    );
}

/// Prints an action message with a red-bold prefix like "   Removing ".
pub fn println_action_red(action: &str, txt: &str) {
    println_action(action, txt, Colour::Red);
}

/// Prints an action message with a yellow-bold prefix like "   Finished ".
pub fn println_action_yellow(action: &str, txt: &str) {
    println_action(action, txt, Colour::Yellow);
}

fn println_action(action: &str, txt: &str, color: Colour) {
    print_message(
        txt,
        color,
        TextStyle::Action(action.to_string()),
        LogLevel::Info,
    );
}

/// Prints a warning message to stdout with the yellow prefix "warning: ".
pub fn println_warning(txt: &str) {
    print_message(
        txt,
        Colour::Yellow,
        TextStyle::Label("warning:".to_string()),
        LogLevel::Warn,
    );
}

/// Prints a warning message to stdout with the yellow prefix "warning: " only in verbose mode.
pub fn println_warning_verbose(txt: &str) {
    print_message(
        txt,
        Colour::Yellow,
        TextStyle::Label("warning:".to_string()),
        LogLevel::Debug,
    );
}

/// Prints a warning message to stderr with the red prefix "error: ".
pub fn println_error(txt: &str) {
    print_message(
        txt,
        Colour::Red,
        TextStyle::Label("error:".to_string()),
        LogLevel::Error,
    );
}

pub fn println_red(txt: &str) {
    print_message(txt, Colour::Red, TextStyle::Plain, LogLevel::Info);
}

pub fn println_green(txt: &str) {
    print_message(txt, Colour::Green, TextStyle::Plain, LogLevel::Info);
}

pub fn println_yellow(txt: &str) {
    print_message(txt, Colour::Yellow, TextStyle::Plain, LogLevel::Info);
}

pub fn println_green_bold(txt: &str) {
    print_message(txt, Colour::Green, TextStyle::Bold, LogLevel::Info);
}

pub fn println_yellow_bold(txt: &str) {
    print_message(txt, Colour::Yellow, TextStyle::Bold, LogLevel::Info);
}

pub fn println_yellow_err(txt: &str) {
    print_message(txt, Colour::Yellow, TextStyle::Plain, LogLevel::Error);
}

pub fn println_red_err(txt: &str) {
    print_message(txt, Colour::Red, TextStyle::Plain, LogLevel::Error);
}

const LOG_FILTER: &str = "RUST_LOG";

#[derive(PartialEq, Eq, Clone)]
pub enum TracingWriter {
    /// Write ERROR and WARN to stderr and everything else to stdout.
    Stdio,
    /// Write everything to stdout.
    Stdout,
    /// Write everything to stderr.
    Stderr,
    /// Write everything as structured JSON to stdout.
    Json,
}

#[derive(Default, Clone)]
pub struct TracingSubscriberOptions {
    pub verbosity: Option<u8>,
    pub silent: Option<bool>,
    pub log_level: Option<LevelFilter>,
    pub writer_mode: Option<TracingWriter>,
    pub regex_filter: Option<String>,
    pub disable_telemetry: Option<bool>,
}

// This allows us to write ERROR and WARN level logs to stderr and everything else to stdout.
// https://docs.rs/tracing-subscriber/latest/tracing_subscriber/fmt/trait.MakeWriter.html
impl<'a> MakeWriter<'a> for TracingWriter {
    type Writer = Box<dyn io::Write>;

    fn make_writer(&'a self) -> Self::Writer {
        match self {
            TracingWriter::Stderr => Box::new(io::stderr()),
            // We must have an implementation of `make_writer` that makes
            // a "default" writer without any configuring metadata. Let's
            // just return stdout in that case.
            _ => Box::new(io::stdout()),
        }
    }

    fn make_writer_for(&'a self, meta: &Metadata<'_>) -> Self::Writer {
        // Here's where we can implement our special behavior. We'll
        // check if the metadata's verbosity level is WARN or ERROR,
        // and return stderr in that case.
        if *self == TracingWriter::Stderr
            || (*self == TracingWriter::Stdio && meta.level() <= &Level::WARN)
        {
            return Box::new(io::stderr());
        }

        // Otherwise, we'll return stdout.
        Box::new(io::stdout())
    }
}

/// A subscriber built using tracing_subscriber::registry with optional telemetry layer.
///
/// `RUST_LOG` environment variable can be used to set different minimum level for the subscriber, default is `INFO`.
///
/// # Telemetry
///
/// When the `telemetry` feature is enabled (default), telemetry data is sent to InfluxDB.
/// This can be disabled via:
/// - The `--disable-telemetry` CLI flag
/// - The `FORC_DISABLE_TELEMETRY` environment variable
/// - Setting `disable_telemetry: Some(true)` in options
///
/// # Return Value
///
/// Returns `Ok(Some(WorkerGuard))` when telemetry is enabled, which must be kept alive
/// for the duration of the program to ensure telemetry is properly collected.
/// Returns `Ok(None)` when telemetry is disabled.
///
/// # Example
///
/// ```ignore
/// let _guard = init_tracing_subscriber(Default::default())?;
/// // Your program code here
/// // The guard is dropped when main() exits, ensuring proper cleanup
/// ```
pub fn init_tracing_subscriber(
    options: TracingSubscriberOptions,
) -> anyhow::Result<Option<WorkerGuard>> {
    let level_filter = options
        .log_level
        .or_else(|| {
            options.verbosity.and_then(|verbosity| match verbosity {
                1 => Some(LevelFilter::DEBUG), // matches --verbose or -v
                2 => Some(LevelFilter::TRACE), // matches -vv
                _ => None,
            })
        })
        .or_else(|| {
            options
                .silent
                .and_then(|silent| silent.then_some(LevelFilter::OFF))
        });

    let writer_mode = match options.writer_mode {
        Some(TracingWriter::Json) => {
            JSON_MODE_ACTIVE.store(true, Ordering::SeqCst);
            TracingWriter::Json
        }
        Some(TracingWriter::Stderr) => TracingWriter::Stderr,
        Some(TracingWriter::Stdout) => TracingWriter::Stdout,
        _ => TracingWriter::Stdio,
    };

    // Set the global telemetry disabled flag
    let disabled = is_telemetry_disabled_from_options(&options);
    TELEMETRY_DISABLED.store(disabled, Ordering::SeqCst);

    // Build the fmt layer with proper filtering
    let hide_telemetry_filter = HideTelemetryFilter;
    let regex_filter = options.regex_filter.clone();

    macro_rules! init_registry {
        ($registry:expr) => {{
            let env_filter = match env::var_os(LOG_FILTER) {
                Some(_) => EnvFilter::try_from_default_env().expect("Invalid `RUST_LOG` provided"),
                None => EnvFilter::new("info"),
            };

            let regex_filter_fn = filter_fn(move |metadata| {
                if let Some(ref regex_filter) = regex_filter {
                    let regex = regex::Regex::new(regex_filter).unwrap();
                    regex.is_match(metadata.target())
                } else {
                    true
                }
            });

            let composite_filter = env_filter.and(hide_telemetry_filter).and(regex_filter_fn);

            // Only apply level_filter if user explicitly set it via CLI flags
            if is_json_mode_active() {
                let layer = tracing_subscriber::fmt::layer()
                    .json()
                    .with_ansi(true)
                    .with_level(false)
                    .with_file(false)
                    .with_line_number(false)
                    .without_time()
                    .with_target(false)
                    .with_writer(writer_mode)
                    .with_filter(composite_filter);

                match level_filter {
                    Some(filter) => $registry.with(layer.with_filter(filter)).init(),
                    None => $registry.with(layer).init(),
                }
            } else {
                let layer = tracing_subscriber::fmt::layer()
                    .with_ansi(true)
                    .with_level(false)
                    .with_file(false)
                    .with_line_number(false)
                    .without_time()
                    .with_target(false)
                    .with_writer(writer_mode)
                    .with_filter(composite_filter);

                match level_filter {
                    Some(filter) => $registry.with(layer.with_filter(filter)).init(),
                    None => $registry.with(layer).init(),
                }
            }
        }};
    }

    // Initialize registry with explicit layer handling
    #[cfg(feature = "telemetry")]
    {
        if !disabled {
            if let Ok((telemetry_layer, guard)) = fuel_telemetry::new_with_watchers!() {
                init_registry!(registry().with(telemetry_layer));
                return Ok(Some(guard));
            }
        }
    }

    // Fallback: no telemetry layer
    init_registry!(registry());
    Ok(None)
}

fn is_telemetry_disabled_from_options(options: &TracingSubscriberOptions) -> bool {
    options.disable_telemetry.unwrap_or(false) || env::var("FORC_DISABLE_TELEMETRY").is_ok()
}

#[cfg(test)]
mod tests {
    use super::*;
    use serial_test::serial;
    use tracing_test::traced_test;

    // Helper function to set up each test with consistent JSON mode state
    fn setup_test() {
        JSON_MODE_ACTIVE.store(false, Ordering::SeqCst);
    }

    #[traced_test]
    #[test]
    #[serial]
    fn test_println_label_green() {
        setup_test();

        let txt = "main.sw";
        println_label_green("Compiling", txt);

        let expected_action = "\x1b[1;32mCompiling\x1b[0m";
        assert!(logs_contain(&format!("{expected_action} {txt}")));
    }

    #[traced_test]
    #[test]
    #[serial]
    fn test_println_label_red() {
        setup_test();

        let txt = "main.sw";
        println_label_red("Error", txt);

        let expected_action = "\x1b[1;31mError\x1b[0m";
        assert!(logs_contain(&format!("{expected_action} {txt}")));
    }

    #[traced_test]
    #[test]
    #[serial]
    fn test_println_action_green() {
        setup_test();

        let txt = "main.sw";
        println_action_green("Compiling", txt);

        let expected_action = "\x1b[1;32mCompiling\x1b[0m";
        assert!(logs_contain(&format!("    {expected_action} {txt}")));
    }

    #[traced_test]
    #[test]
    #[serial]
    fn test_println_action_green_long() {
        setup_test();

        let txt = "main.sw";
        println_action_green("Supercalifragilistic", txt);

        let expected_action = "\x1b[1;32mSupercalifragilistic\x1b[0m";
        assert!(logs_contain(&format!("{expected_action} {txt}")));
    }

    #[traced_test]
    #[test]
    #[serial]
    fn test_println_action_red() {
        setup_test();

        let txt = "main";
        println_action_red("Removing", txt);

        let expected_action = "\x1b[1;31mRemoving\x1b[0m";
        assert!(logs_contain(&format!("     {expected_action} {txt}")));
    }

    #[traced_test]
    #[test]
    #[serial]
    fn test_json_mode_println_functions() {
        setup_test();

        JSON_MODE_ACTIVE.store(true, Ordering::SeqCst);

        // Call various print functions and capture the output
        println_label_green("Label", "Value");
        assert!(logs_contain("Label: Value"));

        println_action_green("Action", "Target");
        assert!(logs_contain("Action"));
        assert!(logs_contain("Target"));

        println_green("Green text");
        assert!(logs_contain("Green text"));

        println_warning("This is a warning");
        assert!(logs_contain("This is a warning"));

        println_error("This is an error");
        assert!(logs_contain("This is an error"));

        JSON_MODE_ACTIVE.store(false, Ordering::SeqCst);
    }
}