36cd491 log: Add regex-based highlighting to test logger — heartwood

Radicle Heartwood Protocol & Stack

log: Add regex-based highlighting to test logger

Adrian Duke committed 2 months ago

commit 36cd4917b6d392e38ba44da5b52e53f11f160591
parent 51acea2eb6a836813020f8f4424bba37bc899562

3 files changed +397 -36

modified crates/radicle-log/src/lib.rs

@@ -5,6 +5,9 @@

 #[cfg(feature = "test")]
 pub mod test;
 #[cfg(test)]
 mod tests;
 use std::io::{self, Write};
 use chrono::prelude::*;

modified crates/radicle-log/src/test.rs

@@ -1,13 +1,55 @@

 use log::*;
 use std::io::{self, Write};
 use std::sync::{Arc, Mutex};
 use log::{Level, Log, Metadata, Record, SetLoggerError};
 use regex::Regex;
 use radicle_localtime::LocalTime;
 use radicle_term::{Color, Paint};
 /// A writer that can be shared across threads.
 pub type SharedWriter = Arc<Mutex<dyn Write + Send + Sync>>;
 /// The Test Logger
 /// Logs with Epoch timestamps, "test"/"sim" formatting and regex highlighting
 pub struct Logger {
     level: Level,
     pub base58_ref_oid_re: Regex,
     pub base58_re: Regex,
     writer: SharedWriter,
 }
 /// The Base58 pattern used for Radicle IDs.
 const BASE58_REGEX: &str = r"z[1-9A-HJ-NP-Za-km-z]{10,}";
 impl Logger {
     pub fn new(level: Level) -> Self {
         Self { level }
         Self {
             level,
             // base58: Starts with 'z', base58 chars, 10+ length.
             // ref: Starts with 'refs/', followed by valid ref chars.
             // oid: Hex characters, between 6 and 40 length, with word boundaries. (currently
             // matching timestamps too e.g. `1769096403171`)
             base58_ref_oid_re: Regex::new(&format!(
                 r"(?P<base58>{BASE58_REGEX})|(?P<ref>refs/[a-zA-Z0-9/*._-]+)|(?P<oid>\b[0-9a-f]{{6,40}}\b)")
             ).expect("invalid regex"),
             base58_re: Regex::new(BASE58_REGEX).expect("invalid id regex"),
             writer: Arc::new(Mutex::new(io::stdout())),
         }
     }
     /// Create a new logger with a custom writer.
     pub fn with_writer(level: Level, writer: SharedWriter) -> Self {
         let mut logger = Self::new(level);
         logger.writer = writer;
         logger
     }
     pub fn init(self) -> Result<(), SetLoggerError> {
         let level = self.level;
         log::set_boxed_logger(Box::new(self))?;
         log::set_max_level(level.to_level_filter());
         Ok(())
     }
 }

@@ -17,49 +59,169 @@ impl Log for Logger {

     }
     fn log(&self, record: &Record) {
         use colored::Colorize;
         if !self.enabled(record.metadata()) {
             return;
         }
         let target = record.target();
         let level = record.level();
         // Helper to paint the "plain" parts of the message based on the target/level.
         let paint_plain = |s: &str| -> String {
             match target {
                 "test" => Paint::cyan(s).to_string(),
                 "sim" => Paint::new(s).bold().to_string(),
                 _ => match level {
                     Level::Warn => Paint::yellow(s).underline().to_string(),
                     Level::Error => Paint::red(s).underline().to_string(),
                     _ => Paint::new(s).dim().to_string(),
                 },
             }
         };
         let msg = record.args().to_string();
         let mut coloured_msg = String::new();
         let mut last_match = 0;
         // Iterate over the main composite matches
         for caps in self.base58_ref_oid_re.captures_iter(&msg) {
             let whole_match = caps.get(0).unwrap();
             // Paint text BEFORE the match (Plain style)
             coloured_msg.push_str(&paint_plain(&msg[last_match..whole_match.start()]));
             // Handle the match based on which group captured it
             if let Some(m) = caps.name("base58") {
                 // Standard Base58 match (not inside a ref)
                 let match_str = m.as_str();
                 coloured_msg.push_str(&paint_base58(match_str).to_string());
             } else if let Some(m) = caps.name("oid") {
                 // Git OID match (RGB from hex with contrast check)
                 let oid = m.as_str();
                 coloured_msg.push_str(&paint_oid(oid).to_string());
             } else if let Some(m) = caps.name("ref") {
                 // Git Ref match
                 let ref_str = m.as_str();
                 let mut last_ref_idx = 0;
                 // Search for Base58 IDs *inside* this ref string
                 for id_match in self.base58_re.find_iter(ref_str) {
                     let prefix = &ref_str[last_ref_idx..id_match.start()];
                     coloured_msg.push_str(&Paint::new(prefix).bold().underline().to_string());
                     // Paint the ID itself (Deterministic Colour + Bold)
                     let id = id_match.as_str();
                     coloured_msg.push_str(
                         &colour_for_base58(id)
                             .paint(id)
                             .bold()
                             .underline()
                             .to_string(),
                     );
                     last_ref_idx = id_match.end();
                 }
                 let suffix = &ref_str[last_ref_idx..];
                 coloured_msg.push_str(&Paint::new(suffix).bold().underline().to_string());
             }
             last_match = whole_match.end();
         }
         // Paint the remaining text
         coloured_msg.push_str(&paint_plain(&msg[last_match..]));
         let time = LocalTime::now().as_secs();
         let mut writer = self.writer.lock().unwrap_or_else(|e| e.into_inner());
         match record.target() {
         match target {
             "test" => {
                 println!(
                     "{time} {} {}",
                     "test:".cyan(),
                     record.args().to_string().cyan()
                 )
                 let _ = writeln!(writer, "{} {} {}", time, Paint::cyan("test:"), coloured_msg);
             }
             "sim" => {
                 println!(
                     "{time} {}  {}",
                     "sim:".bold(),
                     record.args().to_string().bold()
                 )
                 let _ = writeln!(
                     writer,
                     "{} {}  {}",
                     time,
                     Paint::new("sim:").bold(),
                     coloured_msg
                 );
             }
             target => {
                 if self.enabled(record.metadata()) {
                     let current = std::thread::current();
                     let msg = format!("{:>10} {}", format!("{target}:"), record.args());
                     let time = LocalTime::now().as_secs();
                     let s = if let Some(name) = current.name() {
                         format!("{time} {name:<16} {msg}")
                     } else {
                         format!("{time} {msg}")
                     };
                     match record.level() {
                         log::Level::Warn => {
                             println!("{}", s.yellow());
                         }
                         log::Level::Error => {
                             println!("{}", s.red());
                         }
                         _ => {
                             println!("{}", s.dimmed());
                         }
                     }
                 }
             _ => {
                 let current = std::thread::current();
                 let target_str = format!("{}:", target);
                 let prefix = if let Some(name) = current.name() {
                     format!("{} {:<16} {:>10}", time, name, target_str)
                 } else {
                     format!("{} {:>10}", time, target_str)
                 };
                 let _ = writeln!(writer, "{} {}", paint_plain(&prefix), coloured_msg);
             }
         }
     }
     fn flush(&self) {}
 }
 fn paint_base58(s: &str) -> Paint<&str> {
     let colour = colour_for_base58(s);
     colour.paint(s).bold()
 }
 /// Deterministically pick a colour for a base58 string.
 /// NOTE: If the output contains more than base58 strings than the number of colours below,
 /// consider switching to the `paint_oid` system.
 pub fn colour_for_base58(s: &str) -> Color {
     let mut hash: u32 = 0;
     for b in s.bytes() {
         hash = hash.wrapping_add(b as u32);
     }
     let colours = [
         Color::Red,
         Color::Green,
         Color::Yellow,
         Color::Blue,
         Color::Magenta,
         Color::Cyan,
         Color::White,
     ];
     colours[(hash as usize) % colours.len()]
 }
 /// Paint an OID using its first 6 characters as an RGB hex code.
 /// Automatically applies a contrasting background if the colour is too bright or too dark.
 pub fn paint_oid(oid: &str) -> Paint<&str> {
     if oid.len() < 6 {
         return Paint::yellow(oid);
     }
     let r = u8::from_str_radix(&oid[0..2], 16).unwrap_or(128);
     let g = u8::from_str_radix(&oid[2..4], 16).unwrap_or(128);
     let b = u8::from_str_radix(&oid[4..6], 16).unwrap_or(128);
     // Calculate relative luminance (0.0 to 255.0)
     // Formula: 0.299*R + 0.587*G + 0.114*B
     let luminance = (0.299 * r as f32) + (0.587 * g as f32) + (0.114 * b as f32);
     let colour = Color::RGB(r, g, b);
     let paint = colour.paint(oid);
     // Thresholds: < 40 is very dark, > 215 is very bright.
     if luminance < 40.0 {
         paint.bg(Color::White)
     } else if luminance > 215.0 {
         paint.bg(Color::Black)
     } else {
         paint
     }
 }
 /// Initialize the logger with the given level.
 pub fn init(level: Level) -> Result<(), SetLoggerError> {
     Logger::new(level).init()
 }

added crates/radicle-log/src/tests.rs

@@ -0,0 +1,196 @@

 use crate::test::{colour_for_base58, Logger};
 use log::{Level, Log, Record};
 use radicle_term::{Color, Paint};
 use std::io::{self, Write};
 use std::sync::{Arc, Mutex};
 #[derive(Clone)]
 struct TestWriter {
     data: Arc<Mutex<Vec<u8>>>,
 }
 impl Write for TestWriter {
     fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
         self.data.lock().unwrap().write(buf)
     }
     fn flush(&mut self) -> io::Result<()> {
         Ok(())
     }
 }
 #[test]
 fn test_colour_for() {
     let s = "z6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk";
     let color = colour_for_base58(s);
     assert_eq!(color, Color::Red);
     let s = "z6MknSLrJoTcukLrE435hVNQT4JUhbvWLX4kUzqkEStBU8Vi";
     let color = colour_for_base58(s);
     assert_eq!(color, Color::Blue);
 }
 #[test]
 fn test_base58_ref_oid_regex_matching() {
     let logger = Logger::new(Level::Debug);
     let cases = vec![
         (
             "fetched rad:z42hL2jL4XNk6K8oHQaSWfMgCL7ji from z6MknSLrJoTcukLrE435hVNQT4JUhbvWLX4kUzqkEStBU8Vi",
             vec![
                 "z42hL2jL4XNk6K8oHQaSWfMgCL7ji",
                 "z6MknSLrJoTcukLrE435hVNQT4JUhbvWLX4kUzqkEStBU8Vi",
             ],
         ),
         (
             "Setting ref: refs/rad/id -> 3143236b2e40338f5574ec04e935a5ab80a6868a",
             vec!["refs/rad/id", "3143236b2e40338f5574ec04e935a5ab80a6868a"],
         ),
         (
             "Syncing z6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk with z6MknSLrJoTcukLrE435hVNQT4JUhbvWLX4kUzqkEStBU8Vi",
             vec![
                 "z6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk",
                 "z6MknSLrJoTcukLrE435hVNQT4JUhbvWLX4kUzqkEStBU8Vi",
             ],
         ),
         (
             "Multiple refs: refs/heads/master and refs/tags/v1.0.0",
             vec!["refs/heads/master", "refs/tags/v1.0.0"],
         ),
         (
             "Mixed content: z6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk and refs/remotes/origin/main",
             vec![
                 "z6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk",
                 "refs/remotes/origin/main",
             ],
         ),
         (
             "No matches here",
             vec![],
         ),
         (
             "Short z123 is not matched",
             vec![],
         ),
         (
             "Timestamp 1769096403171 is matched by regex but filtered in log",
             vec!["1769096403171"],
         ),
     ];
     for (msg, expected) in cases {
         let matches: Vec<_> = logger
             .base58_ref_oid_re
             .find_iter(msg)
             .map(|m| m.as_str())
             .collect();
         assert_eq!(matches, expected, "Failed matching for input: '{}'", msg);
     }
 }
 #[test]
 fn test_log_output() {
     Paint::force(true);
     let cases = vec![
         (
             "Hello z6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk world",
             "test",
             vec![
                 "\x1b[36mtest:\x1b[0m", // Target
                 "\x1b[36mHello \x1b[0m", // Plain text (Cyan for test)
                 "\x1b[1;31mz6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk\x1b[0m", // ID (Red + Bold)
                 "\x1b[36m world\x1b[0m", // Plain text (Cyan)
             ],
         ),
         (
             "Syncing z6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk with z6MknSLrJoTcukLrE435hVNQT4JUhbvWLX4kUzqkEStBU8Vi",
             "test",
             vec![
                 "\x1b[36mtest:\x1b[0m",
                 "\x1b[36mSyncing \x1b[0m",
                 "\x1b[1;31mz6Mkt67GdsW7715MEfRuP4pSZxJRJh6kj6Y48WRqVv4N1tRk\x1b[0m", // Red + Bold
                 "\x1b[36m with \x1b[0m",
                 "\x1b[1;34mz6MknSLrJoTcukLrE435hVNQT4JUhbvWLX4kUzqkEStBU8Vi\x1b[0m", // Blue + Bold
             ],
         ),
         (
             "Updated refs/heads/master",
             "sim",
             vec![
                 "\x1b[1msim:\x1b[0m", // Target (Bold)
                 "\x1b[1mUpdated \x1b[0m", // Plain text (Bold for sim)
                 "\x1b[1;4mrefs/heads/master\x1b[0m", // Ref (Bold + Underline)
             ],
         ),
         (
             "No matches here",
             "test",
             vec![
                 "\x1b[36mtest:\x1b[0m",
                 "\x1b[36mNo matches here\x1b[0m",
             ],
         ),
         (
             "Timestamp 1769096403171 is matched as OID and given RGB colour",
             "test",
             vec![
                 "\x1b[36mtest:\x1b[0m",
                 "\x1b[36mTimestamp \x1b[0m",
                 "\x1b[38;2;23;105;9m1769096403171\x1b[0m",
                 "\x1b[36m is matched as OID and given RGB colour\x1b[0m",
             ]
         ),
         (
             "Commit 3143236b2e40338f5574ec04e935a5ab80a6868a",
             "test",
             vec![
                 "\x1b[36mtest:\x1b[0m",
                 "\x1b[36mCommit \x1b[0m",
                 // OID painting: 314323 -> R=49, G=67, B=35.
                 // No background.
                 "\x1b[38;2;49;67;35m3143236b2e40338f5574ec04e935a5ab80a6868a\x1b[0m",
             ]
         ),
         (
             "Ref with ID refs/namespaces/z6Mkux1aUQD2voWWukVb5nNUR7thrHveQG4pDQua8nVhib7Z/refs/rad/sigrefs",
             "test",
             vec![
                 "\x1b[36mRef with ID \x1b[0m",
                 "\x1b[1;4mrefs/namespaces/\x1b[0m", // Prefix (Bold + Underline)
                 // ID: z6Mkux...
                 // We check for the ID string being present.
                 "z6Mkux1aUQD2voWWukVb5nNUR7thrHveQG4pDQua8nVhib7Z",
                 "\x1b[1;4m/refs/rad/sigrefs\x1b[0m", // Suffix (Bold + Underline)
             ]
         )
     ];
     for (msg, target, expected_parts) in cases {
         let data = Arc::new(Mutex::new(Vec::new()));
         let writer = TestWriter { data: data.clone() };
         let logger = Logger::with_writer(Level::Debug, Arc::new(Mutex::new(writer)));
         let args = format_args!("{}", msg);
         let record = Record::builder()
             .args(args)
             .level(Level::Info)
             .target(target)
             .build();
         logger.log(&record);
         let output = String::from_utf8(data.lock().unwrap().clone()).unwrap();
         for part in expected_parts {
             assert!(
                 output.contains(part),
                 "Output did not contain expected part: {:?}\nFull output: {:?}",
                 part,
                 output
             );
         }
     }
     Paint::force(false);
 }