use std::fs::{self, File, OpenOptions};
use std::io::Write;
use std::path::PathBuf;
use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
use std::sync::Mutex;
use std::time::{SystemTime, UNIX_EPOCH};
use crate::truncate::truncate_with_suffix;
use crate::event::AgentEvent;
use crate::constants::MATRIX_DIR;
use tokio::sync::mpsc;
static API_CALL_COUNT: AtomicU64 = AtomicU64::new(0);
static COMPRESSION_COUNT: AtomicU64 = AtomicU64::new(0);
static MEMORY_SAVE_COUNT: AtomicU64 = AtomicU64::new(0);
static TOOL_CALL_COUNT: AtomicU64 = AtomicU64::new(0);
const MAX_LOG_SIZE: u64 = 10 * 1024 * 1024;
pub struct DebugLog {
file: Mutex<Option<File>>,
current_file: Mutex<Option<PathBuf>>,
enabled: AtomicBool,
session_id: Mutex<Option<String>>,
}
impl Default for DebugLog {
fn default() -> Self {
Self::new()
}
}
impl DebugLog {
pub fn new() -> Self {
Self {
file: Mutex::new(None),
current_file: Mutex::new(None),
enabled: AtomicBool::new(false),
session_id: Mutex::new(None),
}
}
pub fn enable(&self, session_id: Option<&str>) {
self.enabled.store(true, Ordering::Relaxed);
let sid = session_id.map(|s| s.to_string()).unwrap_or_else(|| {
Self::generate_session_id()
});
if let Ok(mut guard) = self.session_id.lock() {
*guard = Some(sid.clone());
}
if let Ok(mut file_guard) = self.file.lock() {
if let Ok(mut path_guard) = self.current_file.lock() {
match Self::open_session_log_file(&sid, 0) {
Ok((file, path)) => {
*file_guard = Some(file);
*path_guard = Some(path);
}
Err(e) => {
eprintln!("Failed to create debug log file: {}", e);
}
}
}
}
}
pub fn disable(&self) {
self.enabled.store(false, Ordering::Relaxed);
if let Ok(mut guard) = self.file.lock() {
*guard = None;
}
}
pub fn is_enabled(&self) -> bool {
self.enabled.load(Ordering::Relaxed)
}
fn generate_session_id() -> String {
let now = SystemTime::now()
.duration_since(UNIX_EPOCH)
.unwrap_or_default()
.as_secs();
format!("session_{}", now)
}
fn get_log_dir() -> Result<PathBuf, std::io::Error> {
let home = std::env::var_os("HOME")
.or_else(|| std::env::var_os("USERPROFILE"))
.ok_or_else(|| std::io::Error::new(std::io::ErrorKind::NotFound, "HOME not set"))?;
let mut path = PathBuf::from(home);
path.push(MATRIX_DIR);
path.push("logs");
fs::create_dir_all(&path)?;
Ok(path)
}
fn open_session_log_file(session_id: &str, rotation: u32) -> Result<(File, PathBuf), std::io::Error> {
let mut path = Self::get_log_dir()?;
let filename = if rotation == 0 {
format!("{}.log", session_id)
} else {
format!("{}.{}.log", session_id, rotation)
};
path.push(&filename);
let file = OpenOptions::new()
.create(true)
.append(true)
.open(&path)?;
Ok((file, path))
}
fn rotate_if_needed(&self) {
if let Ok(mut file_guard) = self.file.lock()
&& let Ok(mut path_guard) = self.current_file.lock()
&& let Ok(session_guard) = self.session_id.lock()
{
if let (Some(file), Some(_path), Some(session_id)) =
(file_guard.as_mut(), path_guard.as_ref(), session_guard.as_ref())
{
if let Ok(metadata) = file.metadata() {
if metadata.len() > MAX_LOG_SIZE {
let mut rotation = 1u32;
loop {
let mut new_path = Self::get_log_dir().unwrap_or_default();
let filename = format!("{}.{}.log", session_id, rotation);
new_path.push(&filename);
if !new_path.exists() {
break;
}
rotation += 1;
}
if let Ok((new_file, new_path)) = Self::open_session_log_file(session_id, rotation) {
*file_guard = Some(new_file);
*path_guard = Some(new_path);
}
}
}
}
}
}
pub fn cleanup_old_logs(keep_count: usize) -> Result<(), std::io::Error> {
let log_dir = Self::get_log_dir()?;
let mut log_files: Vec<_> = fs::read_dir(&log_dir)?
.filter_map(|e| e.ok())
.filter(|e| e.path().extension().map(|ext| ext == "log").unwrap_or(false))
.collect();
log_files.sort_by_key(|e| {
e.metadata().and_then(|m| m.modified()).unwrap_or(SystemTime::UNIX_EPOCH)
});
let total_sessions = log_files.len();
if total_sessions > keep_count {
for entry in log_files.iter().take(total_sessions - keep_count) {
let _ = fs::remove_file(entry.path());
}
}
Ok(())
}
fn timestamp() -> String {
let now = SystemTime::now()
.duration_since(UNIX_EPOCH)
.unwrap_or_default()
.as_secs();
let secs = now % 60;
let mins = (now / 60) % 60;
let hours = (now / 3600) % 24;
format!("{:02}:{:02}:{:02}", hours, mins, secs)
}
pub fn api_call(&self, model: &str, input_tokens: u32, cached: bool) {
if !self.is_enabled() { return; }
let count = API_CALL_COUNT.fetch_add(1, Ordering::Relaxed) + 1;
let msg = format!(
"API#{}: model={}, input_tokens={}, cached={}",
count,
model,
input_tokens,
cached
);
self.write_log("API", &msg);
}
pub fn compression(&self, original_tokens: u32, compressed_tokens: u32, ratio: f32) {
if !self.is_enabled() { return; }
let count = COMPRESSION_COUNT.fetch_add(1, Ordering::Relaxed) + 1;
let saved = original_tokens - compressed_tokens;
let msg = format!(
"COMPRESSION#{}: original={}, compressed={}, saved={}, ratio={:.1}%",
count,
original_tokens,
compressed_tokens,
saved,
ratio * 100.0
);
self.write_log("COMPRESS", &msg);
}
pub fn memory_save(&self, entries: usize, summary_len: usize) {
if !self.is_enabled() { return; }
let count = MEMORY_SAVE_COUNT.fetch_add(1, Ordering::Relaxed) + 1;
let msg = format!(
"MEMORY#{}: entries={}, summary_len={}chars",
count,
entries,
summary_len
);
self.write_log("MEMORY", &msg);
}
pub fn keywords_extracted(&self, keywords: &[String], source: &str) {
if !self.is_enabled() { return; }
let msg = format!(
"{} extracted from {}chars | keywords: {}",
keywords.len(),
source.len(),
keywords.join(", ")
);
self.write_log("KEYWORDS", &msg);
}
pub fn tool_call(&self, tool: &str, input_preview: &str, result_preview: &str) {
if !self.is_enabled() { return; }
let count = TOOL_CALL_COUNT.fetch_add(1, Ordering::Relaxed) + 1;
let msg = format!(
"TOOL#{}: {} | input: {} | result: {}",
count,
tool,
truncate(input_preview, 50),
truncate(result_preview, 50)
);
self.write_log("TOOL", &msg);
}
pub fn session_save(&self, message_count: usize, total_tokens: u64) {
if !self.is_enabled() { return; }
let msg = format!(
"SESSION: messages={}, total_tokens={}",
message_count,
total_tokens
);
self.write_log("SESSION", &msg);
}
pub fn log(&self, category: &str, message: &str) {
if !self.is_enabled() { return; }
self.write_log(category, message);
}
pub fn api_request(&self, url: &str, body: &str) {
if !self.is_enabled() { return; }
let body_preview = if body.len() > 5000 {
truncate_with_suffix(body, 5000)
} else {
body.to_string()
};
let msg = format!(
"API_REQUEST: url={}\n---REQUEST_BODY---\n{}\n---END---",
url,
body_preview
);
self.write(&format!("[{}] {}", Self::timestamp(), msg));
let panel_msg = format!("url={} | body_len={}chars", url, body.len());
self.send_debug_event("API_REQUEST", &panel_msg);
}
pub fn api_response(&self, status: u16, body: &str) {
if !self.is_enabled() { return; }
let body_preview = if body.len() > 10000 {
truncate_with_suffix(body, 10000)
} else {
body.to_string()
};
let msg = format!(
"API_RESPONSE: status={}\n---RESPONSE_BODY---\n{}\n---END---",
status,
body_preview
);
self.write(&format!("[{}] {}", Self::timestamp(), msg));
let panel_msg = format!("status={} | body_len={}chars", status, body.len());
self.send_debug_event("API_RESPONSE", &panel_msg);
}
pub fn stream_chunk(&self, chunk_type: &str, content: &str) {
if !self.is_enabled() { return; }
let preview = if content.len() > 200 {
truncate_with_suffix(content, 200)
} else {
content.to_string()
};
let msg = format!(
"[{}] STREAM_CHUNK: type={} | {}",
Self::timestamp(),
chunk_type,
preview
);
self.write(&msg);
}
pub fn memory_ai_keywords(&self, model: &str, keywords_count: usize, source_len: usize, used_ai: bool) {
if !self.is_enabled() { return; }
let method = if used_ai { "AI" } else { "rule" };
let msg = format!(
"MEMORY_AI_KEYWORDS: model={}, method={}, keywords={}, source_len={}chars",
model,
method,
keywords_count,
source_len
);
self.write_log("MEMORY", &msg);
}
pub fn memory_ai_detection(&self, model: &str, entries_count: usize, text_len: usize, used_ai: bool) {
if !self.is_enabled() { return; }
let method = if used_ai { "AI" } else { "rule" };
let msg = format!(
"MEMORY_AI_DETECT: model={}, method={}, entries={}, text_len={}chars",
model,
method,
entries_count,
text_len
);
self.write_log("MEMORY", &msg);
}
fn write(&self, msg: &str) {
if !self.is_enabled() {
return;
}
if let Ok(mut guard) = self.file.lock() {
if let Some(ref mut file) = *guard {
let _ = file.write_all(msg.as_bytes());
let _ = file.write_all(b"\n");
let _ = file.flush();
}
}
self.rotate_if_needed();
}
fn write_log(&self, category: &str, message: &str) {
if !self.is_enabled() { return; }
let msg = format!("[{}] {}: {}", Self::timestamp(), category, message);
self.write(&msg);
self.send_debug_event(category, message);
}
fn send_debug_event(&self, category: &str, message: &str) {
if let Ok(guard) = DEBUG_EVENT_SENDER.lock()
&& let Some(ref sender) = *guard
{
let _ = sender.try_send(AgentEvent::debug_log(category, message));
}
}
pub fn stats(&self) -> DebugStats {
DebugStats {
api_calls: API_CALL_COUNT.load(Ordering::Relaxed),
compressions: COMPRESSION_COUNT.load(Ordering::Relaxed),
memory_saves: MEMORY_SAVE_COUNT.load(Ordering::Relaxed),
tool_calls: TOOL_CALL_COUNT.load(Ordering::Relaxed),
}
}
}
fn truncate(s: &str, max: usize) -> String {
truncate_with_suffix(s, max)
}
#[derive(Debug, Clone)]
pub struct DebugStats {
pub api_calls: u64,
pub compressions: u64,
pub memory_saves: u64,
pub tool_calls: u64,
}
impl DebugStats {
pub fn format(&self) -> String {
format!(
"API: {} │ Compress: {} │ Memory: {} │ Tools: {}",
self.api_calls, self.compressions, self.memory_saves, self.tool_calls
)
}
}
static DEBUG_LOG: once_cell::sync::Lazy<DebugLog> = once_cell::sync::Lazy::new(|| {
let _ = dotenvy::dotenv();
if let Ok(cwd) = std::env::current_dir() {
let matrix_env = cwd.join(MATRIX_DIR).join(".env");
if matrix_env.exists() {
let _ = dotenvy::from_path(&matrix_env);
}
}
DebugLog::new()
});
static DEBUG_EVENT_SENDER: once_cell::sync::Lazy<Mutex<Option<mpsc::Sender<AgentEvent>>>> =
once_cell::sync::Lazy::new(|| Mutex::new(None));
pub fn debug_log() -> &'static DebugLog {
&DEBUG_LOG
}
pub fn enable_debug_logging(session_id: Option<&str>) {
DEBUG_LOG.enable(session_id);
}
pub fn disable_debug_logging() {
DEBUG_LOG.disable();
}
pub fn is_debug_enabled() -> bool {
DEBUG_LOG.is_enabled()
}
pub fn set_debug_event_sender(sender: mpsc::Sender<AgentEvent>) {
if let Ok(mut guard) = DEBUG_EVENT_SENDER.lock() {
*guard = Some(sender);
}
}
#[macro_export]
macro_rules! debug_api {
($model:expr, $tokens:expr, $cached:expr) => {
$crate::debug::debug_log().api_call($model, $tokens, $cached)
};
}
#[macro_export]
macro_rules! debug_compress {
($orig:expr, $comp:expr, $ratio:expr) => {
$crate::debug::debug_log().compression($orig, $comp, $ratio)
};
}
#[macro_export]
macro_rules! debug_memory {
($entries:expr, $len:expr) => {
$crate::debug::debug_log().memory_save($entries, $len)
};
}
#[macro_export]
macro_rules! debug_keywords {
($keywords:expr, $source:expr) => {
$crate::debug::debug_log().keywords_extracted($keywords, $source)
};
}
#[macro_export]
macro_rules! debug_tool {
($tool:expr, $input:expr, $result:expr) => {
$crate::debug::debug_log().tool_call($tool, $input, $result)
};
}
#[macro_export]
macro_rules! debug_session {
($msgs:expr, $tokens:expr) => {
$crate::debug::debug_log().session_save($msgs, $tokens)
};
}
#[macro_export]
macro_rules! debug_log_msg {
($cat:expr, $msg:expr) => {
$crate::debug::debug_log().log($cat, $msg)
};
}
#[macro_export]
macro_rules! debug_api_request {
($url:expr, $body:expr) => {
$crate::debug::debug_log().api_request($url, $body)
};
}
#[macro_export]
macro_rules! debug_api_response {
($status:expr, $body:expr) => {
$crate::debug::debug_log().api_response($status, $body)
};
}
#[macro_export]
macro_rules! debug_stream_chunk {
($type:expr, $content:expr) => {
$crate::debug::debug_log().stream_chunk($type, $content)
};
}
#[macro_export]
macro_rules! debug_memory_ai_keywords {
($model:expr, $count:expr, $len:expr, $ai:expr) => {
$crate::debug::debug_log().memory_ai_keywords($model, $count, $len, $ai)
};
}
#[macro_export]
macro_rules! debug_memory_ai_detect {
($model:expr, $count:expr, $len:expr, $ai:expr) => {
$crate::debug::debug_log().memory_ai_detection($model, $count, $len, $ai)
};
}