Add tracing and spans

WIP: #53

Cargo.toml

@@ -23,6 +23,10 @@ chrono = "0.4"
 url = "2"
 rand = {version = "0.8", features = ["small_rng"]}
 
+tracing = "0.1"
+tracing-subscriber = "0.2"
+tracing-futures = "0.2"
+
 [profile.release]
 opt-level = 3
 lto = true

src/checks.rs

@@ -4,6 +4,7 @@ use serenity::{
     model::prelude::*,
     prelude::Mentionable,
 };
+use tracing::{Instrument, Level, span};
 
 use crate::utils::SunnyError;
 
@@ -17,45 +18,48 @@ pub async fn in_same_voice_check(
     _args: &mut Args,
     _command_options: &CommandOptions,
 ) -> Result<(), Reason> {
-    let songbird = songbird::get(ctx)
-        .await
-        .ok_or_else(|| SunnyError::log("Failed to get songbird"))?;
-
-    let guild_id = msg
-        .guild_id
-        .ok_or_else(|| SunnyError::log("Guild ID Empty"))?;
-
-    let channel = {
-        let songbird_call_m = songbird
-            .get(guild_id)
-            .ok_or_else(|| SunnyError::user("Not currently in a call"))?;
-
-        let songbird_call = songbird_call_m.lock().await;
-
-        songbird_call
-            .current_channel()
-            .ok_or_else(|| SunnyError::log("Couldn't find songbird channel"))?
-    };
-
-    let name = ChannelId(channel.0);
-
-    let guild = msg
-        .guild(&ctx.cache)
-        .await
-        .ok_or_else(|| SunnyError::log("Couldn't get guild"))?;
-
-    let mut states = guild.voice_states.values();
-
-    states
-        .any(|vs| match vs.channel_id {
-            Some(c_id) => channel.0 == c_id.0 && vs.user_id.0 == msg.author.id.0,
-            None => false,
-        })
-        .then(|| ())
-        .ok_or_else(|| {
-            SunnyError::user(
-                format!("I only take requests from users in {}", name.mention()).as_str(),
-            )
-        })?;
-    Ok(())
+    let span = span!(Level::INFO, "in_same_voice_check", ?msg);
+    async move {
+        let songbird = songbird::get(ctx)
+            .await
+            .ok_or_else(|| SunnyError::log("Failed to get songbird"))?;
+
+        let guild_id = msg
+            .guild_id
+            .ok_or_else(|| SunnyError::log("Guild ID Empty"))?;
+
+        let channel = {
+            let songbird_call_m = songbird
+                .get(guild_id)
+                .ok_or_else(|| SunnyError::user("Not currently in a call"))?;
+
+            let songbird_call = songbird_call_m.lock().await;
+
+            songbird_call
+                .current_channel()
+                .ok_or_else(|| SunnyError::log("Couldn't find songbird channel"))?
+        };
+
+        let name = ChannelId(channel.0);
+
+        let guild = msg
+            .guild(&ctx.cache)
+            .await
+            .ok_or_else(|| SunnyError::log("Couldn't get guild"))?;
+
+        let mut states = guild.voice_states.values();
+
+        states
+            .any(|vs| match vs.channel_id {
+                Some(c_id) => channel.0 == c_id.0 && vs.user_id.0 == msg.author.id.0,
+                None => false,
+            })
+            .then(|| ())
+            .ok_or_else(|| {
+                SunnyError::user(
+                    format!("I only take requests from users in {}", name.mention()).as_str(),
+                )
+            })?;
+        Ok(())
+    }.instrument(span).await
 }

src/effects/display_queue.rs

@@ -11,6 +11,7 @@ use serenity::{
     },
 };
 use songbird::tracks::TrackHandle;
+use tracing::instrument;
 
 use crate::utils::{SunnyError, SunnyResult};
 
@@ -132,6 +133,7 @@ fn build_action_row(page: usize, queue_len: usize) -> CreateActionRow {
     row
 }
 
+#[instrument(skip(ctx))]
 async fn get_queue(ctx: &Context, guild_id: GuildId) -> SunnyResult<Vec<TrackHandle>> {
     Ok(songbird::get(ctx)
         .await
@@ -145,6 +147,7 @@ async fn get_queue(ctx: &Context, guild_id: GuildId) -> SunnyResult<Vec<TrackHan
 }
 
 /// Sends an interactive queue embed and interactions
+#[instrument(skip(ctx), name ="queue_embed")]
 pub async fn send_embed(
     ctx: &Context,
     guild_id: GuildId,

src/effects/join.rs

@@ -8,6 +8,7 @@ use std::{
 
 use serenity::prelude::Mutex;
 use songbird::{Call, Event, TrackEvent};
+use tracing::instrument;
 
 use crate::{
     handlers::{TimeoutHandler, TrackPlayNotifier},
@@ -17,10 +18,12 @@ use crate::{
 
 static IS_CONNECTING: AtomicBool = AtomicBool::new(false);
 
+#[instrument]
 async fn add_events(cfg: &EventConfig, call_m: Arc<Mutex<Call>>) {
     let mut call = call_m.lock().await;
     call.remove_all_global_events();
 
+
     call.add_global_event(
         Event::Track(TrackEvent::Play),
         TrackPlayNotifier { cfg: cfg.clone() },
@@ -35,6 +38,7 @@ async fn add_events(cfg: &EventConfig, call_m: Arc<Mutex<Call>>) {
     );
 }
 
+#[instrument]
 pub async fn join(cfg: &EventConfig) -> SunnyResult<Arc<Mutex<Call>>> {
     let songbird = songbird::get(&cfg.ctx)
         .await

src/effects/leave.rs

@@ -1,7 +1,9 @@
 use serenity::{client::Context, model::id::GuildId};
+use tracing::instrument;
 
 use crate::utils::{SunnyError, SunnyResult};
 
+#[instrument(skip(ctx))]
 pub async fn leave(ctx: &Context, guild_id: GuildId) -> SunnyResult<()> {
     let songbird = songbird::get(ctx)
         .await

src/effects/now_playing.rs

@@ -5,6 +5,7 @@ use serenity::{
     model::id::{ChannelId, GuildId},
 };
 use songbird::{input::Metadata, tracks::TrackHandle};
+use tracing::instrument;
 
 use crate::utils::{SunnyError, SunnyResult};
 
@@ -52,6 +53,7 @@ pub fn generate_embed(
 }
 
 /// Gets the current and next up song's [`TrackHandle`].
+#[instrument(skip(ctx))]
 async fn get_songs(
     ctx: &Context,
     guild_id: GuildId,
@@ -73,6 +75,7 @@ async fn get_songs(
 }
 
 /// Sends a `now_playing` embed and updates the progress every 10 seconds
+#[instrument(skip(ctx))]
 pub async fn send_embed(
     ctx: &Context,
     guild_id: GuildId,

src/effects/queue/pause.rs

@@ -1,7 +1,9 @@
 use serenity::{client::Context, model::id::GuildId};
+use tracing::instrument;
 
 use crate::utils::{SunnyError, SunnyResult};
 
+#[instrument(skip(ctx))]
 pub async fn pause(ctx: &Context, guild_id: GuildId) -> SunnyResult<()> {
     songbird::get(ctx)
         .await

src/effects/queue/play.rs

@@ -1,13 +1,16 @@
 use serenity::{client::Context, model::id::GuildId};
 use songbird::input::Restartable;
+use tracing::instrument;
 
 use crate::utils::{SunnyError, SunnyResult};
 
+#[derive(Debug)]
 pub enum EnqueueAt {
     Front,
     Back,
 }
 
+#[instrument(skip(ctx))]
 pub async fn play(
     ctx: &Context,
     guild_id: GuildId,

src/effects/queue/remove_at.rs

@@ -2,9 +2,11 @@ use std::num::NonZeroUsize;
 
 use serenity::{client::Context, model::id::GuildId};
 use songbird::tracks::Queued;
+use tracing::instrument;
 
 use crate::utils::{SunnyError, SunnyResult};
 
+#[instrument(skip(ctx))]
 pub async fn remove_at(ctx: &Context, guild_id: GuildId, at: NonZeroUsize) -> SunnyResult<Queued> {
     songbird::get(ctx)
         .await

src/effects/queue/resume.rs

@@ -1,7 +1,9 @@
 use serenity::{client::Context, model::id::GuildId};
+use tracing::instrument;
 
 use crate::utils::{SunnyError, SunnyResult};
 
+#[instrument(skip(ctx))]
 pub async fn resume(ctx: &Context, guild_id: GuildId) -> SunnyResult<()> {
     songbird::get(ctx)
         .await