Add logging

src/main.rs

@@ -1,4 +1,4 @@
-use std::{future::Future, path::Path};
+use std::{future::Future, io, path::Path};
 
 use ::serenity::all::{ChannelId, GuildId, UserId};
 use eyre::{Context as _, Error, OptionExt, Result};
@@ -6,6 +6,7 @@ use futures::{FutureExt, StreamExt, TryStreamExt};
 use poise::serenity_prelude as serenity;
 use rand::seq::SliceRandom;
 use rusqlite::OptionalExtension;
+use tracing_subscriber::{fmt::{self, format::FmtSpan}, layer::SubscriberExt, EnvFilter};
 
 #[derive(Copy, Clone)]
 struct GuildData {
@@ -18,13 +19,21 @@ struct GuildData {
 
 struct Data(tokio::sync::Mutex<rusqlite::Connection>);
 
+impl std::fmt::Debug for Data {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        write!(f, "Data {{}}")
+    }
+}
+
 impl Data {
+    #[tracing::instrument(skip(path))]
     fn open(path: impl AsRef<Path>) -> Result<Self> {
         let conn = rusqlite::Connection::open(path)?;
         conn.execute_batch("CREATE TABLE IF NOT EXISTS guilds(guild TEXT PRIMARY KEY NOT NULL, town_square TEXT NOT NULL, cottages TEXT NOT NULL, st TEXT, currently_playing TEXT);")?;
         Ok(Self(tokio::sync::Mutex::new(conn)))
     }
 
+    #[tracing::instrument]
     async fn get(&self, guild: serenity::GuildId) -> Result<GuildData> {
         self.0
             .lock()
@@ -43,6 +52,7 @@ impl Data {
             .ok_or_eyre("This bot has not been configured in this server!")
     }
 
+    #[tracing::instrument]
     async fn insert(
         &self,
         GuildData {
@@ -76,6 +86,7 @@ impl Data {
 
 type Context<'a> = poise::Context<'a, Data, Error>;
 
+#[tracing::instrument]
 async fn channel_children(
     ctx: &Context<'_>,
     channel: serenity::ChannelId,
@@ -91,19 +102,23 @@ async fn channel_children(
         .collect())
 }
 
+#[tracing::instrument]
 fn move_users<'a>(
     ctx: Context<'a>,
     guild: GuildId,
-    users: impl Iterator<Item = (ChannelId, UserId)> + Send + 'a,
+    users: Vec<(ChannelId, UserId)>,
 ) -> impl Future<Output = Result<()>> + Send + 'a {
-    futures::stream::iter(users.map(move |(channel, user)| async move {
+    futures::stream::iter(users.into_iter().map(move |(channel, user)| async move {
+        tracing::info!(?channel, ?user, "Moving user");
         guild.move_member(ctx, user, channel).await?;
+        tracing::info!(?channel, ?user, "Moved user");
         Ok(())
     }))
     .buffer_unordered(10)
     .try_collect::<()>()
 }
 
+#[tracing::instrument]
 async fn spread(
     ctx: Context<'_>,
     from: serenity::ChannelId,
@@ -132,7 +147,8 @@ async fn spread(
         guild,
         to.into_iter()
             .zip(&users)
-            .map(|(channel, user)| (channel.id, user.user.id)),
+            .map(|(channel, user)| (channel.id, user.user.id))
+            .collect(),
     )
     .await?;
 
@@ -140,6 +156,7 @@ async fn spread(
     Ok(())
 }
 
+#[tracing::instrument]
 async fn collect(
     ctx: Context<'_>,
     from: serenity::ChannelId,
@@ -158,7 +175,7 @@ async fn collect(
         .flatten()
         .collect::<Vec<_>>();
 
-    move_users(ctx, guild, users.iter().map(|user| (to, user.user.id))).await?;
+    move_users(ctx, guild, users.iter().map(|user| (to, user.user.id)).collect()).await?;
     futures::future::try_join_all(users.iter().map(|user| guild.move_member(&ctx, user, to)))
         .await?;
 
@@ -167,6 +184,7 @@ async fn collect(
 }
 
 #[poise::command(slash_command, prefix_command, ephemeral)]
+#[tracing::instrument]
 async fn dusk(ctx: Context<'_>) -> Result<()> {
     let guild = ctx
         .guild_id()
@@ -183,6 +201,7 @@ async fn dusk(ctx: Context<'_>) -> Result<()> {
 }
 
 #[poise::command(slash_command, prefix_command, ephemeral)]
+#[tracing::instrument]
 async fn dawn(ctx: Context<'_>) -> Result<()> {
     let guild = ctx
         .guild_id()
@@ -199,6 +218,7 @@ async fn dawn(ctx: Context<'_>) -> Result<()> {
 }
 
 #[poise::command(slash_command, ephemeral)]
+#[tracing::instrument]
 async fn join(
     ctx: Context<'_>,
     to: serenity::UserId,
@@ -232,6 +252,7 @@ async fn join(
 }
 
 #[poise::command(slash_command, ephemeral)]
+#[tracing::instrument]
 async fn st(ctx: Context<'_>, mut spectators: Vec<serenity::UserId>) -> Result<()> {
     let guild = ctx
         .guild_id()
@@ -263,6 +284,7 @@ async fn st(ctx: Context<'_>, mut spectators: Vec<serenity::UserId>) -> Result<(
 }
 
 #[poise::command(slash_command, ephemeral)]
+#[tracing::instrument]
 async fn currently_playing(ctx: Context<'_>, players: Vec<serenity::UserId>) -> Result<()> {
     let guild = ctx
         .guild_id()
@@ -283,6 +305,7 @@ async fn currently_playing(ctx: Context<'_>, players: Vec<serenity::UserId>) ->
 }
 
 #[poise::command(slash_command, prefix_command, ephemeral)]
+#[tracing::instrument]
 async fn configure(
     ctx: Context<'_>,
     #[channel_types("Voice")] town_square: serenity::ChannelId,
@@ -308,6 +331,7 @@ async fn configure(
     Ok(())
 }
 
+#[tracing::instrument(skip(ctx))]
 async fn register_commands(
     ctx: impl AsRef<serenity::Http>,
     options: &poise::FrameworkOptions<Data, Error>,
@@ -317,6 +341,7 @@ async fn register_commands(
     Ok(())
 }
 
+#[tracing::instrument(skip(ctx, framework))]
 async fn on_event(
     ctx: &serenity::Context,
     event: &serenity::FullEvent,
@@ -330,8 +355,20 @@ async fn on_event(
 }
 
 #[tokio::main(flavor = "current_thread")]
+#[tracing::instrument]
 async fn main() -> Result<()> {
     color_eyre::install()?;
+    tracing::subscriber::set_global_default(
+        tracing_subscriber::registry()
+            .with(
+                fmt::layer()
+                    .event_format(fmt::format().with_ansi(true).pretty())
+                    .with_span_events(FmtSpan::ACTIVE)
+                    .with_writer(io::stderr),
+            )
+            .with(EnvFilter::from_default_env())
+            .with(tracing_error::ErrorLayer::default()),
+    )?;
     let token = std::fs::read_to_string(
         std::env::var_os("DISCORD_TOKEN_FILE").ok_or_eyre("A Discord token is required")?,
     )