diff --git a/Cargo.toml b/Cargo.toml index 5d7dc94..de3d032 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -19,6 +19,14 @@ futures-util = "0.3" tokio = "1.43" tokio-stream = "0.1" +tracing = { version = "0.1", features = ["std"] } +tracing-subscriber = { version = "0.3", features = ["env-filter","registry", "std", "fmt"] } +opentelemetry_sdk = "0.30" +opentelemetry-appender-tracing = "0.30" +tracing-opentelemetry = "0.31" +opentelemetry = { version = "0.30", features = ["trace"] } +opentelemetry-otlp = { version = "0.30", features = ["http-proto", "grpc-tonic"] } + mongodb = "3.2" redis = { version = "0.29", features = ["aio", "tokio-comp"] } diff --git a/src/commands/context.rs b/src/commands/context.rs index bc23034..34a50a1 100644 --- a/src/commands/context.rs +++ b/src/commands/context.rs @@ -24,6 +24,7 @@ macro_rules! extract { }; } +#[derive(Debug, Clone)] pub struct InteractionContext { pub command_vec: Vec, pub command_text: String, diff --git a/src/database/mongodb.rs b/src/database/mongodb.rs index 3866eac..c4c392d 100644 --- a/src/database/mongodb.rs +++ b/src/database/mongodb.rs @@ -5,6 +5,7 @@ use mongodb::{Client, Collection, Database}; use mongodb::bson::doc; #[cfg(feature = "tasks")] use mongodb::bson::DateTime; +use tracing::info; use twilight_model::channel::message::Embed; use twilight_model::id::Id; use twilight_model::id::marker::{ChannelMarker, GuildMarker, UserMarker}; @@ -32,6 +33,7 @@ impl MongoDBConnection { pub async fn connect(uri: String) -> Result { let client = Client::with_uri_str(uri).await?; + info!("connected to MongoDB"); let db = client.database("custom"); let configs = db.collection::("configs"); let cases = db.collection("cases"); @@ -52,7 +54,6 @@ impl MongoDBConnection { } pub async fn get_config(&self, guild_id: Id) -> Result { - match self.configs_cache.get(&guild_id){ Some(config) => { Ok(config.to_owned()) @@ -62,9 +63,14 @@ impl MongoDBConnection { doc! { "guild_id": guild_id.to_string() } - ).await?.unwrap_or_else(|| GuildConfig::new(guild_id)); + ).await?.unwrap_or_else(|| GuildConfig::new(guild_id.to_owned())); self.configs_cache.insert(guild_id, config.to_owned()); + info!( + name: "cached guild config", + cache_size = self.configs_cache.len(), + %guild_id, + ); Ok(config) } diff --git a/src/database/redis.rs b/src/database/redis.rs index b99b8ad..66b82f9 100644 --- a/src/database/redis.rs +++ b/src/database/redis.rs @@ -10,6 +10,7 @@ use crate::utils::errors::Error; use redis::AsyncCommands; use tokio::sync::mpsc::UnboundedSender; use tokio::sync::mpsc::error::SendError; +use tracing::info; use crate::database::mongodb::MongoDBConnection; #[derive(Serialize, Deserialize, Debug)] @@ -127,7 +128,6 @@ impl RedisConnection { &self, mongodb: &MongoDBConnection ) -> Result<(), RedisError> { - let mut pubsub = self.client.get_async_pubsub().await?; pubsub.subscribe("configs").await?; @@ -135,8 +135,13 @@ impl RedisConnection { const ERROR: &str = "Received invalid payload instead of guild id"; let id: String = message.get_payload().expect(ERROR); let id: Id = Id::from_str(id.as_str()).expect(ERROR); - println!("There is a guild config update id={id}"); mongodb.configs_cache.remove(&id); + + info!( + name: "removed config from cache due to update", + cache_size = mongodb.configs_cache.len(), + guild_id = %id, + ); } Ok(()) diff --git a/src/events/automod/mod.rs b/src/events/automod/mod.rs index 75fbc47..d545e65 100644 --- a/src/events/automod/mod.rs +++ b/src/events/automod/mod.rs @@ -3,11 +3,12 @@ mod checks; mod filters; use std::sync::Arc; +use tracing::info; use twilight_http::Client; use twilight_model::channel::Message; use crate::context::Context; use crate::events::automod::actions::run_action; -use crate::models::config::automod::TrigerEvent; +use crate::models::config::automod::TriggerEvent; use crate::models::config::automod::ignore::{Ignore, IgnoreMode}; fn is_ignored(message: &Message, ignore_rule: &Option) -> bool { @@ -37,7 +38,7 @@ pub async fn run( message: Message, discord_http: Arc, context: Arc, - triger: TrigerEvent + trigger: TriggerEvent ) -> Result<(), ()> { let guild_id = message.guild_id.ok_or(())?; let guild_config = Arc::new(context.mongodb.get_config(guild_id).await.map_err(|_| ())?); @@ -52,7 +53,7 @@ pub async fn run( let message = Arc::new(message); for automod_rule in &automod_config.rules { - if triger == TrigerEvent::MessageUpdate && !automod_rule.check_on_edit { continue } + if trigger == TriggerEvent::MessageUpdate && !automod_rule.check_on_edit { continue } if is_ignored(&message, &automod_rule.ignore) { continue } for filter_meta in &automod_rule.filters { @@ -64,6 +65,8 @@ pub async fn run( if !is_allowed { return Ok(()) } } + info!(name: "automod rule violated", ?message, ?automod_rule, ?trigger); + for action in &automod_rule.actions { let run = run_action( action.action.to_owned(), diff --git a/src/events/mod.rs b/src/events/mod.rs index 34f0a99..5cf2c23 100644 --- a/src/events/mod.rs +++ b/src/events/mod.rs @@ -3,7 +3,7 @@ use twilight_http::Client; use twilight_model::gateway::event::Event; use twilight_model::gateway::payload::incoming::GuildCreate; use crate::context::Context; -use crate::models::config::automod::TrigerEvent; +use crate::models::config::automod::TriggerEvent; pub mod automod; mod case; @@ -27,11 +27,11 @@ pub async fn on_event( } Event::MessageCreate(event) => { let message = event.as_ref().0.to_owned(); - self::automod::run(message.to_owned(), discord_http, context.to_owned(), TrigerEvent::MessageCreate).await.ok(); + self::automod::run(message.to_owned(), discord_http, context.to_owned(), TriggerEvent::MessageCreate).await.ok(); self::top::run(message, context).await.ok(); } Event::MessageUpdate(event) => { - self::automod::run(event.0, discord_http, context, TrigerEvent::MessageCreate).await.ok(); + self::automod::run(event.0, discord_http, context, TriggerEvent::MessageCreate).await.ok(); } Event::GuildCreate(event) => { let guild = if let GuildCreate::Available(guild) = *event { guild } else { return Ok(()) }; diff --git a/src/events/setup.rs b/src/events/setup.rs index adaf04c..7a01dfc 100644 --- a/src/events/setup.rs +++ b/src/events/setup.rs @@ -1,4 +1,5 @@ use std::sync::Arc; +use tracing::info; use twilight_http::Client; use twilight_model::id::Id; use twilight_model::id::marker::GuildMarker; @@ -16,6 +17,11 @@ pub async fn run( } } else { return Ok(()); }; + info!( + name: "registering setup command", + %guild_id + ); + let application_id = twilight_http.current_user() .await.map_err(Error::from)?.model().await.map_err(Error::from)?.id; twilight_http diff --git a/src/gateway/shard.rs b/src/gateway/shard.rs index 3214ed8..d0f83a2 100644 --- a/src/gateway/shard.rs +++ b/src/gateway/shard.rs @@ -1,4 +1,5 @@ use std::sync::Arc; +use tracing::error; use twilight_gateway::{EventTypeFlags, Shard, StreamExt}; use twilight_model::gateway::{Intents, ShardId}; use crate::context::Context; @@ -10,7 +11,13 @@ pub async fn connect_shards( context: Arc ) { let token = if let Some(token) = http.token() { token.to_string() } - else { eprintln!("Cannot get token of client {id}"); return }; + else { + error!( + name: "cannot get token of client", + client_id = %id + ); + return + }; let intents = Intents::MESSAGE_CONTENT | Intents::GUILD_MESSAGES | Intents::GUILDS | Intents::GUILD_MODERATION | Intents::GUILD_MEMBERS; @@ -20,8 +27,10 @@ pub async fn connect_shards( let event = match event { Ok(event) => event, Err(err) => { - eprintln!( - "error while receiving events on shard {shard} with {id} client\n{err}", + error!( + name: "error while receiving events", + error = %err, + client_id = %id, shard = shard.id().number() ); continue; diff --git a/src/main.rs b/src/main.rs index 829d0d0..f47f040 100644 --- a/src/main.rs +++ b/src/main.rs @@ -2,6 +2,7 @@ use std::sync::Arc; use crate::context::Context; use dotenv::dotenv; use tokio::task::JoinHandle; +use tracing::info; use twilight_http::Client; all_macro!( @@ -24,11 +25,15 @@ mod database; mod models; pub mod utils; mod server; +mod tracing_init; #[tokio::main] async fn main() { dotenv().ok(); + tracing_init::init(); + info!("starting app"); + let context = Arc::new(Context::new().await); let cloned_context = context.clone(); diff --git a/src/models/config/automod/mod.rs b/src/models/config/automod/mod.rs index 6f6a18c..ac76329 100644 --- a/src/models/config/automod/mod.rs +++ b/src/models/config/automod/mod.rs @@ -41,8 +41,8 @@ pub struct AutoModerationRule { pub name: String, } -#[derive(PartialEq)] -pub enum TrigerEvent { +#[derive(PartialEq, Debug)] +pub enum TriggerEvent { MessageCreate, MessageUpdate -} \ No newline at end of file +} diff --git a/src/server/error.rs b/src/server/error.rs index 9d2d2b4..3de9f65 100644 --- a/src/server/error.rs +++ b/src/server/error.rs @@ -63,7 +63,6 @@ impl> MapErrorIntoInternalRejection for Result Result { - println!("{:?}", rejection); Ok(if let Some(rejection) = rejection.find::() { warp::reply::with_status(rejection.to_string(), match rejection { #[cfg(feature = "http-interactions")] diff --git a/src/server/guild/editing.rs b/src/server/guild/editing.rs index 3d60595..07dcd0a 100644 --- a/src/server/guild/editing.rs +++ b/src/server/guild/editing.rs @@ -4,6 +4,7 @@ use mongodb::bson::doc; use mongodb::bson::oid::ObjectId; use serde_json::{Map, Value}; use tokio::sync::{Mutex, RwLock}; +use tracing::{error, warn}; use twilight_model::id::Id; use twilight_model::id::marker::{GuildMarker, UserMarker}; use crate::context::Context; @@ -78,7 +79,7 @@ impl GuildsEditing { let config = context.mongodb .get_config(guild_id) .await - .inspect_err(|error| println!("{error:?}")) + .inspect_err(|error| error!(name: "mongodb error", ?error)) .ok()?; let guild = self.get_guild(guild_id).await?; @@ -100,7 +101,7 @@ impl GuildsEditing { pub async fn apply_changes(&self, context: &Arc, guild_id: Id) -> Option<()> { let config = context.mongodb.get_config(guild_id).await - .inspect_err(|error| println!("{error:?}")) + .inspect_err(|error| error!(name: "mongodb error", ?error)) .ok()?; let is_guild_premium = config.premium; @@ -109,20 +110,20 @@ impl GuildsEditing { let mut guild_lock = guild.lock().await; let mut new_config = serde_json::to_value(config) - .inspect_err(|error| println!("{error:?}")) + .inspect_err(|error| error!(name: "cannot convert guild config to value", ?error)) .ok()?; json_patch::merge(&mut new_config, &guild_lock.changes); let new_config: GuildConfig = serde_json::from_value(new_config) - .inspect_err(|error| println!("{error:?}")) + .inspect_err(|error| error!(name: "cannot marge edits with guild config", ?error)) .ok()?; if new_config.guild_id != guild_id { - println!("Someone tried changing guild_id in config id={guild_id}"); + warn!(name: "someone tried changing guild_id in guild config", %guild_id); return None } if new_config.premium != is_guild_premium { - println!("Someone tried changing premium in config id={guild_id}"); + warn!(name: "someone tried changing premium in guild config", %guild_id); return None } @@ -133,7 +134,7 @@ impl GuildsEditing { ) .upsert(true) .await - .inspect_err(|error| println!("{error:?}")) + .inspect_err(|error| error!(name: "mongodb error", ?error)) .ok()?; context.mongodb.configs_cache.remove(&guild_id); diff --git a/src/server/guild/ws.rs b/src/server/guild/ws.rs index 70f0741..267be3c 100644 --- a/src/server/guild/ws.rs +++ b/src/server/guild/ws.rs @@ -6,6 +6,7 @@ use serde::{Deserialize, Serialize}; use serde_json::Value; use tokio::sync::mpsc::UnboundedSender; use tokio_stream::wrappers::UnboundedReceiverStream; +use tracing::{error, info}; use twilight_model::id::Id; use twilight_model::id::marker::UserMarker; use twilight_model::user::CurrentUserGuild; @@ -121,7 +122,7 @@ pub async fn handle_connection( let message = match result { Ok(message) => message, Err(error) => { - println!("{error:?}"); + error!(name: "error while receiving message on ws_rx channel", ?error); break } }; @@ -186,10 +187,17 @@ async fn on_message( let _ = guilds_editing.broadcast_changes(&context, guild.id).await; } InboundMessage::ApplyChanges => { + info!( + name: "applying config changes", + author_id = %info.user.id, + guild_id = %guild.id + ); guilds_editing.apply_changes(&context, guild.id).await; let _ = guilds_editing.broadcast_changes(&context, guild.id).await; let _ = context.redis.announce_config_update(guild.id).await - .inspect_err(|error| println!("{error}")); + .inspect_err(|error| { + error!(name: "error sending guild_id to redis update announcer", ?error, %guild.id) + }); } } } diff --git a/src/server/interaction.rs b/src/server/interaction.rs index e70368a..ac97e16 100644 --- a/src/server/interaction.rs +++ b/src/server/interaction.rs @@ -1,4 +1,5 @@ use std::sync::Arc; +use tracing::{debug_span, debug, Instrument}; use twilight_model::application::interaction::{Interaction, InteractionType}; use twilight_http::Client; use twilight_model::channel::message::MessageFlags; @@ -34,11 +35,29 @@ async fn handle_command( let execute_as_slower = interaction_ctx.orginal.target_id().is_none() && context.application.is_slower(&command.name).await; + let span = debug_span!( + "command_execution", + module = command.module, + command_name = command.name, + %guild_id, + interaction = ?interaction_ctx.orginal, + ?config, + execute_as_slower, + ); + if execute_as_slower { tokio::spawn(async move { - let response = (command.run)( + let response = (command.run)( interaction_ctx, context, discord_http.to_owned(), config - ).await; + ).instrument(span).await; + + debug!( + command.name, + module = command.module, + ?response, + %guild_id, + "finished command execution" + ); let response_data = response.map(|(v, _)| v).unwrap_or_else(|e| e.to_interaction_data_response()); @@ -63,7 +82,19 @@ async fn handle_command( }, Some(InteractionResponseType::DeferredChannelMessageWithSource))) } else { - (command.run)(interaction_ctx, context, discord_http, config).await + let response = (command.run)(interaction_ctx, context, discord_http, config) + .instrument(span) + .await; + + debug!( + command.name, + module = command.module, + ?response, + %guild_id, + "finished command execution" + ); + + response } } diff --git a/src/server/routes/login.rs b/src/server/routes/login.rs index 9240535..6fd4832 100644 --- a/src/server/routes/login.rs +++ b/src/server/routes/login.rs @@ -1,6 +1,7 @@ use std::sync::Arc; use std::time::{SystemTime, UNIX_EPOCH}; use serde::{Deserialize, Serialize}; +use tracing::info; use twilight_http::Client; use twilight_model::user::CurrentUser; use twilight_model::util::Timestamp; @@ -117,6 +118,12 @@ async fn run( .model().await.map_rejection()?; let token = authenticator.generate_token(user.id).map_rejection()?; + info!( + name: "user logged in", + user_id = %user.id, + username = %user.name + ); + let reply = warp::reply::json(&Response { user: &user, token: &token @@ -134,6 +141,5 @@ async fn run( http, })).await; - - return Ok(Box::new(reply)) + Ok(Box::new(reply)) } \ No newline at end of file diff --git a/src/server/routes/mod.rs b/src/server/routes/mod.rs index 42ba34c..0b7d827 100644 --- a/src/server/routes/mod.rs +++ b/src/server/routes/mod.rs @@ -41,12 +41,15 @@ pub fn get_all_routes( ) }; + let tracing = warp::trace::request(); + #[cfg(feature = "api")] let filter = filter .or(login::login(authenticator.to_owned(), sessions.to_owned())) .or(users::me::run(authenticator.to_owned(), sessions.to_owned())) .or(guilds::_id::run(context.to_owned(), authenticator.to_owned(), sessions.to_owned())) - .or(guilds::list(context, authenticator, sessions)); + .or(guilds::list(context, authenticator, sessions)) + .with(tracing); filter } \ No newline at end of file diff --git a/src/tasks.rs b/src/tasks.rs index 1039fc8..a60b9e2 100644 --- a/src/tasks.rs +++ b/src/tasks.rs @@ -3,6 +3,7 @@ use std::time::Duration; use mongodb::bson::DateTime; use tokio::task::JoinHandle; use tokio::time::Instant; +use tracing::info; use twilight_http::Client; use twilight_model::id::Id; use twilight_model::id::marker::RoleMarker; @@ -30,7 +31,7 @@ pub async fn interval( if let Ok(tasks) = tasks { if !tasks.is_empty() { - println!("Loaded {} tasks", tasks.len()) + info!(name: "loaded tasks", count = tasks.len()) }; for task in tasks { diff --git a/src/tracing_init.rs b/src/tracing_init.rs new file mode 100644 index 0000000..10bbd9c --- /dev/null +++ b/src/tracing_init.rs @@ -0,0 +1,73 @@ +use opentelemetry::KeyValue; +use opentelemetry::trace::TracerProvider; +use opentelemetry_otlp::WithExportConfig; +use opentelemetry_sdk::Resource; +use std::time::Duration; +use tracing::{Level, warn}; +use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt; + +pub fn init() { + let endpoint = std::env::var("OTEL_ENDPOINT"); + + let fmt_layer = tracing_subscriber::fmt::layer(); + let subscriber = tracing_subscriber::Registry::default() + .with( + tracing_subscriber::filter::Targets::new() + .with_targets(vec![ + ("tower", Level::WARN), + ("hyper_util", Level::WARN), + ("opentelemetry-otlp", Level::WARN), + ("opentelemetry_sdk", Level::WARN), + ("tonic", Level::WARN), + ("h2", Level::WARN), + ]) + .with_default(Level::DEBUG), + ) + .with(tracing_subscriber::filter::LevelFilter::from_level( + Level::DEBUG, + )) + .with(fmt_layer); + + if let Ok(endpoint) = endpoint { + let span_exporter = opentelemetry_otlp::SpanExporter::builder() + .with_tonic() + .with_endpoint(endpoint.to_owned()) + .with_timeout(Duration::from_secs(3)) + .build() + .unwrap(); + let log_exporter = opentelemetry_otlp::LogExporter::builder() + .with_tonic() + .with_endpoint(endpoint) + .with_timeout(Duration::from_secs(3)) + .build() + .unwrap(); + + let resource = Resource::builder() + .with_attribute(KeyValue::new("service.name", "custom")) + .build(); + + let tracer_provider = opentelemetry_sdk::trace::SdkTracerProvider::builder() + .with_batch_exporter(span_exporter) + .with_resource(resource.to_owned()) + .build(); + let logs_provider = opentelemetry_sdk::logs::SdkLoggerProvider::builder() + .with_batch_exporter(log_exporter) + .with_resource(resource) + .build(); + + let tracer = tracer_provider.tracer("custom"); + + let otel_span_layer = tracing_opentelemetry::layer().with_tracer(tracer); + let otel_logs_layer = + opentelemetry_appender_tracing::layer::OpenTelemetryTracingBridge::new(&logs_provider); + + let subscriber = subscriber.with(otel_span_layer).with(otel_logs_layer); + + tracing::subscriber::set_global_default(subscriber).unwrap(); + } else { + tracing::subscriber::set_global_default(subscriber).unwrap(); + warn!( + "There is no OTEL_ENDPOINT environment variable, running with OpenTelemetry disabled" + ); + }; +} diff --git a/src/utils/errors.rs b/src/utils/errors.rs index e32488f..94e572d 100644 --- a/src/utils/errors.rs +++ b/src/utils/errors.rs @@ -94,7 +94,6 @@ impl Error { match self { Error::Debug(errors) => { - println!("{errors:?}"); let description = format!("```{}```", errors.join("``` ```")); EmbedBuilder::new() .title("Internal Server Error".to_string())