add tracing

Cargo.lock

@@ -511,6 +511,9 @@ dependencies = [
  "serde",
  "serde_json",
  "tokio",
+ "tracing",
+ "tracing-appender",
+ "tracing-subscriber",
 ]
 
 [[package]]
@@ -1031,6 +1034,12 @@ dependencies = [
  "wasm-bindgen",
 ]
 
+[[package]]
+name = "lazy_static"
+version = "1.5.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe"
+
 [[package]]
 name = "libc"
 version = "0.2.159"
@@ -1079,6 +1088,15 @@ dependencies = [
  "tendril",
 ]
 
+[[package]]
+name = "matchers"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558"
+dependencies = [
+ "regex-automata 0.1.10",
+]
+
 [[package]]
 name = "memchr"
 version = "2.7.4"
@@ -1160,6 +1178,16 @@ version = "1.0.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "650eef8c711430f1a879fdd01d4745a7deea475becfb90269c06775983bbf086"
 
+[[package]]
+name = "nu-ansi-term"
+version = "0.46.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84"
+dependencies = [
+ "overload",
+ "winapi",
+]
+
 [[package]]
 name = "num-conv"
 version = "0.1.0"
@@ -1175,6 +1203,15 @@ dependencies = [
  "autocfg",
 ]
 
+[[package]]
+name = "num_threads"
+version = "0.1.7"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5c7398b9c8b70908f6371f47ed36737907c87c52af34c268fed0bf0ceb92ead9"
+dependencies = [
+ "libc",
+]
+
 [[package]]
 name = "object"
 version = "0.36.5"
@@ -1234,6 +1271,12 @@ dependencies = [
  "vcpkg",
 ]
 
+[[package]]
+name = "overload"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39"
+
 [[package]]
 name = "parking_lot"
 version = "0.12.3"
@@ -1513,8 +1556,17 @@ checksum = "38200e5ee88914975b69f657f0801b6f6dccafd44fd9326302a4aaeecfacb1d8"
 dependencies = [
  "aho-corasick",
  "memchr",
- "regex-automata",
+ "regex-automata 0.4.8",
- "regex-syntax",
+ "regex-syntax 0.8.5",
+]
+
+[[package]]
+name = "regex-automata"
+version = "0.1.10"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132"
+dependencies = [
+ "regex-syntax 0.6.29",
 ]
 
 [[package]]
@@ -1525,9 +1577,15 @@ checksum = "368758f23274712b504848e9d5a6f010445cc8b87a7cdb4d7cbee666c1288da3"
 dependencies = [
  "aho-corasick",
  "memchr",
- "regex-syntax",
+ "regex-syntax 0.8.5",
 ]
 
+[[package]]
+name = "regex-syntax"
+version = "0.6.29"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1"
+
 [[package]]
 name = "regex-syntax"
 version = "0.8.5"
@@ -1965,6 +2023,15 @@ dependencies = [
  "digest",
 ]
 
+[[package]]
+name = "sharded-slab"
+version = "0.1.7"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6"
+dependencies = [
+ "lazy_static",
+]
+
 [[package]]
 name = "shlex"
 version = "1.3.0"
@@ -2205,6 +2272,16 @@ dependencies = [
  "syn 2.0.79",
 ]
 
+[[package]]
+name = "thread_local"
+version = "1.1.8"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8b9ef9bad013ada3808854ceac7b46812a6465ba368859a37e2100283d2d719c"
+dependencies = [
+ "cfg-if",
+ "once_cell",
+]
+
 [[package]]
 name = "time"
 version = "0.3.36"
@@ -2213,7 +2290,9 @@ checksum = "5dfd88e563464686c916c7e46e623e520ddc6d79fa6641390f2e3fa86e83e885"
 dependencies = [
  "deranged",
  "itoa",
+ "libc",
  "num-conv",
+ "num_threads",
  "powerfmt",
  "serde",
  "time-core",
@@ -2369,6 +2448,18 @@ dependencies = [
  "tracing-core",
 ]
 
+[[package]]
+name = "tracing-appender"
+version = "0.2.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "3566e8ce28cc0a3fe42519fc80e6b4c943cc4c8cef275620eb8dac2d3d4e06cf"
+dependencies = [
+ "crossbeam-channel",
+ "thiserror",
+ "time",
+ "tracing-subscriber",
+]
+
 [[package]]
 name = "tracing-attributes"
 version = "0.1.27"
@@ -2387,6 +2478,50 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54"
 dependencies = [
  "once_cell",
+ "valuable",
+]
+
+[[package]]
+name = "tracing-log"
+version = "0.2.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3"
+dependencies = [
+ "log",
+ "once_cell",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-serde"
+version = "0.1.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1"
+dependencies = [
+ "serde",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.3.18"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b"
+dependencies = [
+ "matchers",
+ "nu-ansi-term",
+ "once_cell",
+ "regex",
+ "serde",
+ "serde_json",
+ "sharded-slab",
+ "smallvec",
+ "thread_local",
+ "time",
+ "tracing",
+ "tracing-core",
+ "tracing-log",
+ "tracing-serde",
 ]
 
 [[package]]
@@ -2523,6 +2658,12 @@ version = "0.7.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "09cc8ee72d2a9becf2f2febe0205bbed8fc6615b7cb429ad062dc7b7ddd036a9"
 
+[[package]]
+name = "valuable"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d"
+
 [[package]]
 name = "vcpkg"
 version = "0.2.15"
@@ -2665,6 +2806,22 @@ dependencies = [
  "rustls-pki-types",
 ]
 
+[[package]]
+name = "winapi"
+version = "0.3.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5c839a674fcd7a98952e593242ea400abe93992746761e38641405d28b00f419"
+dependencies = [
+ "winapi-i686-pc-windows-gnu",
+ "winapi-x86_64-pc-windows-gnu",
+]
+
+[[package]]
+name = "winapi-i686-pc-windows-gnu"
+version = "0.4.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6"
+
 [[package]]
 name = "winapi-util"
 version = "0.1.9"
@@ -2674,6 +2831,12 @@ dependencies = [
  "windows-sys 0.59.0",
 ]
 
+[[package]]
+name = "winapi-x86_64-pc-windows-gnu"
+version = "0.4.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f"
+
 [[package]]
 name = "windows-core"
 version = "0.52.0"

Cargo.toml

@@ -14,6 +14,12 @@ scraper = "0.20.0"
 serde = { version = "1.0.210", features = ["derive"] }
 serde_json = "1.0.128"
 tokio = { version = "1.40.0", features = ["full", "rt"] }
+tracing = "0.1"
+tracing-appender = "0.2"
+
+[dependencies.tracing-subscriber]
+version = "0.3.16"
+features = ["env-filter", "fmt", "json", "local-time", "time"]
 
 [profile.release]
 lto = "fat"

src/commands.rs

@@ -2,6 +2,7 @@ use std::sync::Arc;
 
 use poise::{serenity_prelude::CreateAttachment, CreateReply};
 use tokio::sync::Mutex;
+use tracing::{info, trace};
 
 use crate::{
     context::{create_context, save_context},
@@ -36,6 +37,7 @@ pub async fn context(_: Context<'_>) -> Result<(), Error> {
 
 #[poise::command(prefix_command, slash_command)]
 pub async fn reset(ctx: Context<'_>) -> Result<(), Error> {
+    info!("/fend context reset by {}", ctx.author().id);
     let id = ctx.author().id.get();
 
     let mut data = ctx.data().context.lock().await;
@@ -56,6 +58,13 @@ pub async fn define_custom_unit(
     definition: String,
     plural: Option<String>,
 ) -> Result<(), Error> {
+    info!(
+        "/fend context define_custom_unit {} {} {:?} by {}",
+        singular,
+        definition,
+        plural,
+        ctx.author().id
+    );
     let plural = plural.unwrap_or_default();
     let author = ctx.author().id.get();
 
@@ -87,6 +96,7 @@ pub async fn define_custom_unit(
 
 #[poise::command(prefix_command, slash_command)]
 pub async fn calc(ctx: Context<'_>, expr: String) -> Result<(), Error> {
+    info!("/calc {} by {}", expr, ctx.author().id);
     ctx.defer().await.unwrap();
 
     let author = ctx.author().id.get();
@@ -102,6 +112,7 @@ pub async fn calc(ctx: Context<'_>, expr: String) -> Result<(), Error> {
     };
     let context = Arc::new(Mutex::new(context));
 
+    trace!("Evaluating {}", expr);
     let result = tokio::task::spawn_blocking({
         let context = context.clone();
         let expr = expr.clone();
@@ -118,6 +129,7 @@ pub async fn calc(ctx: Context<'_>, expr: String) -> Result<(), Error> {
     .await;
 
     if let Err(_) = ctx.reply(format!("> {}\n{}", expr, result)).await {
+        trace!("Reply using file");
         ctx.reply("Sending result...").await.unwrap();
         ctx.send(CreateReply::default().attachment(CreateAttachment::bytes(
             format!("> {}\n{}", expr, result),

src/context.rs

@@ -6,8 +6,10 @@ use std::{
 };
 
 use anyhow::{anyhow, Result};
+use tracing::{error, trace};
 
 pub fn create_context() -> fend_core::Context {
+    trace!("Creating new context");
     let mut context = fend_core::Context::new();
     context.set_random_u32_fn(rand::random);
     context.define_custom_unit_v1(
@@ -44,18 +46,21 @@ pub fn create_context() -> fend_core::Context {
 }
 
 pub fn save_context(ctx: &fend_core::Context, id: u64) {
+    trace!("Saving context");
     let file = File::create(format!("./context/{}", id)).unwrap();
     let mut writer = BufWriter::new(file);
     ctx.serialize_variables(&mut writer).unwrap();
 }
 
 pub fn read_context(path: PathBuf) -> Result<fend_core::Context> {
+    trace!("Reading context");
     let mut context = create_context();
 
     let file = File::open(path)?;
     let mut reader = BufReader::new(file);
 
     if let Err(_) = context.deserialize_variables(&mut reader) {
+        error!("Cannot deserialize variable");
         return Err(anyhow!("Cannot deserialize variables"));
     }
 
@@ -63,10 +68,12 @@ pub fn read_context(path: PathBuf) -> Result<fend_core::Context> {
 }
 
 pub fn restore_contexts() -> HashMap<u64, fend_core::Context> {
+    trace!("Restoring contexts");
     let mut result = HashMap::new();
     let mut dir = if let Ok(dir) = std::fs::read_dir("./context") {
         dir
     } else {
+        trace!("Creating context dir");
         std::fs::create_dir("./context").unwrap();
         return HashMap::new();
     };
@@ -75,6 +82,7 @@ pub fn restore_contexts() -> HashMap<u64, fend_core::Context> {
         let id = if let Ok(id) = u64::from_str_radix(entry.file_name().to_str().unwrap(), 10) {
             id
         } else {
+            trace!("Cannot parse id: {}", entry.file_name().to_str().unwrap());
             continue;
         };
 

src/main.rs

@@ -9,6 +9,7 @@ use std::{
     env,
     sync::Arc,
 };
+use tracing::{info, Level};
 
 use poise::{
     serenity_prelude::{self as serenity, futures::lock::Mutex, UserId},
@@ -25,6 +26,9 @@ pub struct Data {
 
 #[tokio::main]
 async fn main() -> Result<()> {
+    tracing_subscriber::fmt()
+        .with_max_level(Level::TRACE)
+        .init();
     let token = env::var("BOT_TOKEN")?;
     let owner = u64::from_str_radix(&env::var("BOT_OWNER")?, 10)?;
     let prefix = env::var("BOT_PREFIX")?;
@@ -34,6 +38,8 @@ async fn main() -> Result<()> {
 
     let contexts = restore_contexts();
 
+    info!("Creating bot client");
+
     let framework = poise::Framework::builder()
         .setup(move |_ctx, _ready, _framework| {
             Box::pin(async move {
@@ -54,6 +60,8 @@ async fn main() -> Result<()> {
         })
         .build();
 
+    info!("Starting bot client");
+
     let client = serenity::ClientBuilder::new(token, intents)
         .framework(framework)
         .await;