cortexkit-log 0.3.2

Fleet logging format, filtering, redaction, and retention for CortexKit modules
Documentation
use std::fmt;
use std::time::SystemTime;

use chrono::{DateTime, SecondsFormat, Utc};
use tracing::Level;

/// Renders one r2 fleet log line: `<ts> <LEVEL> <logger>: [<bound>] <message> <fields>`.
///
/// `logger` is the full dotted name (`engram`, `engram.gc.walk`), already
/// validated by [`logger_name`]. `bound` renders inside the bracket in the order
/// given; an empty slice renders NO bracket, because "nothing bound" and "an
/// empty context" are different facts and only the first is ever true.
pub(crate) fn render_line(
    at: SystemTime,
    level: &Level,
    logger: &str,
    bound: &[(String, String)],
    message: &str,
    fields: &[(String, String)],
) -> String {
    let timestamp = DateTime::<Utc>::from(at).to_rfc3339_opts(SecondsFormat::Millis, true);
    let mut line = format!("{timestamp} {:<5} {logger}:", level.as_str());

    if !bound.is_empty() {
        line.push_str(" [");
        for (index, (key, value)) in bound.iter().enumerate() {
            if index > 0 {
                line.push(' ');
            }
            line.push_str(key);
            line.push('=');
            line.push_str(&format_value(value));
        }
        line.push(']');
    }
    if !message.is_empty() {
        line.push(' ');
        line.push_str(&escape_message(message));
    }
    for (key, value) in fields {
        line.push(' ');
        line.push_str(key);
        line.push('=');
        line.push_str(&format_value(value));
    }

    line
}

/// Joins a module id and an optional component into the logger name, refusing
/// a component that is not in the segment grammar. A `tracing` target that is
/// a Rust module path (`synapse::engine::decode`) is NOT a component: it would
/// make logger names an accident of code layout, so it maps to the bare module
/// id. A target equal to the module id is the same case spelled differently.
pub(crate) fn logger_name(module_id: &str, target: &str) -> String {
    if target.is_empty() || target == module_id || target.contains("::") {
        return module_id.to_owned();
    }
    if !target.split('.').all(is_segment) {
        return module_id.to_owned();
    }
    format!("{module_id}.{target}")
}

pub(crate) fn is_segment(segment: &str) -> bool {
    let mut chars = segment.chars();
    matches!(chars.next(), Some('a'..='z'))
        && chars.all(|character| matches!(character, 'a'..='z' | '0'..='9' | '-'))
}

// Backslash is escaped first so a literal `\n` in the input survives as
// `\\n` and cannot be read back as a newline. Same order as @cortexkit/log.
fn escape_message(message: &str) -> String {
    message
        .replace('\\', "\\\\")
        .replace('\r', "\\r")
        .replace('\n', "\\n")
}

fn format_value(value: &str) -> String {
    if value.is_empty()
        || value
            .chars()
            .any(|character| matches!(character, ' ' | '"' | '\n' | '\r' | ']'))
    {
        let escaped = value
            .replace('\\', "\\\\")
            .replace('"', "\\\"")
            .replace('\r', "\\r")
            .replace('\n', "\\n");
        format!("\"{escaped}\"")
    } else {
        // An unquoted value is verbatim, backslashes included: only the quoted
        // form has an escape grammar, and a reader decodes only quoted values.
        value.to_owned()
    }
}

pub(crate) fn strip_ansi(input: &str) -> String {
    let without_c1 = strip_c1_sequences(input);
    let input = without_c1.as_str();
    let bytes = input.as_bytes();
    let mut output = String::with_capacity(input.len());
    let mut index = 0;
    let mut plain_start = 0;

    while index < bytes.len() {
        if bytes[index] != 0x1b {
            index += 1;
            continue;
        }

        output.push_str(&input[plain_start..index]);
        index += 1;
        if index >= bytes.len() {
            plain_start = index;
            break;
        }

        match bytes[index] {
            b'[' => {
                index += 1;
                while index < bytes.len() {
                    let byte = bytes[index];
                    index += 1;
                    if (0x40..=0x7e).contains(&byte) {
                        break;
                    }
                }
            }
            b']' => {
                index += 1;
                while index < bytes.len() {
                    if bytes[index] == 0x07 {
                        index += 1;
                        break;
                    }
                    if bytes[index] == 0x1b
                        && bytes.get(index + 1).is_some_and(|next| *next == b'\\')
                    {
                        index += 2;
                        break;
                    }
                    index += 1;
                }
            }
            _ => index += 1,
        }
        plain_start = index;
    }

    if plain_start == 0 {
        return without_c1;
    }
    output.push_str(&input[plain_start..]);
    output
}

fn strip_c1_sequences(input: &str) -> String {
    let mut characters = input.chars();
    let mut output = String::with_capacity(input.len());
    while let Some(character) = characters.next() {
        match character {
            '\u{009b}' => {
                for parameter in characters.by_ref() {
                    if ('@'..='~').contains(&parameter) {
                        break;
                    }
                }
            }
            '\u{009d}' => {
                for payload in characters.by_ref() {
                    if matches!(payload, '\u{0007}' | '\u{009c}') {
                        break;
                    }
                }
            }
            '\u{0080}'..='\u{009f}' => {}
            _ => output.push(character),
        }
    }
    output
}

/// A level parsed from a fleet log line.
#[derive(Clone, Copy, Debug, Eq, PartialEq)]
pub enum ParsedLevel {
    /// A trace event.
    Trace,
    /// A debug event.
    Debug,
    /// An informational event.
    Info,
    /// A warning event.
    Warn,
    /// An error event.
    Error,
}

/// The fields needed to merge and filter a fleet log line.
#[derive(Clone, Debug, Eq, PartialEq)]
pub struct ParsedLine<'a> {
    /// Event time decoded from the UTC timestamp.
    pub timestamp: SystemTime,
    /// Event severity.
    pub level: ParsedLevel,
    /// The full dotted logger name, rooted at the module id.
    pub logger: &'a str,
    /// The module id: the logger's first segment.
    pub module_id: &'a str,
    /// The raw text inside the bound bracket, absent when there was none.
    pub bound: Option<&'a str>,
    /// The message and ordered event fields after the bracket.
    pub body: &'a str,
}

impl ParsedLine<'_> {
    /// The `session=` bound value when one is present, whole, issuer included.
    pub fn session(&self) -> Option<&str> {
        self.bound.and_then(|bound| bound_value(bound, "session"))
    }
}

fn bound_value<'a>(bound: &'a str, key: &str) -> Option<&'a str> {
    bound
        .split(' ')
        .filter_map(|pair| pair.split_once('='))
        .find(|(candidate, _)| *candidate == key)
        .map(|(_, value)| value)
}

/// A stable parse failure returned by [`parse_line`](crate::parse_line).
#[derive(Clone, Copy, Debug, Eq, PartialEq)]
pub struct ParseError {
    reason: &'static str,
}

impl ParseError {
    pub(crate) const fn new(reason: &'static str) -> Self {
        Self { reason }
    }

    /// Returns the stable reason used by conformance fixtures and CLI diagnostics.
    pub const fn reason(self) -> &'static str {
        self.reason
    }
}

impl fmt::Display for ParseError {
    fn fmt(&self, formatter: &mut fmt::Formatter<'_>) -> fmt::Result {
        formatter.write_str(self.reason)
    }
}

impl std::error::Error for ParseError {}

pub(crate) fn parse(line: &str) -> Result<ParsedLine<'_>, ParseError> {
    if line.contains('\u{1b}') || line.contains('\u{9b}') {
        return Err(ParseError::new("ansi_forbidden"));
    }
    if line.contains(['\n', '\r']) {
        return Err(ParseError::new("line_break"));
    }

    let (timestamp_text, after_timestamp) = line
        .split_once(' ')
        .ok_or_else(|| ParseError::new("timestamp_missing"))?;
    if !timestamp_text.ends_with('Z') {
        return Err(ParseError::new("timestamp_not_utc_z"));
    }
    if timestamp_text.len() != 24 {
        return Err(ParseError::new("timestamp_precision"));
    }
    let timestamp = DateTime::parse_from_rfc3339(timestamp_text)
        .map_err(|_| ParseError::new("timestamp_invalid"))?;

    let (level, after_level) = parse_level(after_timestamp)?;

    // The logger runs to the first space and MUST end in a colon. An r1 line
    // (`fusiform poll changed`) has no colon and fails here by design: it is
    // the colon that makes the logger unambiguous against a one-word message.
    let (logger_token, mut body) = match after_level.split_once(' ') {
        Some(split) => split,
        None => (after_level, ""),
    };
    let logger = logger_token
        .strip_suffix(':')
        .ok_or_else(|| ParseError::new("logger_not_terminated"))?;
    if logger.is_empty() {
        return Err(ParseError::new("logger_missing"));
    }
    if !logger.split('.').all(is_segment) {
        return Err(ParseError::new("logger_segment_grammar"));
    }
    let module_id = logger.split('.').next().unwrap_or(logger);

    let mut bound = None;
    if let Some(rest) = body.strip_prefix('[') {
        let close =
            find_bracket_close(rest).ok_or_else(|| ParseError::new("bound_unterminated"))?;
        let inside = &rest[..close];
        if inside.is_empty() {
            return Err(ParseError::new("empty_bound_bracket"));
        }
        if let Some(session) = bound_value(inside, "session") {
            let valid = session
                .rsplit_once(':')
                .is_some_and(|(issuer, id)| !issuer.is_empty() && !id.is_empty());
            // `session=global` and other issuer-less placeholders fail here on
            // their missing `issuer:` half; the renderer never has to know any
            // particular sentinel.
            if !valid {
                return Err(ParseError::new("session_missing_issuer"));
            }
        }
        bound = Some(inside);
        body = rest[close + 1..]
            .strip_prefix(' ')
            .unwrap_or(&rest[close + 1..]);
    }

    // A bracket AFTER the message is not context: context precedes the message
    // so its column is stable. Reject rather than silently reading it as a
    // field, because a reader that accepted both would train writers to put
    // it wherever, and the alignment property would be gone in a month.
    if bound.is_none() && body.contains(" [") && body.ends_with(']') {
        return Err(ParseError::new("bound_after_message"));
    }

    Ok(ParsedLine {
        timestamp: SystemTime::from(timestamp),
        level,
        logger,
        module_id,
        bound,
        body,
    })
}

// The bracket closes at the first `]` that is not inside a quoted value. A
// bound value containing `]` was quoted by the renderer for exactly this
// reason, so a naive `find(']')` would split a path like `[root="a]b"]`.
fn find_bracket_close(input: &str) -> Option<usize> {
    let mut in_quotes = false;
    let mut escaped = false;
    for (index, character) in input.char_indices() {
        if escaped {
            escaped = false;
            continue;
        }
        match character {
            '\\' if in_quotes => escaped = true,
            '"' => in_quotes = !in_quotes,
            ']' if !in_quotes => return Some(index),
            _ => {}
        }
    }
    None
}

fn parse_level(input: &str) -> Result<(ParsedLevel, &str), ParseError> {
    for (prefix, level) in [
        ("TRACE ", ParsedLevel::Trace),
        ("DEBUG ", ParsedLevel::Debug),
        ("INFO  ", ParsedLevel::Info),
        ("WARN  ", ParsedLevel::Warn),
        ("ERROR ", ParsedLevel::Error),
    ] {
        if let Some(rest) = input.strip_prefix(prefix) {
            return Ok((level, rest));
        }
    }

    if ["TRACE", "DEBUG", "INFO", "WARN", "ERROR"]
        .iter()
        .any(|level| input.starts_with(level))
    {
        Err(ParseError::new("level_column_width"))
    } else {
        Err(ParseError::new("level_invalid"))
    }
}