KiCad - the KiCad Bridge

//! KiCad's own diagnostics, ported from handlers/kicad_log.py.
//!
//! KiCad writes NO log file. Its diagnostics go through wxLog to stderr, and a GUI
//! process on Windows has no console, so stderr goes to the void unless whoever
//! launched it supplies a handle. The Python bridge's launch verb captures that stream
//! into one file per launch under `<LOCALAPPDATA or ~/.local/share>/Adom Bridge/kicad-logs/`
//! with `KICAD_ENABLE_WXTRACE=1` set, and `kicad_log_tail` returns only what is NEW
//! since a byte offset the caller carries.
//!
//! The native bridge has no launch verb yet, so this module reads the same directory
//! the Python writes (a Python-launched KiCad on the same box still lands here) and
//! says so honestly when nothing is there. `new_log_path` and `trace_env` are ready
//! for the phase 3 launch verb.
//!
//! The dialog channel (`kicad_errors`): measured on KiCad 10, a board that fails to
//! parse produces a "KiCad PCB Editor Error" window with the exact reason while the
//! captured stderr for that launch is ZERO BYTES, because wxLogGui turns wxLogError
//! into a message box. So the dialogs ARE the log. The window walk is OS work (phase
//! 3); the classification of what it finds is pure and lives here as `dialog_entries`.

use std::path::{Path, PathBuf};

use serde_json::{json, Value};

/// One directory, one file per launch, newest wins.
pub const LOG_DIR_NAME: &str = "kicad-logs";
/// How many launch logs to keep (Python `_KEEP_LOGS`).
pub const KEEP_LOGS: usize = 10;

fn home() -> Option<PathBuf> {
    std::env::var_os("HOME").or_else(|| std::env::var_os("USERPROFILE")).map(PathBuf::from)
}

/// `<LOCALAPPDATA>/Adom Bridge/kicad-logs`, or `~/.local/share/Adom Bridge/kicad-logs`
/// where LOCALAPPDATA is unset (Python `log_dir`, without the mkdir: reading is read-only).
pub fn log_dir() -> Option<PathBuf> {
    let base = std::env::var_os("LOCALAPPDATA").map(PathBuf::from).or_else(|| home().map(|h| h.join(".local/share")))?;
    Some(base.join("Adom Bridge").join(LOG_DIR_NAME))
}

/// `~/.adom/bridge-logs/kicad.log`: the bridge's OWN stdout/stderr as ab captures it
/// (ab 2.0.44+). Not KiCad's output; reported so a caller knows where the second file is.
pub fn bridge_log_path() -> Option<PathBuf> {
    home().map(|h| h.join(".adom").join("bridge-logs").join("kicad.log"))
}

/// `*.log` files in a directory, newest mtime first.
fn logs_by_mtime(dir: &Path) -> Vec<PathBuf> {
    let Ok(rd) = std::fs::read_dir(dir) else {
        return Vec::new();
    };
    let mut logs: Vec<(std::time::SystemTime, PathBuf)> = rd
        .flatten()
        .map(|e| e.path())
        .filter(|p| p.is_file() && p.extension().map(|x| x == "log").unwrap_or(false))
        .filter_map(|p| std::fs::metadata(&p).and_then(|m| m.modified()).ok().map(|t| (t, p)))
        .collect();
    logs.sort_by(|a, b| b.0.cmp(&a.0).then_with(|| b.1.cmp(&a.1)));
    logs.into_iter().map(|(_, p)| p).collect()
}

/// The newest launch log in a directory (Python `latest_log`).
pub fn latest_log(dir: &Path) -> Option<PathBuf> {
    logs_by_mtime(dir).into_iter().next()
}

/// A fresh per-launch log path `<dir>/<YYYYmmdd-HHMMSS>-<tag>.log`, pruning old logs so
/// the directory never holds more than KEEP_LOGS (Python `new_log_path`). Creates the
/// directory. `stamp` is the local-time stamp the caller formats (kept out of here so
/// tests are deterministic and no time-zone crate is needed).
pub fn new_log_path(dir: &Path, stamp: &str, tag: &str) -> std::io::Result<PathBuf> {
    std::fs::create_dir_all(dir)?;
    for old in logs_by_mtime(dir).into_iter().skip(KEEP_LOGS - 1) {
        let _ = std::fs::remove_file(old);
    }
    let mut safe = String::new();
    let mut last_dash = false;
    for ch in tag.chars() {
        if ch.is_ascii_alphanumeric() || ch == '_' || ch == '.' || ch == '-' {
            safe.push(ch);
            last_dash = false;
        } else if !last_dash {
            safe.push('-');
            last_dash = true;
        }
    }
    let safe: String = safe.chars().take(40).collect();
    let safe = if safe.is_empty() { "kicad".to_string() } else { safe };
    Ok(dir.join(format!("{stamp}-{safe}.log")))
}

/// Environment additions that make KiCad actually say something (Python `trace_env`):
/// `KICAD_ENABLE_WXTRACE=1` always; `WXTRACE=<masks>` only when the caller wants the
/// firehose. Errors and warnings arrive without any mask once logging is enabled.
pub fn trace_env(masks: Option<&str>) -> Vec<(String, String)> {
    let mut v = vec![("KICAD_ENABLE_WXTRACE".to_string(), "1".to_string())];
    if let Some(m) = masks.filter(|m| !m.is_empty()) {
        v.push(("WXTRACE".to_string(), m.to_string()));
    }
    v
}

const LEVEL_WORDS: [&str; 6] = ["error", "warning", "trace", "info", "debug", "fatal"];

/// Python `_classify`: an explicit `Error:`/`Warning ` prefix wins; otherwise keyword
/// sniffing; otherwise "info".
pub fn classify(line: &str) -> &'static str {
    let t = line.trim_start();
    let low = t.to_ascii_lowercase();
    for w in LEVEL_WORDS {
        if let Some(rest) = low.strip_prefix(w) {
            if rest.starts_with(':') || rest.starts_with(' ') {
                return w;
            }
        }
    }
    let low = line.to_lowercase();
    if low.contains("error") || low.contains("failed") || low.contains("cannot") || low.contains("unable to") {
        return "error";
    }
    if low.contains("warning") || low.contains("deprecat") {
        return "warning";
    }
    "info"
}

const NO_LOG_HINT: &str = "No KiCad log yet. Logs exist only for KiCad instances a bridge launched with stderr captured (Python bridge 0.9.266+; the native bridge has no launch verb yet, so it reads what the Python bridge wrote). A KiCad the user started themselves writes nothing, because its stderr belongs to whoever launched it.";

/// kicad_log_tail (Python `handle_log_tail`): new output since a byte offset, read-only.
/// Args: sinceOffset (default 0), maxBytes (default 200000, newest kept), errorsOnly,
/// path (explicit file; default the newest launch log in `dir`).
pub fn log_tail(dir: Option<&Path>, args: &Value) -> Value {
    let explicit = args.get("path").and_then(Value::as_str).map(str::trim).filter(|s| !s.is_empty()).map(PathBuf::from);
    let p = explicit.or_else(|| dir.and_then(latest_log));
    let bridge_log = bridge_log_path().filter(|p| p.is_file()).map(|p| p.to_string_lossy().replace('\\', "/"));
    let Some(p) = p.filter(|p| p.is_file()) else {
        return json!({
            "success": true, "available": false, "lines": [], "nextOffset": 0, "entries": [], "next": 0,
            "logDir": dir.map(|d| d.to_string_lossy().replace('\\', "/")),
            "bridgeLogPath": bridge_log,
            "_hint": NO_LOG_HINT,
        });
    };
    let since_raw = int_arg(args, "sinceOffset").unwrap_or(0);
    let max_bytes = int_arg(args, "maxBytes").filter(|v| *v > 0).unwrap_or(200_000) as usize;
    let size = std::fs::metadata(&p).map(|m| m.len()).unwrap_or(0);
    let mut since = since_raw.max(0) as u64;
    if since > size {
        since = 0; // file rotated or truncated under us
    }
    let blob = match std::fs::read(&p) {
        Ok(b) => b,
        Err(e) => {
            return json!({"success": false, "errorCode": "log_unreadable", "error": format!("{}: {e}", p.display()),
                "_hint": "The log exists but cannot be read; check permissions."});
        }
    };
    let mut blob = &blob[(since as usize).min(blob.len())..];
    let truncated = blob.len() > max_bytes;
    if truncated {
        blob = &blob[blob.len() - max_bytes..];
    }
    let text = String::from_utf8_lossy(blob);
    let errors_only = args.get("errorsOnly").and_then(Value::as_bool).unwrap_or(false);
    let mut counts: serde_json::Map<String, Value> = serde_json::Map::new();
    let mut lines: Vec<Value> = Vec::new();
    for ln in text.lines().filter(|l| !l.trim().is_empty()) {
        let level = classify(ln);
        if errors_only && !matches!(level, "error" | "warning" | "fatal") {
            continue;
        }
        let n = counts.get(level).and_then(Value::as_u64).unwrap_or(0);
        counts.insert(level.into(), json!(n + 1));
        lines.push(json!({"level": level, "text": ln}));
    }
    json!({
        "success": true, "available": true,
        "logPath": p.to_string_lossy().replace('\\', "/"),
        "sinceOffset": since, "nextOffset": size, "truncated": truncated,
        "lineCount": lines.len(), "levels": counts, "lines": lines,
        // the standard's log_tail (#29): entries and next, the same lines and offset
        "entries": lines, "next": size,
        "bridgeLogPath": bridge_log,
        "_hint": "Carry nextOffset into the next call and you get ONLY what happened since: tail, act, tail again, and the second read is your action's consequences. errorsOnly:true filters to error/warning.",
    })
}

/// Python `int(args.get(k) or 0)`: numbers, numeric strings; None otherwise.
fn int_arg(args: &Value, key: &str) -> Option<i64> {
    match args.get(key)? {
        Value::Number(n) => n.as_i64().or_else(|| n.as_f64().map(|f| f as i64)),
        Value::String(s) => s.trim().parse::<i64>().ok(),
        Value::Bool(b) => Some(*b as i64),
        _ => None,
    }
}

/// Python `_ERR_TITLE`: `\b(error|warning|problem|failed|cannot)\b`, case-insensitive.
pub fn is_error_title(title: &str) -> bool {
    ["error", "warning", "problem", "failed", "cannot"].iter().any(|w| contains_word(title, w))
}

fn is_word(c: char) -> bool {
    c.is_alphanumeric() || c == '_'
}

fn contains_word(hay: &str, word: &str) -> bool {
    let low = hay.to_lowercase();
    let chars: Vec<char> = low.chars().collect();
    let w: Vec<char> = word.chars().collect();
    if w.is_empty() || chars.len() < w.len() {
        return false;
    }
    for i in 0..=chars.len() - w.len() {
        if chars[i..i + w.len()] == w[..] {
            let before_ok = i == 0 || !is_word(chars[i - 1]);
            let after_ok = i + w.len() == chars.len() || !is_word(chars[i + w.len()]);
            if before_ok && after_ok {
                return true;
            }
        }
    }
    false
}

/// One KiCad-owned top-level window as the OS layer will report it: handle, caption,
/// every text-bearing child (win32 GetWindowText, buttons excluded), and the UIA text
/// harvested when the children carried nothing (Windows TaskDialogs draw their text in
/// DirectUI with no per-string child controls).
#[derive(Clone, Debug, Default)]
pub struct DialogRow {
    pub hwnd: u64,
    pub title: String,
    pub texts: Vec<String>,
    pub uia_text: Option<String>,
}

/// Python `handle_errors` loop: which windows count, and each one's entry. The message
/// is the longest text (buttons are short); a window with no readable text says how to
/// read it. Read-only by construction: nothing is clicked, raised or screenshotted.
pub fn dialog_entries(rows: &[DialogRow], include_all: bool) -> Vec<Value> {
    let mut out = Vec::new();
    for row in rows {
        let title = row.title.trim();
        if title.is_empty() {
            continue;
        }
        let errorish = is_error_title(title);
        if !include_all && !errorish {
            continue;
        }
        let mut msg = row.texts.iter().max_by_key(|t| t.len()).cloned().unwrap_or_default();
        let mut via = "win32";
        if msg.is_empty() {
            if let Some(u) = row.uia_text.as_deref().filter(|u| !u.is_empty()) {
                msg = u.to_string();
                via = "uia";
            }
        }
        let mut entry = json!({
            "hwnd": row.hwnd,
            "title": title,
            "message": msg,
            "messageVia": if msg.is_empty() { Value::Null } else { json!(via) },
            "allText": row.texts.iter().take(12).collect::<Vec<_>>(),
            "level": if errorish { "error" } else { "info" },
        });
        if msg.is_empty() {
            entry["messageUnavailable"] = json!("taskdialog_directui_and_uia_unavailable");
            entry["readTextWith"] = json!(format!("desktop_ui_tree {{\"hwnd\":{},\"maxDepth\":8}}: read it IMMEDIATELY; these dialogs are transient", row.hwnd));
        }
        out.push(entry);
    }
    out
}

pub const ERRORS_HINT: &str = "KiCad has NO log file and in GUI mode its errors go to DIALOGS, not stderr, so this is where a GUI failure reason lives. Read-only: nothing is clicked or raised. THREE channels, use all three: (1) this verb; (2) kicad_log_tail for what bypasses wxLog (crashes, asserts, stdio); (3) kicad_screenshot_all when the first two say nothing and the result is still wrong: the pixels have no preconditions and remain the floor under any automation loop. Dismiss with kicad_dismiss_dialogs (which DOES foreground, so caption first).";

/// kicad_errors response in the Python shape: count, dialogs, windowSource, _hint.
pub fn errors(rows: &[DialogRow], include_all: bool, window_source: &str) -> Value {
    let dialogs = dialog_entries(rows, include_all);
    json!({"success": true, "count": dialogs.len(), "dialogs": dialogs, "windowSource": window_source, "_hint": ERRORS_HINT})
}

#[cfg(test)]
mod tests {
    use super::*;

    struct Tmp(PathBuf);
    impl Drop for Tmp {
        fn drop(&mut self) {
            let _ = std::fs::remove_dir_all(&self.0);
        }
    }
    fn tmp(name: &str) -> Tmp {
        let p = std::env::temp_dir().join(format!("kicad-core-log-{}-{name}", std::process::id()));
        let _ = std::fs::remove_dir_all(&p);
        std::fs::create_dir_all(&p).unwrap();
        Tmp(p)
    }

    #[test]
    fn classify_matches_python() {
        assert_eq!(classify("Error: cannot open"), "error");
        assert_eq!(classify("  warning something"), "warning");
        assert_eq!(classify("Trace: KICAD_LIBRARIES foo"), "trace");
        assert_eq!(classify("Fatal: boom"), "fatal");
        assert_eq!(classify("Errors: 3"), "error"); // prefix miss (no boundary), keyword hit
        assert_eq!(classify("Information only"), "info"); // 'Info' + 'r' is no boundary
        assert_eq!(classify("Failed to load board"), "error");
        assert_eq!(classify("Unable to resolve ${KIPRJMOD}"), "error");
        assert_eq!(classify("this API is deprecated"), "warning");
        assert_eq!(classify("loaded 12 footprints"), "info");
    }

    #[test]
    fn error_title_word_boundaries() {
        assert!(is_error_title("KiCad PCB Editor Error"));
        assert!(is_error_title("Warning"));
        assert!(is_error_title("Load failed: x"));
        assert!(is_error_title("Cannot open file"));
        assert!(!is_error_title("Errors and Warnings panel")); // plural: no boundary
        assert!(!is_error_title("KiCad 10.0 [demo/demo.kicad_pcb]"));
        assert!(!is_error_title("Problematic"));
    }

    #[test]
    fn tail_absent_is_honest() {
        let t = tmp("absent");
        let r = log_tail(Some(&t.0), &json!({}));
        assert_eq!(r["success"], json!(true));
        assert_eq!(r["available"], json!(false));
        assert_eq!(r["lines"], json!([]));
        assert_eq!(r["nextOffset"], json!(0));
        assert!(r["_hint"].as_str().unwrap().contains("No KiCad log yet"));
        let r = log_tail(None, &json!({}));
        assert_eq!(r["available"], json!(false));
        let r = log_tail(Some(&t.0), &json!({"path": t.0.join("nope.log").to_string_lossy()}));
        assert_eq!(r["available"], json!(false));
    }

    #[test]
    fn tail_offsets_filters_and_truncation() {
        let t = tmp("tail");
        let p = t.0.join("20260911-120000-launch.log");
        std::fs::write(&p, "Info: start\n\nError: cannot load board\nplain line\nWarning: deprecated thing\n").unwrap();
        let size = std::fs::metadata(&p).unwrap().len();

        let r = log_tail(Some(&t.0), &json!({}));
        assert_eq!(r["available"], json!(true));
        assert_eq!(r["logPath"], json!(p.to_string_lossy().replace('\\', "/")));
        assert_eq!(r["sinceOffset"], json!(0));
        assert_eq!(r["nextOffset"], json!(size));
        assert_eq!(r["truncated"], json!(false));
        assert_eq!(r["lineCount"], json!(4));
        assert_eq!(r["levels"], json!({"info": 2, "error": 1, "warning": 1}));
        assert_eq!(r["lines"][1], json!({"level": "error", "text": "Error: cannot load board"}));

        // Second read from nextOffset returns nothing new.
        let r2 = log_tail(Some(&t.0), &json!({"sinceOffset": size}));
        assert_eq!(r2["lineCount"], json!(0));
        assert_eq!(r2["sinceOffset"], json!(size));

        // Append, tail again: only the new line.
        let mut f = std::fs::OpenOptions::new().append(true).open(&p).unwrap();
        std::io::Write::write_all(&mut f, b"Fatal: crash\n").unwrap();
        let r3 = log_tail(Some(&t.0), &json!({"sinceOffset": size.to_string()}));
        assert_eq!(r3["lineCount"], json!(1));
        assert_eq!(r3["lines"][0]["level"], json!("fatal"));
        assert_eq!(r3["nextOffset"], json!(size + 13));

        // errorsOnly keeps error/warning/fatal.
        let r4 = log_tail(Some(&t.0), &json!({"errorsOnly": true}));
        assert_eq!(r4["lineCount"], json!(3));
        assert_eq!(r4["levels"], json!({"error": 1, "warning": 1, "fatal": 1}));

        // Offset past the end (rotation): whole file again.
        let r5 = log_tail(Some(&t.0), &json!({"sinceOffset": 999999}));
        assert_eq!(r5["sinceOffset"], json!(0));
        assert_eq!(r5["lineCount"], json!(5));

        // maxBytes keeps the newest bytes and flags truncation.
        let r6 = log_tail(Some(&t.0), &json!({"maxBytes": 13}));
        assert_eq!(r6["truncated"], json!(true));
        assert_eq!(r6["lineCount"], json!(1));
        assert_eq!(r6["lines"][0]["text"], json!("Fatal: crash"));
        assert_eq!(r6["nextOffset"], json!(size + 13));

        // Explicit path wins over the newest file.
        let other = t.0.join("00000000-000000-other.log");
        std::fs::write(&other, "Warning: only me\n").unwrap();
        let r7 = log_tail(Some(&t.0), &json!({"path": other.to_string_lossy()}));
        assert_eq!(r7["lineCount"], json!(1));
        assert_eq!(r7["logPath"], json!(other.to_string_lossy().replace('\\', "/")));
    }

    #[test]
    fn latest_log_and_prune() {
        let t = tmp("prune");
        for i in 0..12 {
            let p = t.0.join(format!("20260911-0000{i:02}-launch.log"));
            std::fs::write(&p, "x").unwrap();
            let when = std::time::SystemTime::UNIX_EPOCH + std::time::Duration::from_secs(1_700_000_000 + i * 60);
            let f = std::fs::File::open(&p).unwrap();
            f.set_modified(when).unwrap();
        }
        std::fs::write(t.0.join("notes.txt"), "not a log").unwrap();
        assert_eq!(latest_log(&t.0).unwrap().file_name().unwrap().to_string_lossy(), "20260911-000011-launch.log");
        let p = new_log_path(&t.0, "20260911-130000", "launch demo/proj.kicad_pcb!!").unwrap();
        assert_eq!(p.file_name().unwrap().to_string_lossy(), "20260911-130000-launch-demo-proj.kicad_pcb-.log");
        let left = logs_by_mtime(&t.0);
        assert_eq!(left.len(), KEEP_LOGS - 1);
        assert!(t.0.join("20260911-000011-launch.log").exists());
        assert!(!t.0.join("20260911-000000-launch.log").exists());
        assert!(t.0.join("notes.txt").exists());
        assert_eq!(new_log_path(&t.0, "s", "").unwrap().file_name().unwrap().to_string_lossy(), "s-kicad.log");
        assert!(latest_log(&t.0.join("missing")).is_none());
    }

    #[test]
    fn trace_env_shape() {
        assert_eq!(trace_env(None), vec![("KICAD_ENABLE_WXTRACE".to_string(), "1".to_string())]);
        assert_eq!(trace_env(Some("KICAD_LIBRARIES,KICAD_ENV_VARS")).len(), 2);
        assert_eq!(trace_env(Some("")).len(), 1);
    }

    #[test]
    fn dialog_entries_match_python() {
        let rows = vec![
            DialogRow { hwnd: 1, title: "KiCad PCB Editor Error".into(), texts: vec!["OK".into(), "Error loading PCB 'x'.\nExpecting thru_hole".into()], uia_text: None },
            DialogRow { hwnd: 2, title: "KiCad 10.0 [demo]".into(), texts: vec!["Status".into()], uia_text: None },
            DialogRow { hwnd: 3, title: "Warning".into(), texts: vec![], uia_text: Some("Zone fill is out of date".into()) },
            DialogRow { hwnd: 4, title: "Problem".into(), texts: vec![], uia_text: None },
            DialogRow { hwnd: 5, title: "   ".into(), texts: vec!["ignored".into()], uia_text: None },
        ];
        let d = dialog_entries(&rows, false);
        assert_eq!(d.len(), 3);
        assert_eq!(d[0]["message"], json!("Error loading PCB 'x'.\nExpecting thru_hole"));
        assert_eq!(d[0]["messageVia"], json!("win32"));
        assert_eq!(d[0]["level"], json!("error"));
        assert_eq!(d[0]["allText"].as_array().unwrap().len(), 2);
        assert_eq!(d[1]["hwnd"], json!(3));
        assert_eq!(d[1]["messageVia"], json!("uia"));
        assert_eq!(d[2]["messageVia"], Value::Null);
        assert_eq!(d[2]["messageUnavailable"], json!("taskdialog_directui_and_uia_unavailable"));
        assert!(d[2]["readTextWith"].as_str().unwrap().starts_with("desktop_ui_tree {\"hwnd\":4,"));
        let all = dialog_entries(&rows, true);
        assert_eq!(all.len(), 4);
        assert_eq!(all[1]["level"], json!("info"));
        let r = errors(&rows, false, "test");
        assert_eq!(r["count"], json!(3));
        assert_eq!(r["windowSource"], json!("test"));
    }
}