update logging format

core/logger/Cargo.toml

@@ -9,7 +9,7 @@ authors = ["Hero Team"]
 tracing = "0.1"
 tracing-subscriber = { version = "0.3", features = ["env-filter", "json", "registry", "fmt"] }
 tracing-appender = "0.2"
-tokio = { version = "1", features = ["fs", "time", "rt"] }
+tokio = { version = "1", features = ["fs", "time", "rt", "rt-multi-thread", "macros"] }
 chrono = { version = "0.4", features = ["serde"] }
 serde = { version = "1.0", features = ["derive"] }
 serde_json = "1.0"

core/logger/README.md

@@ -7,11 +7,39 @@ A hierarchical logging system for the Hero project that provides system-level an
 - **Hierarchical Organization**: Physical separation of logs by component and job
 - **System Logger**: Global logging for all non-job-specific events
 - **Per-Job Logger**: Isolated logging for individual job execution
+- **Custom Log Format**: Readable format with precise formatting rules
 - **Hourly Rotation**: Automatic log file rotation every hour
 - **Rhai Integration**: Capture Rhai script `print()` and `debug()` calls
 - **High Performance**: Async logging with efficient filtering
 - **Structured Logging**: Rich context and metadata support
 
+## Custom Log Format
+
+Hero Logger uses a custom format designed for readability and consistency:
+
+```
+21:23:42
+ system     - This is a normal log message
+ system     - This is a multi-line message
+              second line with proper indentation
+              third line maintaining alignment
+E error_cat  - This is an error message
+E             second line of error
+E             third line of error
+```
+
+### Format Rules
+
+- **Time stamps (HH:MM:SS)** are written once per second when the log time changes
+- **Categories** are:
+  - Limited to 10 characters maximum
+  - Padded with spaces to exactly 10 characters
+  - Any `-` in category names are converted to `_`
+- **Each line starts with either:**
+  - ` ` (space) for normal logs (INFO, WARN, DEBUG, TRACE)
+  - `E` for error logs
+- **Multi-line messages** maintain consistent indentation (14 spaces after the prefix)
+
 ## Architecture
 
 The logging system uses a hybrid approach with two main components:
@@ -188,6 +216,11 @@ The system supports standard tracing log levels:
 cargo run --example logging_demo
 ```
 
+### Custom Format Demo
+```bash
+cargo run --example custom_format_demo
+```
+
 ### Integration with Actor System
 ```rust
 // In your actor implementation

core/logger/src/custom_formatter.rs

@@ -0,0 +1,234 @@
+//! Custom Hero Logger Formatter
+//!
+//! This module implements a custom formatter for the Hero logging system that provides:
+//! - Time stamps (HH:MM:SS) written once per second when the log time changes
+//! - Categories limited to 10 characters maximum, padded with spaces, dashes converted to underscores
+//! - Each line starts with either space (normal logs) or E (error logs)
+//! - Multi-line messages maintain consistent indentation (14 spaces after the prefix)
+
+use std::fmt;
+use std::io::{self, Write};
+use std::sync::{Arc, Mutex};
+use tracing::{Event, Level, Subscriber};
+use tracing_subscriber::fmt::{format::Writer, FmtContext, FormatEvent, FormatFields};
+use tracing_subscriber::registry::LookupSpan;
+use chrono::{DateTime, Local};
+
+/// Custom formatter for Hero logging system
+pub struct HeroFormatter {
+    /// Tracks the last written timestamp to avoid duplicate timestamps
+    last_timestamp: Arc<Mutex<Option<String>>>,
+}
+
+impl HeroFormatter {
+    /// Create a new Hero formatter
+    pub fn new() -> Self {
+        Self {
+            last_timestamp: Arc::new(Mutex::new(None)),
+        }
+    }
+
+    /// Format a category name according to Hero rules:
+    /// - Convert dashes to underscores
+    /// - Limit to 10 characters maximum
+    /// - Pad with spaces to exactly 10 characters
+    fn format_category(&self, target: &str) -> String {
+        let processed = target.replace('-', "_");
+        let truncated = if processed.len() > 10 {
+            &processed[..10]
+        } else {
+            &processed
+        };
+        format!("{:<10}", truncated)
+    }
+
+    /// Get the log level prefix (space for normal, E for error)
+    fn get_level_prefix(&self, level: &Level) -> char {
+        match *level {
+            Level::ERROR => 'E',
+            _ => ' ',
+        }
+    }
+
+    /// Get current timestamp in HH:MM:SS format
+    fn get_current_timestamp(&self) -> String {
+        let now: DateTime<Local> = Local::now();
+        now.format("%H:%M:%S").to_string()
+    }
+
+    /// Check if we need to write a timestamp and update the last timestamp
+    fn should_write_timestamp(&self, current_timestamp: &str) -> bool {
+        let mut last_ts = self.last_timestamp.lock().unwrap();
+        match last_ts.as_ref() {
+            Some(last) if last == current_timestamp => false,
+            _ => {
+                *last_ts = Some(current_timestamp.to_string());
+                true
+            }
+        }
+    }
+
+    /// Format a multi-line message with proper indentation
+    fn format_message(&self, prefix: char, category: &str, message: &str) -> String {
+        let lines: Vec<&str> = message.lines().collect();
+        if lines.is_empty() {
+            return format!("{} {} - \n", prefix, category);
+        }
+
+        let mut result = String::new();
+        
+        // First line: prefix + category + " - " + message
+        result.push_str(&format!("{} {} - {}\n", prefix, category, lines[0]));
+        
+        // Subsequent lines: prefix + 14 spaces + message
+        for line in lines.iter().skip(1) {
+            result.push_str(&format!("{}              {}\n", prefix, line));
+        }
+        
+        result
+    }
+}
+
+impl Default for HeroFormatter {
+    fn default() -> Self {
+        Self::new()
+    }
+}
+
+impl<S, N> FormatEvent<S, N> for HeroFormatter
+where
+    S: Subscriber + for<'a> LookupSpan<'a>,
+    N: for<'a> FormatFields<'a> + 'static,
+{
+    fn format_event(
+        &self,
+        _ctx: &FmtContext<'_, S, N>,
+        mut writer: Writer<'_>,
+        event: &Event<'_>,
+    ) -> fmt::Result {
+        // Get current timestamp
+        let current_timestamp = self.get_current_timestamp();
+        
+        // Write timestamp if it has changed
+        if self.should_write_timestamp(&current_timestamp) {
+            writeln!(writer, "{}", current_timestamp)?;
+        }
+
+        // Get event metadata
+        let metadata = event.metadata();
+        let level = metadata.level();
+        let target = metadata.target();
+
+        // Format category and get prefix
+        let category = self.format_category(target);
+        let prefix = self.get_level_prefix(level);
+
+        // Capture the message
+        let mut message_visitor = MessageVisitor::new();
+        event.record(&mut message_visitor);
+        let message = message_visitor.message;
+
+        // Format and write the message
+        let formatted = self.format_message(prefix, &category, &message);
+        write!(writer, "{}", formatted)?;
+
+        Ok(())
+    }
+}
+
+/// Visitor to extract the message from tracing events
+struct MessageVisitor {
+    message: String,
+}
+
+impl MessageVisitor {
+    fn new() -> Self {
+        Self {
+            message: String::new(),
+        }
+    }
+}
+
+impl tracing::field::Visit for MessageVisitor {
+    fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn fmt::Debug) {
+        if field.name() == "message" {
+            self.message = format!("{:?}", value);
+            // Remove surrounding quotes if present
+            if self.message.starts_with('"') && self.message.ends_with('"') {
+                self.message = self.message[1..self.message.len()-1].to_string();
+            }
+        }
+    }
+
+    fn record_str(&mut self, field: &tracing::field::Field, value: &str) {
+        if field.name() == "message" {
+            self.message = value.to_string();
+        }
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+    use tracing::{info, error};
+    use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
+    use std::sync::{Arc, Mutex};
+    use std::io::Cursor;
+
+    #[test]
+    fn test_format_category() {
+        let formatter = HeroFormatter::new();
+        
+        // Test normal category
+        assert_eq!(formatter.format_category("system"), "system    ");
+        
+        // Test category with dashes
+        assert_eq!(formatter.format_category("osis-actor"), "osis_actor");
+        
+        // Test long category (truncation)
+        assert_eq!(formatter.format_category("very-long-category-name"), "very_long_");
+        
+        // Test exact 10 characters
+        assert_eq!(formatter.format_category("exactly10c"), "exactly10c");
+    }
+
+    #[test]
+    fn test_get_level_prefix() {
+        let formatter = HeroFormatter::new();
+        
+        assert_eq!(formatter.get_level_prefix(&Level::ERROR), 'E');
+        assert_eq!(formatter.get_level_prefix(&Level::WARN), ' ');
+        assert_eq!(formatter.get_level_prefix(&Level::INFO), ' ');
+        assert_eq!(formatter.get_level_prefix(&Level::DEBUG), ' ');
+        assert_eq!(formatter.get_level_prefix(&Level::TRACE), ' ');
+    }
+
+    #[test]
+    fn test_format_message() {
+        let formatter = HeroFormatter::new();
+        
+        // Test single line message
+        let result = formatter.format_message(' ', "system    ", "Hello world");
+        assert_eq!(result, "  system     - Hello world\n");
+        
+        // Test multi-line message
+        let result = formatter.format_message('E', "error_cat ", "Line 1\nLine 2\nLine 3");
+        let expected = "E error_cat  - Line 1\nE              Line 2\nE              Line 3\n";
+        assert_eq!(result, expected);
+    }
+
+    #[test]
+    fn test_timestamp_tracking() {
+        let formatter = HeroFormatter::new();
+        let timestamp = "12:34:56";
+        
+        // First call should return true (write timestamp)
+        assert!(formatter.should_write_timestamp(timestamp));
+        
+        // Second call with same timestamp should return false
+        assert!(!formatter.should_write_timestamp(timestamp));
+        
+        // Call with different timestamp should return true
+        assert!(formatter.should_write_timestamp("12:34:57"));
+    }
+}

core/logger/src/job_logger.rs

@@ -3,7 +3,7 @@
 //! This module implements the per-job logging functionality that creates
 //! temporary, isolated loggers for individual job execution.
 
-use crate::{LoggerError, Result};
+use crate::{LoggerError, Result, custom_formatter::HeroFormatter};
 use std::path::{Path, PathBuf};
 use tracing_subscriber::{
     filter::{EnvFilter, LevelFilter},
@@ -70,13 +70,10 @@ pub fn create_job_logger_with_guard<P: AsRef<Path>>(
     let file_appender = rolling::hourly(&job_dir, "log");
     let (non_blocking, guard) = tracing_appender::non_blocking(file_appender);
     
-    // Create a formatted layer for the job
+    // Create a formatted layer for the job with custom Hero formatter
     let layer = fmt::layer()
         .with_writer(non_blocking)
-        .with_target(true)
+        .event_format(HeroFormatter::new())
-        .with_thread_ids(true)
-        .with_file(true)
-        .with_line_number(true)
         .with_ansi(false) // No ANSI colors in log files
         .with_filter(
             EnvFilter::new("trace") // Capture all logs within the job context
@@ -127,13 +124,10 @@ pub fn create_job_logger_with_config<P: AsRef<Path>>(
     
     let (non_blocking, guard) = tracing_appender::non_blocking(file_appender);
     
-    // Create layer with custom configuration
+    // Create layer with custom configuration and Hero formatter
     let mut layer = fmt::layer()
         .with_writer(non_blocking)
-        .with_target(config.include_target)
+        .event_format(HeroFormatter::new())
-        .with_thread_ids(config.include_thread_ids)
-        .with_file(config.include_file_location)
-        .with_line_number(config.include_line_numbers)
         .with_ansi(false);
     
     // Apply level filter

core/logger/src/lib.rs

@@ -39,6 +39,7 @@ mod system_logger;
 mod job_logger;
 mod file_appender;
 mod utils;
+mod custom_formatter;
 pub mod rhai_integration;
 
 pub use system_logger::*;

core/logger/src/system_logger.rs

@@ -3,7 +3,7 @@
 //! This module implements the system-wide logging functionality that captures
 //! all non-job-specific logs from every component with target-based filtering.
 
-use crate::{LoggerError, Result};
+use crate::{LoggerError, Result, custom_formatter::HeroFormatter};
 use std::path::{Path, PathBuf};
 use tracing_subscriber::{
     filter::{EnvFilter, LevelFilter},
@@ -82,13 +82,10 @@ fn create_component_layer<P: AsRef<Path>>(
     let file_appender = rolling::hourly(&log_dir, "log");
     let (non_blocking, guard) = tracing_appender::non_blocking(file_appender);
     
-    // Create a formatted layer with target filtering
+    // Create a formatted layer with custom Hero formatter and target filtering
     let layer = fmt::layer()
         .with_writer(non_blocking)
-        .with_target(true)
+        .event_format(HeroFormatter::new())
-        .with_thread_ids(true)
-        .with_file(true)
-        .with_line_number(true)
         .with_ansi(false) // No ANSI colors in log files
         .with_filter(
             EnvFilter::new(format!("{}=trace", component))