rojo/src/logging.rs

use std::{
    io::{self, IsTerminal, Write},
    path::Path,
};

use tracing_subscriber::{
    fmt::{self, time::UtcTime},
    layer::SubscriberExt,
    util::SubscriberInitExt,
    EnvFilter, Layer,
};

use crate::cli::ColorChoice;

pub struct LogGuard {
    _file_guard: Option<tracing_appender::non_blocking::WorkerGuard>,
}

/// Generates a session log filename like `atlas-serve.2026-03-01_14-32-05.log`.
/// Uses UTC time, hyphens and underscores only (safe on all OSes).
fn session_log_filename(command_name: &str) -> String {
    let now = time::OffsetDateTime::now_utc();
    format!(
        "{}.{:04}-{:02}-{:02}_{:02}-{:02}-{:02}.log",
        command_name,
        now.year(),
        now.month() as u8,
        now.day(),
        now.hour(),
        now.minute(),
        now.second(),
    )
}

fn write_log_header(file: &mut std::fs::File, command_name: &str, project_dir: Option<&Path>) {
    let now = time::OffsetDateTime::now_utc();
    let version = env!("CARGO_PKG_VERSION");
    let project = project_dir
        .map(|p| p.display().to_string())
        .unwrap_or_else(|| "none".into());
    let cwd = std::env::current_dir()
        .map(|p| p.display().to_string())
        .unwrap_or_else(|_| "unknown".into());

    let _ = writeln!(
        file,
        "=== Atlas v{version} ===\n\
         Command: {command_name}\n\
         Project: {project}\n\
         Working dir: {cwd}\n\
         Started: {now}\n\
         ==="
    );
}

pub fn init_logging(
    verbosity: u8,
    color: ColorChoice,
    project_dir: Option<&Path>,
    file_log_level: Option<tracing::level_filters::LevelFilter>,
    command_name: &str,
) -> LogGuard {
    let console_filter = match verbosity {
        0 => "info",
        1 => "info,librojo=debug",
        2 => "info,librojo=trace",
        _ => "trace",
    };

    let console_env_filter =
        EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new(console_filter));

    let use_ansi = match color {
        ColorChoice::Always => true,
        ColorChoice::Never => false,
        ColorChoice::Auto => io::stderr().is_terminal(),
    };

    let console_layer = fmt::layer()
        .with_writer(io::stderr)
        .with_ansi(use_ansi)
        .without_time()
        .with_target(true)
        .with_thread_names(false)
        .with_level(true)
        .with_filter(console_env_filter);

    let mut file_guard: Option<tracing_appender::non_blocking::WorkerGuard> = None;

    let file_layer = if let (Some(level), Some(home)) = (file_log_level, dirs::home_dir()) {
        let log_dir = home.join(".atlas").join("logs");

        match std::fs::create_dir_all(&log_dir) {
            Ok(()) => {
                let compress_dir = log_dir.clone();
                std::thread::spawn(move || {
                    lower_thread_priority();
                    compress_old_logs(&compress_dir);
                });

                let log_filename = session_log_filename(command_name);
                let log_path = log_dir.join(&log_filename);

                match std::fs::OpenOptions::new()
                    .create(true)
                    .append(true)
                    .open(&log_path)
                {
                    Ok(mut file) => {
                        write_log_header(&mut file, command_name, project_dir);

                        let (non_blocking, guard) = tracing_appender::non_blocking(file);
                        file_guard = Some(guard);

                        let file_filter = EnvFilter::new(level.to_string());

                        let layer = fmt::layer()
                            .with_writer(non_blocking)
                            .with_ansi(false)
                            .with_timer(UtcTime::rfc_3339())
                            .with_target(true)
                            .with_thread_names(true)
                            .with_level(true)
                            .with_filter(file_filter);

                        Some(layer)
                    }
                    Err(e) => {
                        eprintln!(
                            "Warning: could not create log file {}: {e}",
                            log_path.display()
                        );
                        None
                    }
                }
            }
            Err(e) => {
                eprintln!(
                    "Warning: could not create log directory {}: {e}",
                    log_dir.display()
                );
                None
            }
        }
    } else {
        None
    };

    tracing_subscriber::registry()
        .with(console_layer)
        .with(file_layer)
        .init();

    LogGuard {
        _file_guard: file_guard,
    }
}

fn lower_thread_priority() {
    #[cfg(windows)]
    unsafe {
        extern "system" {
            fn GetCurrentThread() -> isize;
            fn SetThreadPriority(handle: isize, priority: i32) -> i32;
        }
        const THREAD_PRIORITY_BELOW_NORMAL: i32 = -1;
        SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_BELOW_NORMAL);
    }

    #[cfg(unix)]
    unsafe {
        extern "C" {
            fn nice(inc: i32) -> i32;
        }
        nice(10);
    }
}

fn compress_old_logs(log_dir: &Path) {
    let now_secs = std::time::SystemTime::now()
        .duration_since(std::time::UNIX_EPOCH)
        .unwrap_or_default()
        .as_secs();
    let today = now_secs / 86400;

    let entries = match std::fs::read_dir(log_dir) {
        Ok(entries) => entries,
        Err(_) => return,
    };

    for entry in entries.flatten() {
        let path = entry.path();
        let file_name = match path.file_name().and_then(|n| n.to_str()) {
            Some(n) => n.to_owned(),
            None => continue,
        };

        if file_name.ends_with(".log.gz") {
            if let Ok(meta) = entry.metadata() {
                if let Ok(modified) = meta.modified() {
                    let age_days = modified
                        .duration_since(std::time::UNIX_EPOCH)
                        .map(|d| today.saturating_sub(d.as_secs() / 86400))
                        .unwrap_or(0);
                    if age_days > 7 {
                        let _ = std::fs::remove_file(&path);
                    }
                }
            }
            continue;
        }

        if !file_name.ends_with(".log") {
            continue;
        }

        // Try to open for exclusive write to check if another process holds it.
        // On Windows this fails if another Atlas process has the file open.
        if std::fs::OpenOptions::new().write(true).open(&path).is_err() {
            continue;
        }

        let gz_path = path.with_extension("log.gz");
        if let Ok(input) = std::fs::read(&path) {
            let gz_file = match std::fs::File::create(&gz_path) {
                Ok(f) => f,
                Err(_) => continue,
            };
            let mut encoder =
                flate2::write::GzEncoder::new(gz_file, flate2::Compression::default());
            if encoder.write_all(&input).is_ok() && encoder.finish().is_ok() {
                let _ = std::fs::remove_file(&path);
            } else {
                let _ = std::fs::remove_file(&gz_path);
            }
        }
    }
}

/// Parses a Roblox log message forwarded from the plugin, extracting the real
/// log level and a cleaned message. Rojo plugin logs have `[Rojo-Trace] ` etc.
/// prefixes that encode the level; these are stripped and replaced with `[Rojo]`.
/// Game script output without a Rojo prefix falls back to the `MessageType` enum.
///
/// Returns `(log::Level, cleaned_message)`.
pub fn parse_roblox_log(message: &str, message_type: u64) -> (log::Level, String) {
    if let Some(rest) = message.strip_prefix("[Rojo-Trace] ") {
        (log::Level::Trace, format!("[Studio] [Rojo] {}", rest))
    } else if let Some(rest) = message.strip_prefix("[Rojo-Debug] ") {
        (log::Level::Debug, format!("[Studio] [Rojo] {}", rest))
    } else if let Some(rest) = message.strip_prefix("[Rojo-Info] ") {
        (log::Level::Info, format!("[Studio] [Rojo] {}", rest))
    } else if let Some(rest) = message.strip_prefix("[Rojo-Warn] ") {
        (log::Level::Warn, format!("[Studio] [Rojo] {}", rest))
    } else {
        let lvl = match message_type {
            2 => log::Level::Warn,
            3 => log::Level::Error,
            _ => log::Level::Info,
        };
        (lvl, format!("[Studio] {}", message))
    }
}

/// Lightweight pre-read of a project file to extract the `fileLogLevel` config.
/// Accepts either a project file path or a directory (searches for default project).
/// Returns `None` if no project found or the field is absent (caller defaults
/// to trace). Returns `Some(None)` when `"none"` (disabled).
pub fn quick_read_file_log_level(
    path: &Path,
) -> Option<Option<tracing::level_filters::LevelFilter>> {
    use tracing::level_filters::LevelFilter;

    let project_file = if path.is_file() {
        path.to_path_buf()
    } else {
        let json5_path = path.join("default.project.json5");
        if json5_path.is_file() {
            json5_path
        } else {
            let json_path = path.join("default.project.json");
            if json_path.is_file() {
                json_path
            } else {
                return None;
            }
        }
    };

    let contents = std::fs::read_to_string(&project_file).ok()?;
    let val: serde_json::Value = json5::from_str(&contents).ok()?;
    let level_str = val.get("fileLogLevel")?.as_str()?;

    Some(match level_str.to_lowercase().as_str() {
        "none" | "off" => None,
        "error" => Some(LevelFilter::ERROR),
        "warn" => Some(LevelFilter::WARN),
        "info" => Some(LevelFilter::INFO),
        "debug" => Some(LevelFilter::DEBUG),
        "trace" => Some(LevelFilter::TRACE),
        _ => Some(LevelFilter::TRACE),
    })
}

#[cfg(test)]
mod tests {
    use super::*;
    use std::io::Read;
    use tracing::level_filters::LevelFilter;

    #[test]
    fn parse_roblox_log_rojo_trace() {
        let (level, msg) = parse_roblox_log("[Rojo-Trace] snapshot started", 0);
        assert_eq!(level, log::Level::Trace);
        assert_eq!(msg, "[Studio] [Rojo] snapshot started");
    }

    #[test]
    fn parse_roblox_log_rojo_debug() {
        let (level, msg) = parse_roblox_log("[Rojo-Debug] loading project", 0);
        assert_eq!(level, log::Level::Debug);
        assert_eq!(msg, "[Studio] [Rojo] loading project");
    }

    #[test]
    fn parse_roblox_log_rojo_info() {
        let (level, msg) = parse_roblox_log("[Rojo-Info] connected to server", 0);
        assert_eq!(level, log::Level::Info);
        assert_eq!(msg, "[Studio] [Rojo] connected to server");
    }

    #[test]
    fn parse_roblox_log_rojo_warn() {
        let (level, msg) = parse_roblox_log("[Rojo-Warn] something fishy", 0);
        assert_eq!(level, log::Level::Warn);
        assert_eq!(msg, "[Studio] [Rojo] something fishy");
    }

    #[test]
    fn parse_roblox_log_game_print() {
        let (level, msg) = parse_roblox_log("hello from game", 0);
        assert_eq!(level, log::Level::Info);
        assert_eq!(msg, "[Studio] hello from game");
    }

    #[test]
    fn parse_roblox_log_game_warn() {
        let (level, msg) = parse_roblox_log("something wrong", 2);
        assert_eq!(level, log::Level::Warn);
        assert_eq!(msg, "[Studio] something wrong");
    }

    #[test]
    fn parse_roblox_log_game_error() {
        let (level, msg) = parse_roblox_log("crash!", 3);
        assert_eq!(level, log::Level::Error);
        assert_eq!(msg, "[Studio] crash!");
    }

    #[test]
    fn parse_roblox_log_message_info_type() {
        let (level, msg) = parse_roblox_log("info message", 1);
        assert_eq!(level, log::Level::Info);
        assert_eq!(msg, "[Studio] info message");
    }

    #[test]
    fn parse_roblox_log_unknown_message_type() {
        let (level, msg) = parse_roblox_log("weird type", 99);
        assert_eq!(level, log::Level::Info);
        assert_eq!(msg, "[Studio] weird type");
    }

    #[test]
    fn parse_roblox_log_partial_prefix_not_stripped() {
        let (level, msg) = parse_roblox_log("[Rojo-Trace]no space", 0);
        assert_eq!(level, log::Level::Info);
        assert_eq!(msg, "[Studio] [Rojo-Trace]no space");
    }

    #[test]
    fn parse_roblox_log_empty_message_after_prefix() {
        let (level, msg) = parse_roblox_log("[Rojo-Info] ", 0);
        assert_eq!(level, log::Level::Info);
        assert_eq!(msg, "[Studio] [Rojo] ");
    }

    #[test]
    fn quick_read_file_log_level_trace() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json5"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "trace" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, Some(Some(LevelFilter::TRACE)));
    }

    #[test]
    fn quick_read_file_log_level_none() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json5"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "none" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, Some(None));
    }

    #[test]
    fn quick_read_file_log_level_off() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json5"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "off" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, Some(None));
    }

    #[test]
    fn quick_read_file_log_level_warn() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json5"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "warn" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, Some(Some(LevelFilter::WARN)));
    }

    #[test]
    fn quick_read_file_log_level_case_insensitive() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json5"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "DEBUG" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, Some(Some(LevelFilter::DEBUG)));
    }

    #[test]
    fn quick_read_file_log_level_absent() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json5"),
            r#"{ "name": "Test", "tree": {} }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, None);
    }

    #[test]
    fn quick_read_file_log_level_no_project() {
        let dir = tempfile::tempdir().unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, None);
    }

    #[test]
    fn quick_read_file_log_level_legacy_json() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "error" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, Some(Some(LevelFilter::ERROR)));
    }

    #[test]
    fn quick_read_file_log_level_json5_preferred_over_json() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json5"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "info" }"#,
        )
        .unwrap();
        std::fs::write(
            dir.path().join("default.project.json"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "error" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, Some(Some(LevelFilter::INFO)));
    }

    #[test]
    fn quick_read_file_log_level_direct_file_path() {
        let dir = tempfile::tempdir().unwrap();
        let file_path = dir.path().join("custom.project.json5");
        std::fs::write(
            &file_path,
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "debug" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(&file_path);
        assert_eq!(result, Some(Some(LevelFilter::DEBUG)));
    }

    #[test]
    fn quick_read_file_log_level_unknown_defaults_to_trace() {
        let dir = tempfile::tempdir().unwrap();
        std::fs::write(
            dir.path().join("default.project.json5"),
            r#"{ "name": "Test", "tree": {}, "fileLogLevel": "banana" }"#,
        )
        .unwrap();
        let result = quick_read_file_log_level(dir.path());
        assert_eq!(result, Some(Some(LevelFilter::TRACE)));
    }

    #[test]
    fn compress_old_logs_compresses_all_log_files() {
        let dir = tempfile::tempdir().unwrap();
        let log_dir = dir.path();

        let serve_file = log_dir.join("atlas-serve.2020-01-01_10-00-00.log");
        std::fs::write(&serve_file, "serve log content").unwrap();

        let build_file = log_dir.join("atlas-build.2020-01-01_11-00-00.log");
        std::fs::write(&build_file, "build log content").unwrap();

        compress_old_logs(log_dir);

        assert!(!serve_file.exists(), "serve .log should be deleted");
        assert!(!build_file.exists(), "build .log should be deleted");

        let serve_gz = log_dir.join("atlas-serve.2020-01-01_10-00-00.log.gz");
        assert!(serve_gz.exists(), "serve .log.gz should be created");

        let build_gz = log_dir.join("atlas-build.2020-01-01_11-00-00.log.gz");
        assert!(build_gz.exists(), "build .log.gz should be created");

        let gz_data = std::fs::read(&serve_gz).unwrap();
        let mut decoder = flate2::read::GzDecoder::new(&gz_data[..]);
        let mut decompressed = String::new();
        decoder.read_to_string(&mut decompressed).unwrap();
        assert_eq!(decompressed, "serve log content");
    }

    #[test]
    fn compress_old_logs_skips_non_log_files() {
        let dir = tempfile::tempdir().unwrap();
        let log_dir = dir.path();

        let txt_file = log_dir.join("notes.txt");
        std::fs::write(&txt_file, "not a log").unwrap();

        compress_old_logs(log_dir);

        assert!(txt_file.exists(), "non-.log files should be left alone");
    }

    #[test]
    fn compress_old_logs_prunes_old_gz() {
        let dir = tempfile::tempdir().unwrap();
        let log_dir = dir.path();

        let old_gz = log_dir.join("atlas-serve.2020-01-01_10-00-00.log.gz");
        std::fs::write(&old_gz, "old compressed").unwrap();

        let mtime =
            std::time::SystemTime::UNIX_EPOCH + std::time::Duration::from_secs(86400 * 18262);
        filetime::set_file_mtime(&old_gz, filetime::FileTime::from_system_time(mtime))
            .unwrap_or_default();

        compress_old_logs(log_dir);

        assert!(!old_gz.exists(), "old .log.gz (>7 days) should be pruned");
    }

    #[test]
    fn session_log_filename_format() {
        let name = session_log_filename("atlas-serve");
        assert!(
            name.starts_with("atlas-serve."),
            "should start with command prefix"
        );
        assert!(name.ends_with(".log"), "should end with .log");
        assert!(!name.contains(':'), "no colons (Windows-safe)");
        assert!(!name.contains('/'), "no slashes");
        assert!(!name.contains('\\'), "no backslashes");

        let middle = &name["atlas-serve.".len()..name.len() - ".log".len()];
        assert_eq!(
            middle.len(),
            19,
            "timestamp should be YYYY-MM-DD_HH-MM-SS (19 chars)"
        );
        assert_eq!(&middle[4..5], "-");
        assert_eq!(&middle[7..8], "-");
        assert_eq!(&middle[10..11], "_");
        assert_eq!(&middle[13..14], "-");
        assert_eq!(&middle[16..17], "-");
    }
}