log2src 0.1.0

//! log2src maps between generated logs and source code locations.
//!
//! # Stability
//! This crate is evolving. Prefer types and methods documented as part of the
//! primary workflow. Other exposed types may become internal in future releases.
//!
//! # Quick Start
//! The typical flow is:
//! 1. Create a LogMatcher
//! 2. Add one or more source roots
//! 3. Discover sources and extract the logging
//! 4. Build a LogRef from log input and attempt to match it
//!
//! # Example
//! ```no_run
//! use log2src::{LogMatcher, LogRefBuilder};
//! use std::path::Path;
//!
//! let mut matcher = LogMatcher::new();
//! matcher.add_root(Path::new("./src")).unwrap();
//!
//! matcher.discover_sources();
//! let _summary = matcher.extract_log_statements();
//!
//! let log_ref = LogRefBuilder::new()
//!     .with_body(Some("hello from logs"))
//!     .build("hello from logs");
//! let _mapping = matcher.match_log_statement(&log_ref);
//! ```

use directories::ProjectDirs;
use indicatif::HumanBytes;
use itertools::Itertools;
use miette::Diagnostic;
use rayon::prelude::*;
use regex::{Captures, Regex, RegexSet};
use serde::{Deserialize, Serialize};
use sha2::{Digest, Sha256};
use std::collections::HashMap;
use std::error::Error;
use std::ffi::OsStr;
use std::fs::File;
use std::io::{BufRead, BufReader, Seek, Write};
use std::ops::Deref;
use std::path::{Path, PathBuf};
use std::sync::{Arc, LazyLock};
use std::time::{SystemTime, UNIX_EPOCH};
use std::{fs, io};
use tempfile::NamedTempFile;
use thiserror::Error;
use tree_sitter::Language;

mod code_source;
mod log_format;
mod progress;
mod source_hier;
mod source_query;
mod source_ref;

use crate::code_source::CodeSource;
use crate::progress::{current_global_progress_tracker, WorkGuard};
use crate::source_hier::{ScanEvent, SourceFileID, SourceHierContent, SourceHierTree};
use crate::source_query::SourceQuery;
use crate::source_ref::FormatArgument;

pub use log_format::LogFormat;
pub use progress::set_tracker_once;
pub use progress::ProgressListener;
pub use progress::ProgressTracker;
pub use progress::ProgressUpdate;
pub use progress::WorkInfo;
use source_query::QueryResult;
pub use source_ref::{CallSite, SourceRef};

#[derive(Error, Debug, Diagnostic, Clone, Default)]
pub enum LogError {
    #[default]
    #[error("unknown error")]
    Unknown,
    #[error("unable to read line {line}")]
    UnableToReadLine { line: usize, source: Arc<io::Error> },
    #[error("invalid log format regular expression")]
    InvalidFormatRegex { source: regex::Error },
    #[error("unknown capture in log format: {name}")]
    #[diagnostic(help(
        "The supported captures are: timestamp, thread, level, file, line, method, and body"
    ))]
    UnknownFormatCapture { name: String },
    #[error("log format is missing capture: {name}")]
    #[diagnostic(help("A log format must have a 'body' capture at a minimum"))]
    FormatMissingCapture { name: String },
    #[error("\"{path}\" is already covered by \"{root}\"")]
    PathExists { path: PathBuf, root: PathBuf },
    #[error("cannot read source file \"{path}\"")]
    #[diagnostic(severity(warning))]
    CannotReadSourceFile {
        path: PathBuf,
        source: Arc<io::Error>,
    },
    #[error("cannot read log file \"{path}\"")]
    CannotReadLogFile {
        path: PathBuf,
        source: Arc<io::Error>,
    },
    #[error("no log statements found")]
    #[diagnostic(help(
        "\
    Make sure the source path is valid and refers to a tree with \
    supported source code and logging statements"
    ))]
    NoLogStatements,
    #[error("cannot access path \"{path}\"")]
    #[diagnostic(severity(warning))]
    CannotAccessPath {
        path: PathBuf,
        source: Arc<io::Error>,
    },
    #[error("unsupported file type \"{name}\"")]
    UnsupportedFileType { name: String },
    #[error("no log messages found in input")]
    #[diagnostic(help("Make sure the log format matches the input"))]
    NoLogMessages,
    #[error("failed to find user cache directory")]
    #[diagnostic(severity(warning))]
    CannotFindCache,
    #[error("failed to create cache directory \"{path}\"")]
    #[diagnostic(severity(warning))]
    CannotCreateCache {
        path: PathBuf,
        source: Arc<dyn Error + Send + Sync>,
    },
    #[error("failed to write cache file")]
    #[diagnostic(severity(warning))]
    FailedToWriteCache {
        source: Arc<dyn Error + Send + Sync>,
    },
    #[error("outdated cache file \"{path}\"")]
    #[diagnostic(severity(info))]
    OldCacheEntry { path: PathBuf },
    #[error("failed to read cache file \"{path}\"")]
    #[diagnostic(severity(warning))]
    FailedToReadCache {
        path: PathBuf,
        source: Arc<dyn Error + Send + Sync>,
    },
}

/// Handle for the source tree cache
pub struct Cache {
    location: PathBuf,
}

impl Cache {
    /// Try to get a handle on the cache in the user's default location.
    pub fn open() -> Result<Cache, LogError> {
        // XXX we don't own log2src.org
        let project_dirs =
            ProjectDirs::from("org", "log2src", "log2src").ok_or(LogError::CannotFindCache {})?;
        let location = project_dirs.cache_dir().to_path_buf();
        Ok(Cache { location })
    }

    /// The path to the cache directory.
    pub fn location(&self) -> &Path {
        &self.location
    }
}

#[derive(Serialize, Deserialize, Debug)]
pub(crate) enum CacheEntrySchema {
    #[serde(
        rename = "https://raw.githubusercontent.com/ttiimm/log2src/refs/heads/main/schemas/cache-header-v1.json"
    )]
    V1,
}

/// The revision value is a simple way to invalidate the cache entries by changing the number.
#[derive(Serialize, Deserialize, Debug)]
pub(crate) enum Revision {
    #[serde(rename = "1")]
    Current,
}

#[derive(Serialize, Deserialize, Debug)]
pub(crate) enum CacheEntryFormat {
    Postcard,
}

/// Header for an entry in the cache.  Currently, this is more of interest to humans than machines.
#[derive(Serialize, Deserialize, Debug)]
pub(crate) struct CacheEntryHeader {
    #[serde(rename = "$schema")]
    pub schema: CacheEntrySchema,
    pub revision: Revision,
    pub format: CacheEntryFormat,
    pub path: String,
    pub timestamp: u64,
}

fn to_write_cache_error<E>(err: E) -> LogError
where
    E: Error + Send + Sync + 'static,
{
    LogError::FailedToWriteCache {
        source: Arc::new(err),
    }
}

/// Collection of log statements in a single source file
#[derive(Debug, Serialize, Deserialize)]
pub struct StatementsInFile {
    pub path: String,
    id: SourceFileID,
    pub log_statements: Vec<SourceRef>,
    /// A single matcher for all log statements.
    /// If there are too many in the file, the `RegexSet`` construction
    /// fails silently and this file is skipped during matching.
    #[serde(skip)]
    pub(crate) matcher: Option<RegexSet>,
}

impl StatementsInFile {
    /// When loading from the cache, we need to fill in the pattern string and populate the
    /// RegexSet matcher.
    fn try_creating_matcher(&mut self) {
        for stmt in self.log_statements.iter_mut() {
            if stmt.pattern_str.is_empty() {
                stmt.pattern_str = stmt.pattern.to_string();
            }
        }
        if self.matcher.is_some() {
            return;
        }
        let patterns = self
            .log_statements
            .iter()
            .map(|s| s.pattern_str.as_str())
            .collect::<Vec<&str>>();
        self.matcher = RegexSet::new(&patterns).ok();
    }

    fn to_lookup_pair(&self) -> Option<(String, SourceFileID)> {
        PATH_TO_NAME_REGEX
            .captures(&self.path)
            .into_iter()
            .flat_map(|caps| caps.get(1))
            .map(|name_match| (name_match.as_str().to_owned(), self.id))
            .next()
    }
}

/// Collection of individual source files under a root path
#[derive(Serialize, Deserialize, Debug)]
pub(crate) struct SourceTree {
    pub tree: SourceHierTree,
    pub files_with_statements: HashMap<SourceFileID, StatementsInFile>,
    /// Most log statements only have the file name, so we keep an extra map from the name
    /// to the source file IDs to speed up matches.
    #[serde(skip)]
    pub file_name_to_sources: HashMap<String, Vec<SourceFileID>>,
}

/// Maps log lines to source statements discovered from one or more source roots.
///
/// Typical lifecycle:
/// - add_root
/// - discover_sources
/// - extract_log_statements
/// - match_log_statement
#[derive(Default)]
pub struct LogMatcher {
    roots: HashMap<PathBuf, SourceTree>,
}

fn to_cached_name(path: &Path) -> String {
    format!(
        "cache.{:x}",
        Sha256::digest(path.as_os_str().as_encoded_bytes())
    )
}

/// The result of calling extract_log_statements() with the summary and errors.
#[derive(Default)]
pub struct ExtractLogResult {
    pub summary: ExtractLogSummary,
    pub errors: Vec<LogError>,
}

/// A summary of the work done by extract_log_statements().  Useful for knowing if there were
/// any changes that need to be saved to the cache.
#[derive(Default, Debug)]
pub struct ExtractLogSummary {
    pub deleted: u64,
    pub new: u64,
}

impl ExtractLogSummary {
    pub fn changes(&self) -> u64 {
        self.new.saturating_add(self.deleted)
    }
}

impl LogMatcher {
    /// Create an empty LogMatcher
    pub fn new() -> Self {
        Self {
            roots: HashMap::new(),
        }
    }

    fn load_cache_entry(path: &Path, mut file: &File) -> Result<SourceTree, LogError> {
        let mut reader = BufReader::new(&mut file);
        let mut header_str = String::new();
        reader
            .read_line(&mut header_str)
            .map_err(|err| LogError::FailedToReadCache {
                path: path.to_owned(),
                source: Arc::new(err),
            })?;
        // We're deserializing the header to check for garbage and version compatibility.
        let _header = serde_json::from_str::<CacheEntryHeader>(&header_str).map_err(|_err| {
            LogError::OldCacheEntry {
                path: path.to_owned(),
            }
        })?;
        // XXX check that the path matches?
        let mut scratch = [0u8; 1024];
        let (mut decoded_root, _) = postcard::from_io::<SourceTree, _>((&mut reader, &mut scratch))
            .map_err(|err| LogError::FailedToReadCache {
                path: path.to_owned(),
                source: Arc::new(err),
            })?;
        for sif in decoded_root.files_with_statements.values_mut() {
            sif.try_creating_matcher();
            sif.to_lookup_pair().into_iter().for_each(|(name, sid)| {
                decoded_root
                    .file_name_to_sources
                    .entry(name)
                    .or_default()
                    .push(sid);
            });
        }
        Ok(decoded_root)
    }

    /// Try to load SourceTrees from the cache for each root.
    #[must_use]
    pub fn load_from_cache(&mut self, cache: &Cache) -> Vec<LogError> {
        let tracker = current_global_progress_tracker();
        tracker.begin_step(format!(
            "Loading cached log statements from: {}",
            cache.location.display()
        ));
        let mut old_roots: HashMap<PathBuf, SourceTree> = HashMap::new();
        let mut retval: Vec<LogError> = Vec::new();
        std::mem::swap(&mut self.roots, &mut old_roots);
        let work_guard = tracker.doing_work(old_roots.len() as u64, "root".to_string());
        let mut found = 0;
        let mut not_found = 0;
        let mut skipped = 0;
        for (root_path, old_root) in old_roots.into_iter() {
            let cached_name = to_cached_name(&root_path);
            let cached_path = cache.location.join(&cached_name);
            let new_root = if let Ok(file) = File::open(&cached_path) {
                match Self::load_cache_entry(&cached_path, &file) {
                    Ok(new_root) => {
                        found += 1;
                        new_root
                    }
                    Err(err) => {
                        skipped += 1;
                        retval.push(err);
                        old_root
                    }
                }
            } else {
                not_found += 1;
                old_root
            };
            self.roots.insert(root_path, new_root);
            work_guard.inc(1);
        }
        tracker.end_step(format!(
            "found {}; skipped {}; not found {}",
            found, skipped, not_found
        ));

        retval
    }

    /// Save the log statements to the cache.
    pub fn cache_to(&self, cache: &Cache) -> Result<(), LogError> {
        let tracker = current_global_progress_tracker();
        tracker.begin_step(format!(
            "Saving log statements to: {}",
            cache.location.display()
        ));
        let mut total_size: u64 = 0;
        let work_guard = tracker.doing_work(self.roots.len() as u64, "root".to_string());
        for (root_path, root) in &self.roots {
            let cached_name = to_cached_name(root_path);
            let tmp_path = {
                fs::create_dir_all(&cache.location).map_err(to_write_cache_error)?;
                let mut file =
                    NamedTempFile::with_suffix_in(".tmp", &cache.location).map_err(|err| {
                        LogError::FailedToWriteCache {
                            source: Arc::new(err),
                        }
                    })?;
                // Write a JSON header as the first line so that a user can figure out what this
                // file is.  It can also be used in the future if the file format needs to change.
                let header = CacheEntryHeader {
                    schema: CacheEntrySchema::V1,
                    revision: Revision::Current,
                    format: CacheEntryFormat::Postcard,
                    path: root_path.to_string_lossy().to_string(),
                    timestamp: SystemTime::now()
                        .duration_since(UNIX_EPOCH)
                        .unwrap_or_default()
                        .as_secs(),
                };
                serde_json::to_writer(&file, &header).map_err(to_write_cache_error)?;
                file.write_all("\n".as_bytes())
                    .map_err(to_write_cache_error)?;
                postcard::to_io(root, &mut file).map_err(to_write_cache_error)?;
                total_size = total_size.saturating_add(file.stream_position().unwrap_or(0));
                file.into_temp_path()
            };
            fs::rename(tmp_path, cache.location.join(cached_name)).map_err(to_write_cache_error)?;
            work_guard.inc(1);
        }
        tracker.end_step(format!(
            "{} files totaling {}",
            self.roots.len(),
            HumanBytes(total_size)
        ));

        Ok(())
    }

    /// True if no log statements are recognized by this matcher.
    pub fn is_empty(&self) -> bool {
        self.roots
            .iter()
            .all(|(_path, coll)| coll.files_with_statements.is_empty())
    }

    /// Add a source root path
    pub fn add_root(&mut self, path: &Path) -> Result<(), LogError> {
        let path = path.canonicalize().unwrap_or(path.to_owned());
        if let Some(_existing_path) = self.match_path(&path) {
        } else {
            self.roots
                .entry(path.to_owned())
                .or_insert_with(|| SourceTree {
                    tree: SourceHierTree::from(&path),
                    files_with_statements: HashMap::new(),
                    file_name_to_sources: HashMap::new(),
                });
        }
        Ok(())
    }

    /// Check if the given path is covered by any of the roots in this matcher.
    fn match_path(&self, path: &Path) -> Option<(&PathBuf, &SourceTree)> {
        self.roots
            .iter()
            .find(|(existing_path, _coll)| path.starts_with(existing_path))
    }

    /// Return the log statements extracted from the given source file path, if any.
    pub fn find_source_file_statements(&self, path: &Path) -> Vec<&StatementsInFile> {
        self.roots
            .values()
            .flat_map(|root| {
                root.tree
                    .find_file(path)
                    .into_iter()
                    .filter_map(|(_actual_path, info)| root.files_with_statements.get(&info.id))
            })
            .collect()
    }

    /// Traverse the roots looking for supported source files.
    #[must_use]
    pub fn discover_sources(&mut self) -> Vec<LogError> {
        let tracker = current_global_progress_tracker();
        tracker.begin_step("Finding source code".to_string());
        let pguard = tracker.doing_work(self.roots.len() as u64, "paths".to_string());
        self.roots.par_iter_mut().for_each(|(_path, coll)| {
            coll.tree.sync();
            pguard.inc(1);
        });
        let mut retval: Vec<LogError> = Vec::new();
        let mut file_count: usize = 0;
        self.roots.values().for_each(|coll| {
            coll.tree.visit(|node| match &node.content {
                SourceHierContent::File { .. } => file_count += 1,
                SourceHierContent::UnsupportedFile { .. } => {}
                SourceHierContent::Directory { .. } => {}
                SourceHierContent::Error { ref source } => retval.push(source.clone()),
                SourceHierContent::Unknown { .. } => {}
            });
        });
        tracker.end_step(format!("{} files found", file_count));

        retval
    }

    /// Scan the source files looking for potential log statements.
    pub fn extract_log_statements(&mut self) -> ExtractLogResult {
        let tracker = current_global_progress_tracker();
        let mut retval = ExtractLogResult::default();
        tracker.begin_step("Extracting log statements".to_string());
        self.roots.iter_mut().for_each(|(_path, coll)| {
            let guard = tracker.doing_work(coll.tree.stats().files as u64, "files".to_string());
            for event_chunk in &coll.tree.scan().chunks(10) {
                let sources = event_chunk
                    .flat_map(|event| match event {
                        ScanEvent::NewFile(path, info) => {
                            retval.summary.new += 1;
                            match File::open(&path) {
                                Ok(file) => match CodeSource::new(&path, info, file) {
                                    Ok(cs) => Some(cs),
                                    Err(err) => {
                                        retval.errors.push(err);
                                        None
                                    }
                                },
                                Err(err) => {
                                    retval.errors.push(LogError::CannotReadSourceFile {
                                        path,
                                        source: std::sync::Arc::new(err),
                                    });
                                    None
                                }
                            }
                        }
                        ScanEvent::DeletedFile(_path, id) => {
                            retval.summary.deleted += 1;
                            coll.files_with_statements.remove(&id);
                            coll.file_name_to_sources.values_mut().for_each(|ids| {
                                ids.retain_mut(|elem| *elem != id);
                            });
                            None
                        }
                    })
                    .collect::<Vec<CodeSource>>();
                extract_logging_guarded(&sources, &guard)
                    .into_iter()
                    .for_each(|sif| {
                        sif.to_lookup_pair().into_iter().for_each(|(name, sid)| {
                            coll.file_name_to_sources.entry(name).or_default().push(sid);
                        });
                        coll.files_with_statements.insert(sif.id, sif);
                    });
            }
        });
        tracker.end_step(format!(
            "{} found",
            self.roots
                .values()
                .flat_map(|coll| coll.files_with_statements.values())
                .map(|stmts| stmts.log_statements.len())
                .sum::<usize>()
        ));

        retval
    }

    /// Attempt to match the given log message.
    pub fn match_log_statement<'a>(&self, log_ref: &LogRef<'a>) -> Option<LogMapping<'a>> {
        for coll in self.roots.values() {
            let matches = if let Some(LogDetails {
                file: Some(filename),
                body: Some(body),
                ..
            }) = log_ref.details
            {
                if let Some(sources) = coll.file_name_to_sources.get(filename) {
                    sources
                        .iter()
                        .flat_map(|path| coll.files_with_statements.get(path))
                        .flat_map(|stmts| {
                            let file_matches = stmts.matcher.as_ref()?.matches(body);
                            match file_matches.iter().next() {
                                None => None,
                                Some(index) => stmts.log_statements.get(index),
                            }
                        })
                        .collect::<Vec<&SourceRef>>()
                } else {
                    // XXX this block and the else are basically the same, try to refactor
                    coll.files_with_statements
                        .values()
                        .filter(|stmts| stmts.path.contains(filename))
                        .flat_map(|stmts| {
                            let file_matches = stmts.matcher.as_ref()?.matches(body);
                            match file_matches.iter().next() {
                                None => None,
                                Some(index) => stmts.log_statements.get(index),
                            }
                        })
                        .collect::<Vec<&SourceRef>>()
                }
            } else {
                coll.files_with_statements
                    .par_iter()
                    .flat_map(|src_ref_coll| {
                        let file_matches = src_ref_coll.1.matcher.as_ref()?.matches(log_ref.body());
                        match file_matches.iter().next() {
                            None => None,
                            Some(index) => src_ref_coll.1.log_statements.get(index),
                        }
                    })
                    .collect::<Vec<&SourceRef>>()
            };
            if let Some(src_ref) = matches
                .iter()
                .sorted_by(|lhs, rhs| rhs.quality.cmp(&lhs.quality))
                .next()
            {
                let exception_trace = match log_ref {
                    LogRef {
                        details:
                            Some(LogDetails {
                                trace: Some(trace), ..
                            }),
                        ..
                    } => trace.to_exception_trace(self),
                    _ => Vec::new(),
                };
                let variables = extract_variables(log_ref, src_ref);
                return Some(LogMapping {
                    log_ref: *log_ref,
                    src_ref: Some((*src_ref).clone()),
                    variables,
                    exception_trace,
                });
            }
        }
        None
    }
}

#[derive(Debug, Eq, PartialEq, Copy, Clone, Serialize, Deserialize)]
pub enum SourceLanguage {
    Rust,
    Java,
    #[serde(rename = "C++")]
    Cpp,
    Python,
}

impl From<SourceLanguage> for Language {
    fn from(value: SourceLanguage) -> Self {
        match value {
            SourceLanguage::Rust => tree_sitter_rust_orchard::LANGUAGE.into(),
            SourceLanguage::Java => tree_sitter_java::LANGUAGE.into(),
            SourceLanguage::Cpp => tree_sitter_cpp::LANGUAGE.into(),
            SourceLanguage::Python => tree_sitter_python::LANGUAGE.into(),
        }
    }
}

const IDENTS_RS: &[&str] = &["debug", "info", "warn"];
const IDENTS_JAVA: &[&str] = &["logger", "log", "fine", "debug", "info", "warn", "trace"];
const IDENTS_CPP: &[&str] = &["debug", "info", "warn", "trace"];

const IDENTS_PYTHON: &[&str] = &["debug", "info", "warn", "trace"];

static RUST_PLACEHOLDER_REGEX: LazyLock<Regex> = LazyLock::new(|| {
    Regex::new(r#"\{(?:([a-zA-Z_][a-zA-Z0-9_.]*)|(\d+))?\s*(?::[^}]*)?}"#).unwrap()
});

static JAVA_PLACEHOLDER_REGEX: LazyLock<Regex> =
    LazyLock::new(|| Regex::new(r#"\{[^}]*}|\\\{([^}]*)}"#).unwrap());

static CPP_PLACEHOLDER_REGEX: LazyLock<Regex> = LazyLock::new(|| {
    Regex::new(r#"%[-+ #0]*(?:\d+|\*)?(?:\.(?:\d+|\*))?[hlLzjt]*[diuoxXfFeEgGaAcspn%]|\{(?:([a-zA-Z_][a-zA-Z0-9_.]*)|(\d+))?\s*(?::[^}]*)?}"#).unwrap()
});

static PYTHON_PLACEHOLDER_REGEX: LazyLock<Regex> = LazyLock::new(|| {
    Regex::new(r#"%[-+ #0]*(?:\d+|\*)?(?:\.(?:\d+|\*))?[hlLzjt]*[diuoxXfFeEgGaAcrspn%]"#).unwrap()
});

static PATH_TO_NAME_REGEX: LazyLock<Regex> =
    LazyLock::new(|| Regex::new(r#"[/\\]([^/\\]+)$"#).unwrap());

static BACKTRACE_REGEX: LazyLock<Regex> = LazyLock::new(|| {
    Regex::new(
        r#"(?smx)
    (?<python>
        # Match the initial 'Traceback' line
        ^Traceback\s+\(most\s+recent\s+call\s+last\):\s*$\n?

        # Match all stack frames
        (?:
            # File line: '  File "path", line N, in function'
            ^\s{2}File\s+"[^"]*",\s+line\s+\d+,\s+in\s+\S+\s*$\n?

            # Code line (optional): '    code_here'
            (?:^\s{4}.*$\n?)?
        )+

        # Match the final exception line
        ^[a-zA-Z_][a-zA-Z0-9_.]*(?:\.[a-zA-Z_][a-zA-Z0-9_]*)*:.*$
    )
    |
    (?<java>
        # Match exception header(s)
        (?:^\S*?(?:Exception|Error)(?::\s*.*?)?$\n?)+

        # Match all stack trace components
        (?:
            # Stack frame: at package.Class.method(Source.java:123)
            (?:^\s*at\s+
                (?:[a-zA-Z_$][a-zA-Z0-9_$]*\.)*  # Package names
                [a-zA-Z_$][a-zA-Z0-9_$]*         # Class name
                (?:\.[a-zA-Z_$][a-zA-Z0-9_$]*)?  # Method name
                (?:\([^)]*\))?                    # Source info
                (?:\s*~\[[^\]]+\])?              # Module info
                (?:\s*@[a-fA-F0-9]+)?$\n?        # Memory address
            )
            |
            # Suppressed frames: ... N more
            (?:^\s*\.{3}\s*\d+\s+
                (?:more|common\s+frames?\s+omitted)$\n?
            )
            |
            # Caused by chain
            (?:^\s*Caused\s+by:\s*
                [a-zA-Z_$][a-zA-Z0-9_$.]*       # Exception class
                (?::\s*.*?)?$\n?                 # Optional message
            )
            |
            # Suppressed exceptions
            (?:^\s*Suppressed:\s*
                [a-zA-Z_$][a-zA-Z0-9_$.]*       # Exception class
                (?::\s*.*?)?$\n?                 # Optional message
            )
        )*
    )
"#,
    )
    .unwrap()
});

impl SourceLanguage {
    pub fn as_str(&self) -> &'static str {
        match self {
            SourceLanguage::Rust => "Rust",
            SourceLanguage::Java => "Java",
            SourceLanguage::Cpp => "C++",
            SourceLanguage::Python => "Python",
        }
    }

    fn from_extension(extension: &OsStr) -> Option<Self> {
        match extension.to_str() {
            Some("rs") => Some(Self::Rust),
            Some("java") => Some(Self::Java),
            Some("h" | "hh" | "hpp" | "hxx" | "tpp" | "cc" | "cpp" | "cxx") => Some(Self::Cpp),
            Some("py") => Some(Self::Python),
            None | Some(_) => None,
        }
    }

    fn from_path(path: &Path) -> Option<Self> {
        match path.extension() {
            Some(extension) => Self::from_extension(extension),
            // Some languages might have well-known file names without an extension
            None => None,
        }
    }

    fn get_query(&self) -> &str {
        match self {
            SourceLanguage::Rust => {
                // XXX: assumes it's a debug macro
                r#"
                    (macro_invocation macro: (_) @macro-name
                        (token_tree .
                            (string_literal) @log
                        )
                        (#not-any-of? @macro-name "format" "vec")
                    )
                "#
            }
            SourceLanguage::Java => {
                r#"
                    (method_invocation
                        object: (identifier) @object-name
                        name: (identifier) @method-name
                        arguments: [
                            (argument_list (template_expression
                                template_argument: (string_literal) @arguments))
                            (argument_list . (string_literal) @arguments)
                        ]
                        (#match? @object-name "log(ger)?|LOG(GER)?")
                        (#match? @method-name "fine|debug|info|warn|trace|error")
                    )
                "#
            }
            SourceLanguage::Cpp => {
                r#"
                    (
                        (compound_statement
                            (expression_statement
                                (call_expression
                                    function: (_) @fname
                                    arguments: (argument_list (string_literal) @arguments)
                                )
                            )
                        )
                        (#not-match? @fname "snprintf|sprintf")
                    )
                "#
            }
            SourceLanguage::Python => {
                r#"
                (
                    (expression_statement
                      (call
                        function: (_) @func
                        arguments: (argument_list .
                          (string) @args
                        )
                      )
                    )
                )
                "#
            }
        }
    }

    fn get_identifiers(&self) -> &[&str] {
        match self {
            SourceLanguage::Rust => IDENTS_RS,
            SourceLanguage::Java => IDENTS_JAVA,
            SourceLanguage::Cpp => IDENTS_CPP,
            SourceLanguage::Python => IDENTS_PYTHON,
        }
    }

    fn get_placeholder_regex(&self) -> &'static Regex {
        match self {
            SourceLanguage::Rust => RUST_PLACEHOLDER_REGEX.deref(),
            SourceLanguage::Java => JAVA_PLACEHOLDER_REGEX.deref(),
            SourceLanguage::Cpp => CPP_PLACEHOLDER_REGEX.deref(),
            SourceLanguage::Python => PYTHON_PLACEHOLDER_REGEX.deref(),
        }
    }

    fn captures_to_format_arg(&self, caps: &Captures) -> FormatArgument {
        for (index, cap) in caps.iter().skip(1).enumerate() {
            if let Some(cap) = cap {
                return match (self, index) {
                    (SourceLanguage::Rust | SourceLanguage::Java | SourceLanguage::Cpp, 0) => {
                        FormatArgument::Named(cap.as_str().to_string())
                    }
                    (SourceLanguage::Rust | SourceLanguage::Cpp, 1) => {
                        FormatArgument::Positional(cap.as_str().parse().unwrap())
                    }
                    _ => unreachable!(),
                };
            }
        }
        FormatArgument::Placeholder
    }
}

/// A variable expression and the value it held at the matched log call site.
#[derive(PartialEq, Clone, Debug, Serialize)]
pub struct VariablePair {
    pub expr: String,
    pub value: String,
}

/// The result of matching a log line to a source statement.
#[derive(Serialize)]
pub struct LogMapping<'a> {
    #[serde(rename(serialize = "logRef"))]
    pub log_ref: LogRef<'a>,
    #[serde(rename(serialize = "srcRef"))]
    pub src_ref: Option<SourceRef>,
    #[serde(skip_serializing_if = "Vec::is_empty")]
    #[serde(rename(serialize = "exceptionTrace"))]
    pub exception_trace: Vec<CallSite>,
    pub variables: Vec<VariablePair>,
}

/// A parsed log line, optionally with structured details extracted by a [`LogFormat`].
#[derive(Copy, Clone, Debug, PartialEq, Serialize)]
pub struct LogRef<'a> {
    #[serde(skip_serializing)]
    pub line: &'a str,
    #[serde(skip_serializing_if = "is_only_body")]
    pub details: Option<LogDetails<'a>>,
}

fn is_only_body(details: &Option<LogDetails>) -> bool {
    if let Some(details) = details {
        details.thread.is_none()
            && details.file.is_none()
            && details.lineno.is_none()
            && details.trace.is_none()
    } else {
        true
    }
}

static PYTHON_CALLER_REGEX: LazyLock<Regex> = LazyLock::new(|| {
    Regex::new(
        r#"(?smx)
    (?:
        ^\s+File\s+"(?<path>[^"]+)",\s+line\s+(?<line>\d+),\s+in\s+(?<name>[^\n]+)$\n?
    )
"#,
    )
    .unwrap()
});

static JAVA_CALLER_REGEX: LazyLock<Regex> = LazyLock::new(|| {
    Regex::new(
        r#"(?smx)
    (?:
        ^\s+at\s+(?<pkg>(?:[^.\n(]+\.)*)(?<class>[^.$\n(]+)\.(?<name>\S+)\((?<file>[^:]+):(?<line>\d+)\)\s*$\n?
    )
"#,
    )
        .unwrap()
});

/// An exception stack trace embedded in a log message body.
#[derive(Copy, Clone, Debug, PartialEq, Serialize)]
pub struct StackTrace<'a> {
    pub language: SourceLanguage,
    pub content: &'a str,
}

impl StackTrace<'_> {
    fn to_exception_trace(self, log_matcher: &LogMatcher) -> Vec<CallSite> {
        let mut retval = Vec::new();
        match self.language {
            SourceLanguage::Rust => {}
            SourceLanguage::Java => {
                for cap in JAVA_CALLER_REGEX.captures_iter(self.content) {
                    // The Java stack trace does not contain the full path to the source file.
                    // So, we need to construct a path from the package and class name.  Then,
                    // we use SourceHierTree::find_file() to find the actual path.
                    let path_for_pkg = cap
                        .name("pkg")
                        .map(|m| PathBuf::from(m.as_str().replace(".", "/")))
                        .unwrap_or_default();
                    let path_for_class = path_for_pkg.join(cap.name("file").unwrap().as_str());
                    let full_path = log_matcher
                        .roots
                        .values()
                        .filter_map(|root| {
                            if let Some((actual_path, _source_info)) =
                                root.tree.find_file(&path_for_class).first()
                            {
                                Some(actual_path.clone())
                            } else {
                                None
                            }
                        })
                        .next();
                    if let Some(full_path) = full_path {
                        retval.push(CallSite {
                            name: cap.name("name").unwrap().as_str().to_string(),
                            source_path: full_path.to_string_lossy().to_string(),
                            language: SourceLanguage::Java,
                            line_no: cap.name("line").unwrap().as_str().parse::<usize>().unwrap(),
                        });
                    }
                }
            }
            SourceLanguage::Cpp => {}
            SourceLanguage::Python => {
                for cap in PYTHON_CALLER_REGEX.captures_iter(self.content) {
                    retval.push(CallSite {
                        name: cap.name("name").unwrap().as_str().to_string(),
                        source_path: cap.name("path").unwrap().as_str().to_string(),
                        language: SourceLanguage::Python,
                        line_no: cap.name("line").unwrap().as_str().parse::<usize>().unwrap(),
                    });
                }
            }
        }
        retval
    }
}

/// Structured fields parsed from a log line by a [`LogFormat`].
#[derive(Copy, Clone, Debug, PartialEq, Serialize, Default)]
pub struct LogDetails<'a> {
    #[serde(skip_serializing_if = "Option::is_none")]
    pub thread: Option<&'a str>,
    #[serde(skip_serializing_if = "Option::is_none")]
    pub file: Option<&'a str>,
    #[serde(skip_serializing_if = "Option::is_none")]
    pub lineno: Option<usize>,
    #[serde(skip_serializing)]
    pub body: Option<&'a str>,
    #[serde(skip_serializing_if = "Option::is_none")]
    pub trace: Option<StackTrace<'a>>,
}

impl LogDetails<'_> {
    fn is_empty(&self) -> bool {
        self.thread.is_none()
            && self.file.is_none()
            && self.lineno.is_none()
            && self.body.is_none()
            && self.trace.is_none()
    }
}

/// Builder for [`LogRef`]. Use [`LogRefBuilder::build`] or [`LogRefBuilder::build_from_captures`] to construct one.
pub struct LogRefBuilder<'a> {
    details: LogDetails<'a>,
}

impl Default for LogRefBuilder<'_> {
    fn default() -> Self {
        LogRefBuilder::new()
    }
}

impl<'a> LogRefBuilder<'a> {
    pub fn new() -> Self {
        Self {
            details: Default::default(),
        }
    }

    pub fn build_from_captures(self, captures: Captures<'a>, content: &'a str) -> LogRef<'a> {
        self.with_file(captures.name("file").map(|m| m.as_str()))
            .with_lineno(
                captures
                    .name("line")
                    .map(|m| m.as_str().parse::<usize>().unwrap_or_default()),
            )
            .with_thread(captures.name("thread").map(|m| m.as_str()))
            .with_body(captures.name("body").map(|m| m.as_str()))
            .build(content)
    }

    pub fn with_thread(mut self, thread: Option<&'a str>) -> Self {
        self.details.thread = thread;
        self
    }
    pub fn with_file(mut self, file: Option<&'a str>) -> Self {
        self.details.file = file;
        self
    }
    pub fn with_lineno(mut self, lineno: Option<usize>) -> Self {
        self.details.lineno = lineno;
        self
    }

    pub fn with_body(mut self, body: Option<&'a str>) -> Self {
        let (body, trace) = if let Some(body) = body {
            if let Some(trace) = BACKTRACE_REGEX.captures(body) {
                let language = if trace.name("python").is_some() {
                    SourceLanguage::Python
                } else if trace.name("java").is_some() {
                    SourceLanguage::Java
                } else {
                    unreachable!();
                };
                let cap0 = trace.get(0).unwrap();
                (
                    Some(body[0..cap0.range().start].trim_end()),
                    Some(StackTrace {
                        language,
                        content: cap0.as_str(),
                    }),
                )
            } else {
                (Some(body), None)
            }
        } else {
            (None, None)
        };
        self.details.body = body;
        self.details.trace = trace;
        self
    }

    pub fn build(self, line: &'a str) -> LogRef<'a> {
        let details = if self.details.is_empty() {
            None
        } else {
            Some(self.details)
        };
        LogRef { line, details }
    }
}

impl<'a> LogRef<'a> {
    pub fn body(self) -> &'a str {
        if let Some(LogDetails { body: Some(s), .. }) = self.details {
            s
        } else {
            self.line
        }
    }
}

/// Extract variable name/value pairs by matching the log line against the source statement's pattern.
pub fn extract_variables<'a>(log_ref: &LogRef<'a>, src_ref: &'a SourceRef) -> Vec<VariablePair> {
    let mut variables = Vec::new();
    let line = match log_ref.details {
        Some(details) => details.body.unwrap_or(log_ref.line),
        None => log_ref.line,
    };
    if let Some(captures) = src_ref.captures(line) {
        let mut placeholder_index = 0;
        for (cap, placeholder) in std::iter::zip(captures.iter().skip(1), src_ref.args.iter()) {
            let expr = match placeholder {
                FormatArgument::Named(name) => name.clone(),
                FormatArgument::Positional(pos) => src_ref
                    .vars
                    .get(*pos)
                    .map(|s| s.as_str())
                    .unwrap_or("<unknown>")
                    .to_string(),
                FormatArgument::Placeholder => {
                    let res = src_ref.vars[placeholder_index].to_string();

                    placeholder_index += 1;
                    res
                }
            };
            variables.push(VariablePair {
                expr,
                value: cap.unwrap().as_str().to_string(),
            });
        }
    }

    variables
}

fn extract_logging_guarded(sources: &[CodeSource], guard: &WorkGuard) -> Vec<StatementsInFile> {
    sources
        .par_iter()
        .flat_map(|code| {
            let mut matched = vec![];
            let src_query = SourceQuery::new(code);
            let query = code.info.language.get_query();
            let results = src_query.query(query, None);
            for result in results {
                // println!("node.kind()={:?} range={:?}", result.kind, result.range);
                match result.kind.as_str() {
                    "string_literal" | "string" => {
                        if let Some(src_ref) = SourceRef::new(code, result) {
                            matched.push(src_ref);
                        }
                    }
                    "args" | "this" if !matched.is_empty() => {
                        let range = result.range;
                        let source = code.buffer.as_str();
                        let text = source[range.start_byte..range.end_byte].to_string();
                        // eprintln!("text={} matched.len()={}", text, matched.len());
                        // check the text doesn't match any of the logging related identifiers
                        if code
                            .info
                            .language
                            .get_identifiers()
                            .iter()
                            .all(|&s| s != text.to_lowercase())
                        {
                            let length = matched.len() - 1;
                            let prior_result: &mut SourceRef = matched.get_mut(length).unwrap();
                            prior_result.end_line_no = result.range.end_point.row + 1;
                            prior_result.vars.push(text.trim().to_string());
                        }
                    }
                    _ => {} // eprintln!("ignoring {}", result.kind),
                }
                // println!("*****");
            }
            guard.inc(1);
            if matched.is_empty() {
                None
            } else {
                let mut sif = StatementsInFile {
                    path: matched.first().unwrap().source_path.clone(),
                    id: code.info.id,
                    log_statements: matched,
                    matcher: None,
                };
                sif.try_creating_matcher();
                Some(sif)
            }
        })
        .collect()
}

#[cfg(test)]
mod tests {
    use super::*;
    use insta::{assert_snapshot, assert_yaml_snapshot};

    fn extract_logging(sources: &[CodeSource]) -> Vec<StatementsInFile> {
        let tracker = current_global_progress_tracker();
        let guard = tracker.doing_work(sources.len() as u64, "files".to_string());
        extract_logging_guarded(sources, &guard)
    }

    fn from_log_format_and_line(buffer: &'_ str, log_format: LogFormat) -> LogRef<'_> {
        let captures = log_format.captures(buffer).unwrap();
        LogRefBuilder::new().build_from_captures(captures, buffer)
    }

    #[test]
    fn test_log_ref_builder() {
        let buffer = String::from(
            "2025-04-10 22:12:52 INFO  JvmPauseMonitor:146 - JvmPauseMonitor-n0: Started",
        );
        let regex = r"^(?<timestamp>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}) (?<level>\w+)\s+ (?<file>[\w$.]+):(?<line>\d+) - (?<body>.*)$";
        let log_format: LogFormat = regex.try_into().unwrap();
        let captures = log_format.captures(&buffer).unwrap();
        let result = LogRefBuilder::new().build_from_captures(captures, &buffer);
        let details = Some(LogDetails {
            thread: None,
            file: Some("JvmPauseMonitor"),
            lineno: Some(146),
            body: Some("JvmPauseMonitor-n0: Started"),
            trace: None,
        });
        assert_eq!(
            result,
            LogRef {
                line: "2025-04-10 22:12:52 INFO  JvmPauseMonitor:146 - JvmPauseMonitor-n0: Started",
                details
            }
        );
    }

    const TEST_SOURCE: &str = r#"
#[macro_use]
extern crate log;

fn main() {
    env_logger::init();
    debug!("you're only as funky as your last cut");
    for i in 0..3 {
        foo(i);
    }
}

fn foo(i: u32) {
    nope(i);
}

fn nope(i: u32, j: i32) {
    log::debug!("this won't match i={}; j={}", i, j);
}

fn namedarg0(salutation: &str, name: &str) {
    debug!("{salutation}, {name}!"); // lower quality than the next one
}

fn namedarg(name: &str) {
    let msg = format!("Goodbye, {name}!");
    debug!("Hello, {name}!");
}

fn namedarg2(salutation: &str, name: &str) {
    debug!("{salutation}, {name}!"); // lower quality than the previous one
}
    "#;

    #[test]
    fn test_extract_logging() {
        let code = CodeSource::from_string(Path::new("in-mem.rs"), TEST_SOURCE);
        let src_refs = extract_logging(&[code]).pop().unwrap().log_statements;
        assert_yaml_snapshot!(src_refs);
    }

    #[test]
    fn test_extract_variables() {
        let log_ref = LogRefBuilder::new().build("this won't match i=1; j=2");
        let code = CodeSource::from_string(Path::new("in-mem.rs"), TEST_SOURCE);
        let src_refs = extract_logging(&[code]).pop().unwrap().log_statements;
        assert_eq!(src_refs.len(), 5);
        let vars = extract_variables(&log_ref, &src_refs[1]);
        assert_eq!(
            vars,
            vec![
                VariablePair {
                    expr: "i".to_string(),
                    value: "1".to_string()
                },
                VariablePair {
                    expr: "j".to_string(),
                    value: "2".to_string()
                }
            ]
        );
    }

    #[test]
    fn test_extract_named() {
        let log_ref = LogRefBuilder::new().build("Hello, Tim!");
        let code = CodeSource::from_string(Path::new("in-mem.rs"), TEST_SOURCE);
        let src_refs = extract_logging(&[code]).pop().unwrap().log_statements;
        assert_eq!(src_refs.len(), 5);
        let vars = extract_variables(&log_ref, &src_refs[3]);
        assert_eq!(
            vars,
            vec![VariablePair {
                expr: "name".to_string(),
                value: "Tim".to_string()
            },]
        );
    }

    const TEST_PUNC_SRC: &str = r#"""
  private void run() {
    LOG.info("{}: Started", this);
    try {
      for (; Thread.currentThread().equals(threadRef.get()); ) {
        detectPause();
      }
    } finally {
      LOG.info("{}: Stopped", this);
    }
  }
"""#;
    #[test]
    fn test_extract_var_punctuation() {
        let lf =
            r"^(?<timestamp>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}) (?<level>\w+)\s+ (?<file>[\w$.]+):(?<line>\d+) - (?<body>.*)$".try_into().unwrap();
        let log_ref = from_log_format_and_line(
            "2025-04-10 22:12:52 INFO  JvmPauseMonitor:146 - JvmPauseMonitor-n0: Started",
            lf,
        );
        let code = CodeSource::from_string(&PathBuf::from("in-mem.java"), TEST_PUNC_SRC);
        let src_refs = extract_logging(&[code]).pop().unwrap().log_statements;
        assert_eq!(src_refs.len(), 2);
        let vars = extract_variables(&log_ref, &src_refs[0]);
        assert_eq!(
            vars,
            vec![VariablePair {
                expr: "this".to_string(),
                value: "JvmPauseMonitor-n0".to_string()
            },]
        );
    }

    const CPP_SOURCE: &str = r#"
    #include <stdio.h>

    int main(int argc, char* argv[]) {
        printf("Hello, %s!", argv[1]);
    }
    "#;

    #[test]
    fn test_basic_cpp() {
        let log_ref = LogRefBuilder::new().build("Hello, Steve!");
        let code = CodeSource::from_string(Path::new("in-mem.cc"), CPP_SOURCE);
        let src_refs = extract_logging(&[code]).pop().unwrap().log_statements;
        assert_eq!(src_refs.len(), 1);
        let vars = extract_variables(&log_ref, &src_refs[0]);
        assert_eq!(
            vars,
            vec![VariablePair {
                expr: "argv[1]".to_string(),
                value: "Steve".to_string()
            },]
        );
    }

    const PYTHON_SOURCE: &str = r#"
def main(args):
    logger.info("foo %s \N{greek small letter pi}", test_var)
    logging.info(f'Hello, {args[1]}!')
    logger.warning(f"warning message:\nlow disk space")
    logger.info(rf"""info message:
processing \started -- {args[0]}""")
"#;

    #[test]
    fn test_basic_python() {
        let log_ref = LogRefBuilder::new().build("foo bar π");
        let code = CodeSource::from_string(Path::new("in-mem.py"), PYTHON_SOURCE);
        let src_refs = extract_logging(&[code]).pop().unwrap().log_statements;
        assert_yaml_snapshot!(src_refs);
        let vars = extract_variables(&log_ref, &src_refs[0]);
        assert_eq!(
            vars,
            vec![VariablePair {
                expr: "test_var".to_string(),
                value: "bar".to_string()
            },]
        );
    }

    const TRACE: &str = r#"JvmPauseMonitor-n0: Started
java.lang.IllegalStateException: simulated failure for demo
    at org.example.Main.simulateError(Main.java:50)
    at org.example.Main.main(Main.java:41)
    at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)
    at java.base/java.lang.Thread.run(Thread.java:1447)
"#;

    #[test]
    fn test_backtrace_re() {
        let code = CodeSource::from_string(&PathBuf::from("in-mem.java"), TEST_PUNC_SRC);
        let log_ref = LogRefBuilder::new().with_body(Some(TRACE)).build(TRACE);
        assert_snapshot!(log_ref.line);
        assert_yaml_snapshot!(log_ref);
        let src_refs = extract_logging(&[code]).pop().unwrap().log_statements;
        assert_yaml_snapshot!(src_refs);
        let vars = extract_variables(&log_ref, &src_refs[0]);
        assert_yaml_snapshot!(vars);
    }

    const PYTHON_TRACE: &str = r#"\
Traceback (most recent call last):
  File "python-logging-example/python_logging_example/__main__.py", line 26, in main
    helper.fail_now()
    ~~~~~~~~~~~~~~~^^
  File "python-logging-example/python_logging_example/helper.py", line 3, in fail_now
    return 1 / 0
           ~~^~~
ZeroDivisionError: division by zero
"#;

    #[test]
    fn test_python_trace() {
        let stacktrace = StackTrace {
            language: SourceLanguage::Python,
            content: PYTHON_TRACE,
        };

        let log_matcher = LogMatcher::new();
        let trace = stacktrace.to_exception_trace(&log_matcher);
        assert_yaml_snapshot!(trace);
    }

    #[test]
    fn test_extract_log_statements_missing_file() {
        let temp_dir = tempfile::tempdir().unwrap();
        let root = temp_dir.path();

        let source_path = root.join("main.rs");
        std::fs::write(&source_path, r#"fn main() { debug!("hello"); }"#).unwrap();

        let mut log_matcher = LogMatcher::new();
        log_matcher.add_root(root).unwrap();

        let _ = log_matcher.discover_sources();

        std::fs::remove_file(&source_path).unwrap();
        let summary = log_matcher.extract_log_statements();
        assert_eq!(summary.errors.len(), 1);
        assert!(matches!(
            &summary.errors[0],
            LogError::CannotReadSourceFile { path, source }
            if path.file_name() == Some(std::ffi::OsStr::new("main.rs"))
                && source.kind() == io::ErrorKind::NotFound
        ));
    }

    #[test]
    fn test_extract_log_statements_nonutf8() {
        let temp_dir = tempfile::tempdir().unwrap();
        let root = temp_dir.path();

        let source_path = root.join("main.rs");
        let invalid_utf8 = [0xff, 0xfe, 0xfd];
        std::fs::write(&source_path, invalid_utf8).unwrap();

        let mut log_matcher = LogMatcher::new();
        log_matcher.add_root(root).unwrap();

        let _ = log_matcher.discover_sources();
        let summary = log_matcher.extract_log_statements();
        assert_eq!(summary.errors.len(), 1);
        assert!(matches!(
            &summary.errors[0],
            LogError::CannotReadSourceFile { path, source }
            if path.file_name() == Some(std::ffi::OsStr::new("main.rs"))
                && source.kind() == io::ErrorKind::InvalidData
        ));
    }
}