supercode-harness 0.5.113

//! The slow log: a command or door call that takes more than a second is one JSON line in
//! `<supercode home>/logs/slow.jsonl`, so slowness reads as bug monitoring (the audit reads it
//! every round). The Node packages write the same lines (`@volter/supercode-harness-sdk/slow-log`).
//!
//! `{ v: 1, at, kind: "command"|"door"|"call", name, args, ms, outcome, machine, pid, caller,
//! slowest: { step, ms } }`. `slowest` is the longest step the command noted. Writing never
//! fails the command it measures.

use std::io::Write;
use std::path::PathBuf;
use std::sync::Mutex;
use std::time::Instant;

/// Anything slower than this many milliseconds is written.
pub const SLOW_MS: u128 = 1000;

/// The log's size before it rotates: it and the one rotation before it are all that is kept.
pub const ROTATE_BYTES: u64 = 4 * 1024 * 1024;

static SLOWEST: Mutex<Option<(String, u128)>> = Mutex::new(None);

/// A step of the running command took `ms`; the longest is the command's `slowest`.
pub fn note_step(step: &str, ms: u128) {
    if let Ok(mut slowest) = SLOWEST.lock() {
        if slowest.as_ref().is_none_or(|(_, longest)| ms > *longest) {
            *slowest = Some((step.to_string(), ms));
        }
    }
}

/// Run `f` as the step `step` of the running command.
pub fn timed<T>(step: &str, f: impl FnOnce() -> T) -> T {
    let started = Instant::now();
    let value = f();
    note_step(step, started.elapsed().as_millis());
    value
}

/// The longest step noted so far.
pub fn slowest_step() -> Option<(String, u128)> {
    SLOWEST.lock().ok().and_then(|slowest| slowest.clone())
}

/// Where the lines go.
pub fn path() -> PathBuf {
    crate::agent::global_instructions_dir()
        .join("logs")
        .join("slow.jsonl")
}

fn secret_flag(flag: &str) -> bool {
    let name = flag.trim_start_matches('-').to_ascii_lowercase();
    matches!(
        name.as_str(),
        "token"
            | "key"
            | "api-key"
            | "apikey"
            | "secret"
            | "password"
            | "passwd"
            | "credential"
            | "credentials"
            | "auth"
            | "authorization"
            | "bearer"
            | "cookie"
            | "session-token"
    )
}

fn secret_name(name: &str) -> bool {
    let name = name.to_ascii_lowercase();
    [
        "token",
        "secret",
        "password",
        "passwd",
        "credential",
        "api_key",
        "api-key",
        "apikey",
        "authorization",
        "cookie",
    ]
    .iter()
    .any(|word| name.contains(word))
}

fn secret_value(value: &str) -> bool {
    let token_like = |prefix: &str, min: usize| value.starts_with(prefix) && value.len() >= min;
    token_like("sk-", 19)
        || token_like("ghp_", 24)
        || token_like("gho_", 24)
        || token_like("ghs_", 24)
        || token_like("ghu_", 24)
        || token_like("ghr_", 24)
        || token_like("xoxb-", 15)
        || token_like("xoxp-", 15)
        || (value.starts_with("eyJ") && value.matches('.').count() == 2 && value.len() > 40)
        || (value.len() >= 40
            && value.bytes().all(|b| {
                b.is_ascii_alphanumeric() || matches!(b, b'+' | b'/' | b'_' | b'-' | b'=')
            }))
}

/// The arguments as the log keeps them: secrets replaced, each at most 200 characters.
pub fn redact_args(args: &[String]) -> Vec<String> {
    let mut out = Vec::with_capacity(args.len());
    let mut hide_next = false;
    for arg in args {
        if hide_next {
            out.push("[redacted]".to_string());
            hide_next = false;
            continue;
        }
        if let Some((flag, _)) = arg.split_once('=') {
            if flag.starts_with('-') && secret_flag(flag) {
                out.push(format!("{flag}=[redacted]"));
                continue;
            }
            if !flag.starts_with('-')
                && !flag.is_empty()
                && flag.bytes().all(|b| b.is_ascii_alphanumeric() || b == b'_')
                && secret_name(flag)
            {
                out.push(format!("{flag}=[redacted]"));
                continue;
            }
        }
        if arg.starts_with('-') && secret_flag(arg) {
            out.push(arg.clone());
            hide_next = true;
            continue;
        }
        if secret_value(arg) {
            out.push("[redacted]".to_string());
            continue;
        }
        if arg.chars().count() > 200 {
            out.push(format!("{}…", arg.chars().take(200).collect::<String>()));
        } else {
            out.push(arg.clone());
        }
    }
    out
}

/// One line, when `ms` is above the bound. `caller` is asked only then (resolving a caller reads
/// the process table). Answers whether a line was written.
#[allow(clippy::too_many_arguments)]
pub fn record(
    kind: &str,
    name: &str,
    args: &[String],
    ms: u128,
    outcome: &str,
    slowest: Option<(String, u128)>,
    caller: impl FnOnce() -> Option<String>,
) -> bool {
    if ms <= SLOW_MS {
        return false;
    }
    let line = serde_json::json!({
        "v": 1,
        "at": supercode_interchange::sidecar::ms_to_rfc3339(
            std::time::SystemTime::now()
                .duration_since(std::time::UNIX_EPOCH)
                .map(|elapsed| elapsed.as_millis() as i64)
                .unwrap_or_default(),
        ),
        "kind": kind,
        "name": name,
        "args": redact_args(args),
        "ms": ms as u64,
        "outcome": outcome,
        "machine": crate::mailbox::local_machine_name(),
        "pid": std::process::id(),
        "caller": caller().map(|address| serde_json::json!({ "address": address })),
        "slowest": slowest.map(|(step, ms)| serde_json::json!({ "step": step, "ms": ms as u64 })),
    });
    let path = path();
    if let Some(dir) = path.parent() {
        let _ = std::fs::create_dir_all(dir);
    }
    // Bounded: past ROTATE_BYTES the log becomes `slow.jsonl.1` (replacing the one before) and starts again.
    if std::fs::metadata(&path).is_ok_and(|meta| meta.len() > ROTATE_BYTES) {
        let _ = std::fs::rename(&path, path.with_extension("jsonl.1"));
    }
    std::fs::OpenOptions::new()
        .create(true)
        .append(true)
        .open(&path)
        .and_then(|mut file| writeln!(file, "{line}"))
        .is_ok()
}