From 3bd180494e0b0a26c64693c0c432e4d0065483d2 Mon Sep 17 00:00:00 2001 From: AI Agent Date: Thu, 19 Mar 2026 18:04:32 -0600 Subject: [PATCH] Implement robust logging with flexi_logger and update CI to verify logs --- .gitea/workflows/smoke-tests.yml | 20 ++++ Cargo.lock | 174 +++++++++---------------------- Cargo.toml | 2 +- src/admin.rs | 8 ++ src/combat.rs | 6 +- src/main.rs | 32 +++++- src/ssh.rs | 9 ++ 7 files changed, 122 insertions(+), 129 deletions(-) diff --git a/.gitea/workflows/smoke-tests.yml b/.gitea/workflows/smoke-tests.yml index e048653..3651e5f 100644 --- a/.gitea/workflows/smoke-tests.yml +++ b/.gitea/workflows/smoke-tests.yml @@ -170,3 +170,23 @@ jobs: grep -q '"shop"' rpc_resp.json rm rpc_resp.json ./target/debug/mudtool -d "$TEST_DB" players delete rpctest + + - name: Verify logging + run: | + if [ ! -d "logs" ]; then + echo "Error: logs directory not found" + exit 1 + fi + if ! ls logs/mudserver_*.log >/dev/null 2>&1; then + echo "Error: no log files found" + exit 1 + fi + LOG_FILE=$(ls -t logs/mudserver_*.log | head -n 1) + echo "Checking log file: $LOG_FILE" + grep -q "World '.*': .* rooms" "$LOG_FILE" + grep -q "MUD server listening on" "$LOG_FILE" + grep -q "New character created: smoketest" "$LOG_FILE" + grep -q "Admin action: registration setting updated: '.*'" "$LOG_FILE" + grep -q "Combat: Player 'smoketest' (ID .*) killed NPC 'Shadowy Thief'" "$LOG_FILE" + grep -q "New character created: rpctest" "$LOG_FILE" + grep -q "New JSON-RPC connection from" "$LOG_FILE" diff --git a/Cargo.lock b/Cargo.lock index d7e0910..dd9c3a4 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -61,56 +61,6 @@ dependencies = [ "libc", ] -[[package]] -name = "anstream" -version = "0.6.21" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "43d5b281e737544384e969a5ccad3f1cdd24b48086a0fc1b2a5262a26b8f4f4a" -dependencies = [ - "anstyle", - "anstyle-parse", - "anstyle-query", - "anstyle-wincon", - "colorchoice", - "is_terminal_polyfill", - "utf8parse", -] - -[[package]] -name = "anstyle" -version = "1.0.14" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "940b3a0ca603d1eade50a4846a2afffd5ef57a9feac2c0e2ec2e14f9ead76000" - -[[package]] -name = "anstyle-parse" -version = "0.2.7" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4e7644824f0aa2c7b9384579234ef10eb7efb6a0deb83f9630a49594dd9c15c2" -dependencies = [ - "utf8parse", -] - -[[package]] -name = "anstyle-query" -version = "1.1.5" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "40c48f72fd53cd289104fc64099abca73db4166ad86ea0b4341abe65af83dadc" -dependencies = [ - "windows-sys 0.61.2", -] - -[[package]] -name = "anstyle-wincon" -version = "3.0.11" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "291e6a250ff86cd4a820112fb8898808a366d8f9f58ce16d1f538353ad55747d" -dependencies = [ - "anstyle", - "once_cell_polyfill", - "windows-sys 0.61.2", -] - [[package]] name = "anyhow" version = "1.0.102" @@ -335,12 +285,6 @@ dependencies = [ "inout", ] -[[package]] -name = "colorchoice" -version = "1.0.5" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1d07550c9036bf2ae0c684c4297d503f838287c83c53686d05370d0e139ae570" - [[package]] name = "compact_str" version = "0.9.0" @@ -385,6 +329,30 @@ dependencies = [ "libc", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "82b8f8f868b36967f9606790d1903570de9ceaf870a7bf9fbbd3016d636a2cb2" +dependencies = [ + "crossbeam-utils", +] + +[[package]] +name = "crossbeam-queue" +version = "0.3.12" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0f58bbc28f91df819d0aa2a2c00cd19754769c2fad90579b3592b1c9ba7a3115" +dependencies = [ + "crossbeam-utils", +] + +[[package]] +name = "crossbeam-utils" +version = "0.8.21" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d0a5c400df2834b80a4c3327b3aad3a4c4cd4de0629063962b03235697506a28" + [[package]] name = "crossterm" version = "0.28.1" @@ -694,29 +662,6 @@ dependencies = [ "syn 2.0.117", ] -[[package]] -name = "env_filter" -version = "1.0.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "7a1c3cc8e57274ec99de65301228b537f1e4eedc1b8e0f9411c6caac8ae7308f" -dependencies = [ - "log", - "regex", -] - -[[package]] -name = "env_logger" -version = "0.11.9" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b2daee4ea451f429a58296525ddf28b45a3b64f1acf6587e2067437bb11e218d" -dependencies = [ - "anstream", - "anstyle", - "env_filter", - "jiff", - "log", -] - [[package]] name = "equivalent" version = "1.0.2" @@ -809,6 +754,21 @@ version = "0.4.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0ce7134b9999ecaf8bcd65542e436736ef32ddca1b3e06094cb6ec5755203b80" +[[package]] +name = "flexi_logger" +version = "0.29.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "88a5a6882b2e137c4f2664562995865084eb5a00611fba30c582ef10354c4ad8" +dependencies = [ + "chrono", + "crossbeam-channel", + "crossbeam-queue", + "log", + "nu-ansi-term", + "regex", + "thiserror 2.0.18", +] + [[package]] name = "fnv" version = "1.0.7" @@ -1166,12 +1126,6 @@ dependencies = [ "zeroize", ] -[[package]] -name = "is_terminal_polyfill" -version = "1.70.2" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a6cb138bb79a146c1bd460005623e142ef0181e3d0219cb493e02f7d08a35695" - [[package]] name = "itertools" version = "0.14.0" @@ -1187,30 +1141,6 @@ version = "1.0.17" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "92ecc6618181def0457392ccd0ee51198e065e016d1d527a7ac1b6dc7c1f09d2" -[[package]] -name = "jiff" -version = "0.2.23" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1a3546dc96b6d42c5f24902af9e2538e82e39ad350b0c766eb3fbf2d8f3d8359" -dependencies = [ - "jiff-static", - "log", - "portable-atomic", - "portable-atomic-util", - "serde_core", -] - -[[package]] -name = "jiff-static" -version = "0.2.23" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2a8c8b344124222efd714b73bb41f8b5120b27a7cc1c75593a6ff768d9d05aa4" -dependencies = [ - "proc-macro2", - "quote", - "syn 2.0.117", -] - [[package]] name = "js-sys" version = "0.3.91" @@ -1387,7 +1317,7 @@ name = "mudserver" version = "0.2.0" dependencies = [ "crossterm 0.28.1", - "env_logger", + "flexi_logger", "log", "rand", "ratatui", @@ -1423,6 +1353,15 @@ dependencies = [ "minimal-lexical", ] +[[package]] +name = "nu-ansi-term" +version = "0.50.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5" +dependencies = [ + "windows-sys 0.61.2", +] + [[package]] name = "num-bigint" version = "0.4.6" @@ -1512,12 +1451,6 @@ version = "1.21.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9f7c3e4beb33f85d45ae3e3a1792185706c8e16d043238c593331cc7cd313b50" -[[package]] -name = "once_cell_polyfill" -version = "1.70.2" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "384b8ab6d37215f3c5301a95a4accb5d64aa607f1fcb26a11b5303878451b4fe" - [[package]] name = "opaque-debug" version = "0.3.1" @@ -1815,15 +1748,6 @@ version = "1.13.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c33a9471896f1c69cecef8d20cbe2f7accd12527ce60845ff44c153bb2a21b49" -[[package]] -name = "portable-atomic-util" -version = "0.2.6" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "091397be61a01d4be58e7841595bd4bfedb15f1cd54977d79b8271e94ed799a3" -dependencies = [ - "portable-atomic", -] - [[package]] name = "powerfmt" version = "0.2.0" diff --git a/Cargo.toml b/Cargo.toml index 457f726..5b45c07 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -13,6 +13,6 @@ rusqlite = { version = "0.35", features = ["bundled"] } ratatui = "0.30" crossterm = "0.28" log = "0.4" -env_logger = "0.11" +flexi_logger = { version = "0.29", features = ["async"] } regex = "1" rand = "0.8" diff --git a/src/admin.rs b/src/admin.rs index 01c4d2f..5249237 100644 --- a/src/admin.rs +++ b/src/admin.rs @@ -74,6 +74,7 @@ async fn admin_promote(target: &str, state: &SharedState) -> CommandResult { if target.is_empty() { return simple(&format!("{}\r\n", ansi::error_msg("Usage: admin promote "))); } + log::info!("Admin action: promote player '{}'", target); let st = state.lock().await; if st.db.set_admin(target, true) { // Also update in-memory if online @@ -124,6 +125,7 @@ async fn admin_demote(target: &str, state: &SharedState) -> CommandResult { if target.is_empty() { return simple(&format!("{}\r\n", ansi::error_msg("Usage: admin demote "))); } + log::info!("Admin action: demote player '{}'", target); let st = state.lock().await; if st.db.set_admin(target, false) { simple(&format!( @@ -142,6 +144,7 @@ async fn admin_kick(target: &str, player_id: usize, state: &SharedState) -> Comm if target.is_empty() { return simple(&format!("{}\r\n", ansi::error_msg("Usage: admin kick "))); } + log::info!("Admin action: kick player '{}'", target); let mut st = state.lock().await; let low = target.to_lowercase(); @@ -237,6 +240,7 @@ async fn admin_teleport(room_id: &str, player_id: usize, state: &SharedState) -> ansi::error_msg("Usage: admin teleport ") )); } + log::info!("Admin action: teleport player ID {} to '{}'", player_id, room_id); let mut st = state.lock().await; if st.world.get_room(room_id).is_none() { let rooms: Vec<&String> = st.world.rooms.keys().collect(); @@ -329,6 +333,7 @@ async fn admin_teleport(room_id: &str, player_id: usize, state: &SharedState) -> } async fn admin_registration(args: &str, state: &SharedState) -> CommandResult { + log::info!("Admin action: registration setting updated: '{}'", args); let st = state.lock().await; match args.to_lowercase().as_str() { "on" | "true" | "open" => { @@ -365,6 +370,7 @@ async fn admin_announce(msg: &str, player_id: usize, state: &SharedState) -> Com ansi::error_msg("Usage: admin announce ") )); } + log::info!("Admin action: announcement by player ID {}: '{}'", player_id, msg); let st = state.lock().await; let announcement = CryptoVec::from( format!( @@ -405,6 +411,7 @@ async fn admin_announce(msg: &str, player_id: usize, state: &SharedState) -> Com } async fn admin_heal(args: &str, player_id: usize, state: &SharedState) -> CommandResult { + log::info!("Admin action: heal player '{}' (empty means self)", args); let mut st = state.lock().await; if args.is_empty() { @@ -564,6 +571,7 @@ async fn admin_info(target: &str, state: &SharedState) -> CommandResult { } async fn admin_setattitude(args: &str, state: &SharedState) -> CommandResult { + log::info!("Admin action: setattitude '{}'", args); let parts: Vec<&str> = args.splitn(3, ' ').collect(); if parts.len() < 3 { return simple(&format!( diff --git a/src/combat.rs b/src/combat.rs index 1307ba4..61314c1 100644 --- a/src/combat.rs +++ b/src/combat.rs @@ -69,6 +69,8 @@ pub fn resolve_combat_tick( )); if new_npc_hp <= 0 { + let player_name = state.players.get(&player_id).map(|c| c.player.name.clone()).unwrap_or_else(|| "Unknown".into()); + log::info!("Combat: Player '{}' (ID {}) killed NPC '{}' ({})", player_name, player_id, npc_template.name, npc_id); if let Some(inst) = state.npc_instances.get_mut(&npc_id) { inst.alive = false; inst.hp = 0; @@ -351,7 +353,9 @@ pub fn player_death_respawn(player_id: usize, state: &mut GameState) -> String { .players .get(&player_id) .map(|c| c.player.name.clone()) - .unwrap_or_default(); + .unwrap_or_else(|| "Unknown".into()); + + log::info!("Combat: Player '{}' (ID {}) died and respawned at {}", player_name, player_id, spawn_room); if let Some(conn) = state.players.get_mut(&player_id) { conn.player.stats.hp = conn.player.stats.max_hp; diff --git a/src/main.rs b/src/main.rs index 41cf891..8b8e744 100644 --- a/src/main.rs +++ b/src/main.rs @@ -2,6 +2,7 @@ use std::path::PathBuf; use std::sync::Arc; use tokio::sync::Mutex; +use flexi_logger::{Cleanup, Criterion, Duplicate, FileSpec, Logger, Naming, WriteMode}; use russh::keys::ssh_key::rand_core::OsRng; use russh::server::Server as _; use tokio::net::TcpListener; @@ -18,12 +19,12 @@ const DEFAULT_DB_PATH: &str = "./mudserver.db"; #[tokio::main] async fn main() { - env_logger::Builder::from_env(env_logger::Env::default().default_filter_or("info")).init(); - let mut port = DEFAULT_PORT; let mut jsonrpc_port = 2223; let mut world_dir = PathBuf::from(DEFAULT_WORLD_DIR); let mut db_path = PathBuf::from(DEFAULT_DB_PATH); + let mut log_dir = "logs".to_string(); + let mut log_level = "info".to_string(); let args: Vec = std::env::args().collect(); let mut i = 1; @@ -51,12 +52,22 @@ async fn main() { i += 1; db_path = PathBuf::from(args.get(i).expect("--db requires a path")); } + "--log-dir" => { + i += 1; + log_dir = args.get(i).expect("--log-dir requires a path").to_string(); + } + "--log-level" => { + i += 1; + log_level = args.get(i).expect("--log-level requires a level").to_string(); + } "--help" => { eprintln!("Usage: mudserver [OPTIONS]"); eprintln!(" --port, -p SSH listen port (default: {DEFAULT_PORT})"); eprintln!(" --rpc-port JSON-RPC listen port (default: 2223)"); eprintln!(" --world, -w World directory (default: {DEFAULT_WORLD_DIR})"); eprintln!(" --db, -d Database path (default: {DEFAULT_DB_PATH})"); + eprintln!(" --log-dir Directory for log files (default: logs)"); + eprintln!(" --log-level Logging level (default: info)"); std::process::exit(0); } other => { @@ -67,6 +78,23 @@ async fn main() { i += 1; } + // Initialize logger + Logger::try_with_str(&log_level) + .unwrap() + .log_to_file(FileSpec::default().directory(&log_dir).basename("mudserver")) + .duplicate_to_stderr(Duplicate::All) + .rotate( + Criterion::Size(10_000_000), // 10 MB + Naming::Numbers, + Cleanup::KeepLogFiles(7), + ) + .write_mode(WriteMode::BufferAndFlush) + .start() + .unwrap_or_else(|e| { + eprintln!("Failed to initialize logger: {e}"); + std::process::exit(1); + }); + log::info!("Loading world from: {}", world_dir.display()); let loaded_world = world::World::load(&world_dir).unwrap_or_else(|e| { eprintln!("Failed to load world: {e}"); diff --git a/src/ssh.rs b/src/ssh.rs index 658ce4e..2751cde 100644 --- a/src/ssh.rs +++ b/src/ssh.rs @@ -83,6 +83,8 @@ impl MudHandler { state.load_existing_player(self.id, saved, Some(channel), Some(handle)); drop(state); + log::info!("Player '{}' (id={}) logged in", self.username, self.id); + let msg = format!( "{}\r\n", ansi::system_msg("Welcome back! Your character has been restored.") @@ -171,6 +173,13 @@ impl MudHandler { .map(|c| c.name.clone()) .unwrap_or_default(); + log::info!( + "New character created: {} (Race: {}, Class: {})", + self.username, + race_name, + class_name + ); + state.create_new_player( self.id, self.username.clone(),