From d363372f190fe0419970731c70aca807caf7c06d Mon Sep 17 00:00:00 2001 From: Tsiry Sandratraina Date: Thu, 25 Sep 2025 21:17:02 +0300 Subject: [PATCH] Refactor logging to use `tracing` instead of `println` and `eprintln` - Replaced all instances of `println!` and `eprintln!` with `tracing::info!`, `tracing::warn!`, and `tracing::error!` for better structured logging. - Updated log messages to include relevant context and structured fields for improved traceability. - Ensured consistent logging practices across the `jetstream`, `scrobbler`, and `webscrobbler` crates. --- crates/analytics/src/subscriber/mod.rs | 86 +++++------ crates/dropbox/src/cmd/serve.rs | 4 +- crates/dropbox/src/handlers/files.rs | 8 ++ crates/dropbox/src/scan.rs | 134 ++++++++---------- crates/googledrive/src/cmd/serve.rs | 4 +- .../googledrive/src/repo/google_drive_path.rs | 7 +- crates/googledrive/src/scan.rs | 106 ++++---------- crates/jetstream/src/repo.rs | 106 +++++--------- crates/jetstream/src/subscriber.rs | 15 +- crates/jetstream/src/webhook/discord/mod.rs | 4 +- crates/jetstream/src/webhook_worker.rs | 4 +- crates/scrobbler/src/auth.rs | 2 +- .../scrobbler/src/handlers/v1/nowplaying.rs | 2 +- .../scrobbler/src/handlers/v1/submission.rs | 2 +- crates/scrobbler/src/lib.rs | 5 +- .../scrobbler/src/listenbrainz/core/submit.rs | 10 +- .../src/listenbrainz/core/validate_token.rs | 2 +- crates/scrobbler/src/listenbrainz/handlers.rs | 25 ++-- crates/scrobbler/src/main.rs | 6 +- crates/scrobbler/src/rocksky.rs | 7 +- crates/scrobbler/src/scrobbler.rs | 72 +++------- crates/scrobbler/src/spotify/client.rs | 12 +- crates/webscrobbler/src/handlers.rs | 21 +-- crates/webscrobbler/src/lib.rs | 5 +- crates/webscrobbler/src/rocksky.rs | 12 +- crates/webscrobbler/src/scrobbler.rs | 13 +- crates/webscrobbler/src/spotify/client.rs | 12 +- 27 files changed, 260 insertions(+), 426 deletions(-) diff --git a/crates/analytics/src/subscriber/mod.rs b/crates/analytics/src/subscriber/mod.rs index abe7d6e7..a64fe50e 100644 --- a/crates/analytics/src/subscriber/mod.rs +++ b/crates/analytics/src/subscriber/mod.rs @@ -42,15 +42,15 @@ pub fn on_scrobble(nc: Arc>, conn: Arc>) { let data = String::from_utf8(msg.payload.to_vec()).unwrap(); match serde_json::from_str::(&data) { Ok(payload) => match save_scrobble(conn.clone(), payload.clone()).await { - Ok(_) => println!( - "Scrobble saved successfully for {}", - payload.scrobble.uri.cyan() + Ok(_) => tracing::info!( + uri = %payload.scrobble.uri.cyan(), + "Scrobble saved successfully", ), - Err(e) => eprintln!("Error saving scrobble: {}", e), + Err(e) => tracing::error!("Error saving scrobble: {}", e), }, Err(e) => { - eprintln!("Error parsing payload: {}", e); - println!("{}", data); + tracing::error!("Error parsing payload: {}", e); + tracing::debug!("{}", data); } } } @@ -77,13 +77,16 @@ pub fn on_new_track(nc: Arc>, conn: Arc>) { match serde_json::from_str::(&data) { Ok(payload) => match save_track(conn.clone(), payload.clone()).await { Ok(_) => { - println!("Song saved successfully for {}", payload.track.title.cyan()) + tracing::info!( + title = %payload.track.title.cyan(), + "Track saved successfully", + ) } - Err(e) => eprintln!("Error saving song: {}", e), + Err(e) => tracing::error!("Error saving track: {}", e), }, Err(e) => { - eprintln!("Error parsing payload: {}", e); - println!("{}", data); + tracing::error!("Error parsing payload: {}", e); + tracing::debug!("{}", data); } } } @@ -109,15 +112,15 @@ pub fn on_like(nc: Arc>, conn: Arc>) { let data = String::from_utf8(msg.payload.to_vec()).unwrap(); match serde_json::from_str::(&data) { Ok(payload) => match like(conn.clone(), payload.clone()).await { - Ok(_) => println!( - "Like saved successfully for {}", - payload.track_id.xata_id.cyan() + Ok(_) => tracing::info!( + track_id = %payload.track_id.xata_id.cyan(), + "Like saved successfully", ), - Err(e) => eprintln!("Error saving like: {}", e), + Err(e) => tracing::error!("Error saving like: {}", e), }, Err(e) => { - eprintln!("Error parsing payload: {}", e); - println!("{}", data); + tracing::error!("Error parsing payload: {}", e); + tracing::debug!("{}", data); } } } @@ -143,15 +146,15 @@ pub fn on_unlike(nc: Arc>, conn: Arc>) { let data = String::from_utf8(msg.payload.to_vec()).unwrap(); match serde_json::from_str::(&data) { Ok(payload) => match unlike(conn.clone(), payload.clone()).await { - Ok(_) => println!( - "Unlike saved successfully for {}", - payload.track_id.xata_id.cyan() + Ok(_) => tracing::info!( + track_id = %payload.track_id.xata_id.cyan(), + "Unlike saved successfully", ), - Err(e) => eprintln!("Error saving unlike: {}", e), + Err(e) => tracing::error!("Error saving unlike: {}", e), }, Err(e) => { - eprintln!("Error parsing payload: {}", e); - println!("{}", data); + tracing::error!("Error parsing payload: {}", e); + tracing::debug!("{}", data); } } } @@ -177,16 +180,15 @@ pub fn on_new_user(nc: Arc>, conn: Arc>) { let data = String::from_utf8(msg.payload.to_vec()).unwrap(); match serde_json::from_str::(&data) { Ok(payload) => match save_user(conn.clone(), payload.clone()).await { - Ok(_) => println!( - "User saved successfully for {}{}", - "@".cyan(), - payload.handle.cyan() + Ok(_) => tracing::info!( + handle = %payload.handle.cyan(), + "User saved successfully", ), - Err(e) => eprintln!("Error saving user: {}", e), + Err(e) => tracing::error!("Error saving user: {}", e), }, Err(e) => { - eprintln!("Error parsing payload: {}", e); - println!("{}", data); + tracing::error!("Error parsing payload: {}", e); + tracing::debug!("{}", data); } } } @@ -253,7 +255,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[artists] error: {}", e); + tracing::error!("[artists] error: {}", e); return Err(e.into()); } } @@ -308,7 +310,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[albums] error: {}", e); + tracing::error!("[albums] error: {}", e); return Err(e.into()); } } @@ -371,7 +373,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[tracks] error: {}", e); + tracing::error!("[tracks] error: {}", e); return Err(e.into()); } } @@ -394,7 +396,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[album_tracks] error: {}", e); + tracing::error!("[album_tracks] error: {}", e); return Err(e.into()); } } @@ -412,7 +414,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[artist_tracks] error: {}", e); + tracing::error!("[artist_tracks] error: {}", e); return Err(e.into()); } } @@ -430,7 +432,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[artist_albums] error: {}", e); + tracing::error!("[artist_albums] error: {}", e); return Err(e.into()); } } @@ -448,7 +450,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[user_albums] error: {}", e); + tracing::error!("[user_albums] error: {}", e); return Err(e.into()); } } @@ -466,7 +468,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[user_artists] error: {}", e); + tracing::error!("[user_artists] error: {}", e); return Err(e.into()); } } @@ -484,7 +486,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[user_tracks] error: {}", e); + tracing::error!("[user_tracks] error: {}", e); return Err(e.into()); } } @@ -521,7 +523,7 @@ pub async fn save_scrobble( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[scrobbles] error: {}", e); + tracing::error!("[scrobbles] error: {}", e); return Err(e.into()); } } @@ -593,7 +595,7 @@ pub async fn save_track( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[tracks] error: {}", e); + tracing::error!("[tracks] error: {}", e); return Err(e.into()); } } @@ -616,7 +618,7 @@ pub async fn save_track( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[album_tracks] error: {}", e); + tracing::error!("[album_tracks] error: {}", e); return Err(e.into()); } } @@ -634,7 +636,7 @@ pub async fn save_track( Ok(_) => (), Err(e) => { if !e.to_string().contains("violates primary key constraint") { - println!("[artist_tracks] error: {}", e); + tracing::error!("[artist_tracks] error: {}", e); return Err(e.into()); } } diff --git a/crates/dropbox/src/cmd/serve.rs b/crates/dropbox/src/cmd/serve.rs index 9053f43d..43e4b3f4 100644 --- a/crates/dropbox/src/cmd/serve.rs +++ b/crates/dropbox/src/cmd/serve.rs @@ -27,7 +27,7 @@ async fn call_method( req: HttpRequest, ) -> Result { let method = req.match_info().get("method").unwrap_or("unknown"); - println!("Method: {}", method.bright_green()); + tracing::info!(method = %method.bright_green(), "API call"); let conn = data.get_ref().clone(); handle(method, &mut payload, &req, conn) @@ -41,7 +41,7 @@ pub async fn serve() -> Result<(), Error> { let addr = format!("{}:{}", host, port); let url = format!("http://{}", addr); - println!("Listening on {}", url.bright_green()); + tracing::info!(url = %url.bright_green(), "Listening on"); let pool = PgPoolOptions::new() .max_connections(5) diff --git a/crates/dropbox/src/handlers/files.rs b/crates/dropbox/src/handlers/files.rs index 9878de70..95b10c6c 100644 --- a/crates/dropbox/src/handlers/files.rs +++ b/crates/dropbox/src/handlers/files.rs @@ -2,6 +2,7 @@ use std::{env, sync::Arc, thread}; use actix_web::{web, HttpRequest, HttpResponse}; use anyhow::Error; +use owo_colors::OwoColorize; use sqlx::{Pool, Postgres}; use tokio_stream::StreamExt; @@ -24,6 +25,7 @@ pub async fn get_files( let body = read_payload!(payload); let params = serde_json::from_slice::(&body)?; let refresh_token = find_dropbox_refresh_token(&pool.clone(), ¶ms.did).await?; + tracing::info!(did = %params.did.bright_green(), "dropbox.getFiles"); if refresh_token.is_none() { return Ok(HttpResponse::Unauthorized().finish()); @@ -48,6 +50,7 @@ pub async fn create_music_folder( let body = read_payload!(payload); let params = serde_json::from_slice::(&body)?; let refresh_token = find_dropbox_refresh_token(&pool.clone(), ¶ms.did).await?; + tracing::info!(did = %params.did.bright_green(), "dropbox.createMusicFolder"); if refresh_token.is_none() { return Ok(HttpResponse::Unauthorized().finish()); @@ -72,6 +75,7 @@ pub async fn get_files_at( let body = read_payload!(payload); let params = serde_json::from_slice::(&body)?; let refresh_token = find_dropbox_refresh_token(&pool.clone(), ¶ms.did).await?; + tracing::info!(did = %params.did.bright_green(), path = %params.path.bright_green(), "dropbox.getFilesAt"); if refresh_token.is_none() { return Ok(HttpResponse::Unauthorized().finish()); @@ -96,6 +100,7 @@ pub async fn download_file( let body = read_payload!(payload); let params = serde_json::from_slice::(&body)?; let refresh_token = find_dropbox_refresh_token(&pool.clone(), ¶ms.did).await?; + tracing::info!(did = %params.did.bright_green(), path = %params.path.bright_green(), "dropbox.downloadFile"); if refresh_token.is_none() { return Ok(HttpResponse::Unauthorized().finish()); @@ -118,6 +123,7 @@ pub async fn get_temporary_link( let body = read_payload!(payload); let params = serde_json::from_slice::(&body)?; let refresh_token = find_dropbox_refresh_token(&pool.clone(), ¶ms.did).await?; + tracing::info!(did = %params.did.bright_green(), path = %params.path.bright_green(), "dropbox.getTemporaryLink"); if refresh_token.is_none() { return Ok(HttpResponse::Unauthorized().finish()); @@ -142,6 +148,7 @@ pub async fn get_metadata( let body = read_payload!(payload); let params = serde_json::from_slice::(&body)?; let refresh_token = find_dropbox_refresh_token(&pool.clone(), ¶ms.did).await?; + tracing::info!(did = %params.did.bright_green(), path = %params.path.bright_green(), "dropbox.getMetadata"); if refresh_token.is_none() { return Ok(HttpResponse::Unauthorized().finish()); @@ -165,6 +172,7 @@ pub async fn scan_folder( ) -> Result { let body = read_payload!(payload); let params = serde_json::from_slice::(&body)?; + tracing::info!(did = %params.did.bright_green(), path = %params.path.bright_green(), "dropbox.scanFolder"); let pool = pool.clone(); thread::spawn(move || { diff --git a/crates/dropbox/src/scan.rs b/crates/dropbox/src/scan.rs index 9395c278..62fecdc7 100644 --- a/crates/dropbox/src/scan.rs +++ b/crates/dropbox/src/scan.rs @@ -91,14 +91,14 @@ pub fn scan_audio_files( .await?; if res.status().as_u16() == 400 || res.status().as_u16() == 409 { - println!("Path not found: {}", path.bright_red()); + tracing::error!(path = %path.bright_red(), "Path not found"); return Ok(()); } let entry = res.json::().await?; if entry.tag.clone().unwrap().as_str() == "folder" { - println!("Scanning folder: {}", path.bright_green()); + tracing::info!(path = %path.bright_green(), "Scanning folder"); let parent_path = Path::new(&path) .parent() @@ -160,7 +160,7 @@ pub fn scan_audio_files( let client = Client::new(); - println!("Downloading file: {}", path.bright_green()); + tracing::info!(path = %path.bright_green(), "Downloading file"); let res = client .post(&format!("{}/files/download", CONTENT_URL)) @@ -176,15 +176,12 @@ pub fn scan_audio_files( let mut tmpfile = File::create(&tmppath)?; tmpfile.write_all(&bytes)?; - println!( - "Reading file: {}", - &tmppath.clone().display().to_string().bright_green() - ); + tracing::info!(path = %tmppath.clone().display().to_string().bright_green(), "Reading file"); let tagged_file = match Probe::open(&tmppath)?.read() { Ok(tagged_file) => tagged_file, Err(e) => { - println!("Error opening file: {}", e); + tracing::error!(path = %tmppath.clone().display().to_string().bright_red(), "Error reading file: {}", e); return Ok(()); } }; @@ -193,71 +190,57 @@ pub fn scan_audio_files( let tag = match primary_tag { Some(tag) => tag, None => { - println!("No tag found in file"); + tracing::error!(path = %tmppath.clone().display().to_string().bright_red(), "No tag found in file"); return Ok(()); } }; let pictures = tag.pictures(); - println!( - "Title: {}", - tag.get_string(&lofty::tag::ItemKey::TrackTitle) - .unwrap_or_default() - .bright_green() - ); - println!( - "Artist: {}", - tag.get_string(&lofty::tag::ItemKey::TrackArtist) - .unwrap_or_default() - .bright_green() + tracing::info!( + title = %tag + .get_string(&lofty::tag::ItemKey::TrackTitle) + .unwrap_or_default(), ); - println!( - "Album Artist: {}", - tag.get_string(&lofty::tag::ItemKey::AlbumArtist) - .unwrap_or_default() - .bright_green() + tracing::info!( + artist = %tag + .get_string(&lofty::tag::ItemKey::TrackArtist) + .unwrap_or_default(), ); - println!( - "Album: {}", - tag.get_string(&lofty::tag::ItemKey::AlbumTitle) - .unwrap_or_default() - .bright_green() + tracing::info!( + album = %tag + .get_string(&lofty::tag::ItemKey::AlbumTitle) + .unwrap_or_default(), ); - println!( - "Lyrics: {}", - tag.get_string(&lofty::tag::ItemKey::Lyrics) - .unwrap_or_default() - .bright_green() + tracing::info!( + album_artist = %tag + .get_string(&lofty::tag::ItemKey::AlbumArtist) + .unwrap_or_default(), ); - println!("Year: {}", tag.year().unwrap_or_default().bright_green()); - println!( - "Track Number: {}", - tag.track().unwrap_or_default().bright_green() + tracing::info!( + lyrics = %tag + .get_string(&lofty::tag::ItemKey::Lyrics) + .unwrap_or_default(), ); - println!( - "Track Total: {}", - tag.track_total().unwrap_or_default().bright_green() + tracing::info!(year = %tag.year().unwrap_or_default()); + tracing::info!(track_number = %tag.track().unwrap_or_default()); + tracing::info!(track_total = %tag.track_total().unwrap_or_default()); + tracing::info!( + release_date = %tag + .get_string(&lofty::tag::ItemKey::OriginalReleaseDate) + .unwrap_or_default(), ); - println!( - "Release Date: {:?}", - tag.get_string(&lofty::tag::ItemKey::OriginalReleaseDate) - .unwrap_or_default() - .bright_green() + tracing::info!( + recording_date = %tag + .get_string(&lofty::tag::ItemKey::RecordingDate) + .unwrap_or_default(), ); - println!( - "Recording Date: {:?}", - tag.get_string(&lofty::tag::ItemKey::RecordingDate) - .unwrap_or_default() - .bright_green() + tracing::info!( + copyright_message = %tag + .get_string(&lofty::tag::ItemKey::CopyrightMessage) + .unwrap_or_default(), ); - println!( - "Copyright Message: {}", - tag.get_string(&lofty::tag::ItemKey::CopyrightMessage) - .unwrap_or_default() - .bright_green() - ); - println!("Pictures: {:?}", pictures); + tracing::info!(pictures = ?pictures); let title = tag .get_string(&lofty::tag::ItemKey::TrackTitle) @@ -290,18 +273,18 @@ pub fn scan_audio_files( match track { Some(track) => { - println!("Track exists: {}", title.bright_green()); + tracing::info!(title = %title.bright_green(), "Track exists"); let parent_path = Path::new(&path) .parent() .map(|p| p.to_string_lossy().to_string()); let status = create_dropbox_path(&pool, &entry, &track, &dropbox_id, parent_path).await; - println!("status: {:?}", status); + tracing::info!(status = ?status); // TODO: publish file metadata to nats } None => { - println!("Creating track: {}", title.bright_green()); + tracing::info!(title = %title.bright_green(), "Creating track"); let album_art = upload_album_cover(albumart_id.into(), pictures, &access_token).await?; let client = Client::new(); @@ -338,7 +321,7 @@ pub fn scan_audio_files( })) .send() .await?; - println!("Track Saved: {} {}", title, response.status()); + tracing::info!(title = title, status = %response.status(), "Track saved"); tokio::time::sleep(std::time::Duration::from_secs(3)).await; let track = get_track_by_hash(&pool, &hash).await?; @@ -353,7 +336,7 @@ pub fn scan_audio_files( return Ok(()); } - println!("Failed to create track: {}", title.bright_green()); + tracing::error!(title = %title.bright_red(), "Failed to create track"); } } @@ -413,7 +396,7 @@ pub async fn upload_album_cover( .send() .await?; - println!("Cover uploaded: {}", response.status()); + tracing::info!(status = %response.status(), "Cover uploaded"); Ok(Some(name)) } @@ -433,15 +416,18 @@ pub async fn get_track_duration(path: &Path) -> Result { let meta_opts = MetadataOptions::default(); let format_opts = FormatOptions::default(); - let probed = - match symphonia::default::get_probe().format(&hint, media_source, &format_opts, &meta_opts) - { - Ok(probed) => probed, - Err(_) => { - println!("Error probing file"); - return Ok(duration); - } - }; + let probed = match symphonia::default::get_probe().format( + &hint, + media_source, + &format_opts, + &meta_opts, + ) { + Ok(probed) => probed, + Err(e) => { + tracing::error!(path = %path.display().to_string().bright_red(), "Error probing file: {}", e); + return Ok(duration); + } + }; if let Some(track) = probed.format.tracks().first() { if let Some(duration) = track.codec_params.n_frames { diff --git a/crates/googledrive/src/cmd/serve.rs b/crates/googledrive/src/cmd/serve.rs index 8ead9b56..c64588d1 100644 --- a/crates/googledrive/src/cmd/serve.rs +++ b/crates/googledrive/src/cmd/serve.rs @@ -27,7 +27,7 @@ async fn call_method( req: HttpRequest, ) -> Result { let method = req.match_info().get("method").unwrap_or("unknown"); - println!("Method: {}", method.bright_green()); + tracing::info!(method = %method.bright_green(), "API call"); let conn = data.get_ref().clone(); handle(method, &mut payload, &req, conn) @@ -41,7 +41,7 @@ pub async fn serve() -> Result<(), Error> { let addr = format!("{}:{}", host, port); let url = format!("http://{}", addr); - println!("Listening on {}", url.bright_green()); + tracing::info!(url = %url.bright_green(), "Listening on"); let pool = PgPoolOptions::new() .max_connections(5) diff --git a/crates/googledrive/src/repo/google_drive_path.rs b/crates/googledrive/src/repo/google_drive_path.rs index 2088b14c..e23bff22 100644 --- a/crates/googledrive/src/repo/google_drive_path.rs +++ b/crates/googledrive/src/repo/google_drive_path.rs @@ -1,3 +1,4 @@ +use owo_colors::OwoColorize; use sqlx::{Pool, Postgres}; use crate::{ @@ -47,7 +48,11 @@ pub async fn create_google_drive_path( .execute(pool) .await?; - println!("{:?}", result); + tracing::info!( + file_id = %file.id.bright_green(), + rows_affected = %result.rows_affected(), + "Google Drive path created" + ); sqlx::query( r#" diff --git a/crates/googledrive/src/scan.rs b/crates/googledrive/src/scan.rs index 0dd81a36..32213094 100644 --- a/crates/googledrive/src/scan.rs +++ b/crates/googledrive/src/scan.rs @@ -104,7 +104,7 @@ pub fn scan_audio_files( let file = res.json::().await?; if file.mime_type == "application/vnd.google-apps.folder" { - println!("Scanning folder: {}", file.name.bright_green()); + tracing::info!(folder = %file.name.bright_green(), "Scanning folder"); create_google_drive_directory( &pool, @@ -172,7 +172,7 @@ pub fn scan_audio_files( return Ok(()); } - println!("Downloading file: {}", file.name.bright_green()); + tracing::info!(file = %file.name.bright_green(), "Downloading file"); let client = Client::new(); @@ -191,15 +191,12 @@ pub fn scan_audio_files( let mut tmpfile = std::fs::File::create(&tmppath)?; tmpfile.write_all(&bytes)?; - println!( - "Reading file: {}", - &tmppath.clone().display().to_string().bright_green() - ); + tracing::info!(path = %tmppath.display(), "Reading file"); let tagged_file = match Probe::open(&tmppath)?.read() { Ok(tagged_file) => tagged_file, Err(e) => { - println!("Error opening file: {}", e); + tracing::warn!(file = %file.name.bright_green(), error = %e, "Failed to open file with lofty"); return Ok(()); } }; @@ -208,71 +205,25 @@ pub fn scan_audio_files( let tag = match primary_tag { Some(tag) => tag, None => { - println!("No tag found in file"); + tracing::warn!(file = %file.name.bright_green(), "No tag found in file"); return Ok(()); } }; let pictures = tag.pictures(); - println!( - "Title: {}", - tag.get_string(&lofty::tag::ItemKey::TrackTitle) - .unwrap_or_default() - .bright_green() - ); - println!( - "Artist: {}", - tag.get_string(&lofty::tag::ItemKey::TrackArtist) - .unwrap_or_default() - .bright_green() - ); - println!( - "Album Artist: {}", - tag.get_string(&lofty::tag::ItemKey::AlbumArtist) - .unwrap_or_default() - .bright_green() - ); - println!( - "Album: {}", - tag.get_string(&lofty::tag::ItemKey::AlbumTitle) - .unwrap_or_default() - .bright_green() - ); - println!( - "Lyrics: {}", - tag.get_string(&lofty::tag::ItemKey::Lyrics) - .unwrap_or_default() - .bright_green() - ); - println!("Year: {}", tag.year().unwrap_or_default().bright_green()); - println!( - "Track Number: {}", - tag.track().unwrap_or_default().bright_green() - ); - println!( - "Track Total: {}", - tag.track_total().unwrap_or_default().bright_green() - ); - println!( - "Release Date: {:?}", - tag.get_string(&lofty::tag::ItemKey::OriginalReleaseDate) - .unwrap_or_default() - .bright_green() - ); - println!( - "Recording Date: {:?}", - tag.get_string(&lofty::tag::ItemKey::RecordingDate) - .unwrap_or_default() - .bright_green() - ); - println!( - "Copyright Message: {}", - tag.get_string(&lofty::tag::ItemKey::CopyrightMessage) - .unwrap_or_default() - .bright_green() - ); - println!("Pictures: {:?}", pictures); + tracing::info!(title = %tag.get_string(&lofty::tag::ItemKey::TrackTitle).unwrap_or_default(), "Title"); + tracing::info!(artist = %tag.get_string(&lofty::tag::ItemKey::TrackArtist).unwrap_or_default(), "Artist"); + tracing::info!(album_artist = %tag.get_string(&lofty::tag::ItemKey::AlbumArtist).unwrap_or_default(), "Album artist"); + tracing::info!(album = %tag.get_string(&lofty::tag::ItemKey::AlbumTitle).unwrap_or_default(), "Album"); + tracing::info!(lyrics = %tag.get_string(&lofty::tag::ItemKey::Lyrics).unwrap_or_default(), "Lyrics"); + tracing::info!(year = %tag.year().unwrap_or_default(), "Year"); + tracing::info!(track_number = %tag.track().unwrap_or_default(), "Track number"); + tracing::info!(track_total = %tag.track_total().unwrap_or_default(), "Track total"); + tracing::info!(release_date = %tag.get_string(&lofty::tag::ItemKey::OriginalReleaseDate).unwrap_or_default(), "Release date"); + tracing::info!(recording_date = %tag.get_string(&lofty::tag::ItemKey::RecordingDate).unwrap_or_default(), "Recording date"); + tracing::info!(copyright = %tag.get_string(&lofty::tag::ItemKey::CopyrightMessage).unwrap_or_default(), "Copyright message"); + tracing::info!(pictures = %pictures.len(), "Pictures found"); let title = tag .get_string(&lofty::tag::ItemKey::TrackTitle) @@ -304,9 +255,9 @@ pub fn scan_audio_files( match track { Some(track) => { - println!("Track exists: {}", title.bright_green()); + tracing::info!(title = %title.bright_green(), "Track exists"); let parent_drive_id = parent_drive_file_id.as_deref(); - let status = create_google_drive_path( + create_google_drive_path( &pool, &file, &track, @@ -315,11 +266,10 @@ pub fn scan_audio_files( ) .await?; - println!("status: {:?}", status); // TODO: publish file metadata to nats } None => { - println!("Creating track: {}", title.bright_green()); + tracing::info!(title = %title.bright_green(), "Creating track"); let albumart = upload_album_cover(albumart_id.into(), pictures, &access_token).await?; @@ -358,22 +308,20 @@ pub fn scan_audio_files( })) .send() .await?; - println!("Track Saved: {} {}", title, response.status()); + tracing::info!(status = %response.status(), "Track saved"); tokio::time::sleep(std::time::Duration::from_secs(3)).await; let track = get_track_by_hash(&pool, &hash).await?; if let Some(track) = track { let parent_drive_id = parent_drive_file_id.as_deref(); - let status = create_google_drive_path( + create_google_drive_path( &pool, &file, &track, &google_drive_id, parent_drive_id.unwrap_or(""), ) - .await; - - println!("status: {:?}", status); + .await?; // TODO: publish file metadata to nats @@ -382,7 +330,7 @@ pub fn scan_audio_files( return Ok(()); } - println!("Failed to create track: {}", title.bright_green()); + tracing::warn!(title = %title.bright_green(), "Failed to create track"); } } @@ -442,7 +390,7 @@ pub async fn upload_album_cover( .send() .await?; - println!("Cover uploaded: {}", response.status()); + tracing::info!(status = %response.status(), "Cover uploaded"); Ok(Some(name)) } @@ -466,8 +414,8 @@ pub async fn get_track_duration(path: &Path) -> Result { match symphonia::default::get_probe().format(&hint, media_source, &format_opts, &meta_opts) { Ok(probed) => probed, - Err(_) => { - println!("Error probing file"); + Err(e) => { + tracing::warn!(path = %path.display(), error = %e, "Failed to probe media"); return Ok(duration); } }; diff --git a/crates/jetstream/src/repo.rs b/crates/jetstream/src/repo.rs index e872529d..470249bf 100644 --- a/crates/jetstream/src/repo.rs +++ b/crates/jetstream/src/repo.rs @@ -16,9 +16,16 @@ use crate::{ }, webhook_worker::{push_to_queue, AppState}, xata::{ - album::Album, album_track::AlbumTrack, artist::Artist, artist_album::ArtistAlbum, - artist_track::ArtistTrack, track::Track, user::User, user_album::UserAlbum, - user_artist::UserArtist, user_track::UserTrack, + album::Album, + album_track::AlbumTrack, + artist::Artist, + artist_album::ArtistAlbum, + artist_track::ArtistTrack, + track::Track, + user::{self, User}, + user_album::UserAlbum, + user_artist::UserArtist, + user_track::UserTrack, }, }; @@ -56,14 +63,7 @@ pub async fn save_scrobble( let user_id = save_user(&mut tx, did).await?; - println!( - "Saving scrobble: {} ", - format!( - "{} - {} - {}", - scrobble_record.title, scrobble_record.artist, scrobble_record.album - ) - .magenta() - ); + tracing::info!(title = %scrobble_record.title.magenta(), artist = %scrobble_record.artist.magenta(), album = %scrobble_record.album.magenta(), "Saving scrobble"); sqlx::query( r#" @@ -144,7 +144,7 @@ pub async fn save_scrobble( { Ok(_) => {} Err(e) => { - eprintln!("Failed to push to webhook queue: {}", e); + tracing::error!(error = %e, "Failed to push to webhook queue"); } } } @@ -188,7 +188,7 @@ pub async fn save_scrobble( } } _ => { - println!("Unsupported operation: {}", commit.operation); + tracing::warn!(operation = %commit.operation, "Unsupported operation"); } } Ok(()) @@ -341,11 +341,11 @@ pub async fn save_album( .await?; if !albums.is_empty() { - println!("Album already exists: {}", albums[0].title.magenta()); + tracing::info!(name = %albums[0].title.magenta(), "Album already exists"); return Ok(albums[0].xata_id.clone()); } - println!("Saving album: {}", scrobble_record.album.magenta()); + tracing::info!(name = %scrobble_record.album, "Saving new album"); let uri: Option = None; let artist_uri: Option = None; @@ -402,11 +402,11 @@ pub async fn save_artist( .await?; if !artists.is_empty() { - println!("Artist already exists: {}", artists[0].name.magenta()); + tracing::info!(name = %scrobble_record.album_artist, "Artist already exists"); return Ok(artists[0].xata_id.clone()); } - println!("Saving artist: {}", scrobble_record.album_artist.magenta()); + tracing::info!(name = %scrobble_record.album_artist, "Saving new artist"); let uri: Option = None; let picture = ""; @@ -450,17 +450,11 @@ pub async fn save_album_track( .await?; if !album_tracks.is_empty() { - println!( - "Album track already exists: {}", - format!("{} - {}", album_id, track_id).magenta() - ); + tracing::info!(album_id = %album_id, track_id = %track_id, "Album track already exists"); return Ok(()); } - println!( - "Saving album track: {}", - format!("{} - {}", album_id, track_id).magenta() - ); + tracing::info!(album_id = %album_id, track_id = %track_id, "Saving album track"); sqlx::query( r#" @@ -492,17 +486,11 @@ pub async fn save_artist_track( .await?; if !artist_tracks.is_empty() { - println!( - "Artist track already exists: {}", - format!("{} - {}", artist_id, track_id).magenta() - ); + tracing::info!(artist_id = %artist_id, track_id = %track_id, "Artist track already exists"); return Ok(()); } - println!( - "Saving artist track: {}", - format!("{} - {}", artist_id, track_id).magenta() - ); + tracing::info!(artist_id = %artist_id, track_id = %track_id, "Saving artist track"); sqlx::query( r#" @@ -534,17 +522,11 @@ pub async fn save_artist_album( .await?; if !artist_albums.is_empty() { - println!( - "Artist album already exists: {}", - format!("{} - {}", artist_id, album_id).magenta() - ); + tracing::info!(artist_id = %artist_id, album_id = %album_id, "Artist album already exists"); return Ok(()); } - println!( - "Saving artist album: {}", - format!("{} - {}", artist_id, album_id).magenta() - ); + tracing::info!(artist_id = %artist_id, album_id = %album_id, "Saving artist album"); sqlx::query( r#" @@ -585,7 +567,7 @@ pub async fn save_user_artist( match artists.is_empty() { true => { - println!("Saving artist: {}", record.name.magenta()); + tracing::info!(name = %record.name, "Artist not found in database, inserting new artist"); let did = users[0].did.clone(); sqlx::query( r#" @@ -632,10 +614,7 @@ pub async fn save_user_artist( .await?; if !user_artists.is_empty() { - println!( - "User artist already exists: {}", - format!("{} - {}", user_id, artist_id).magenta() - ); + tracing::info!(user_id = %user_id, artist_id = %artist_id, "Updating user artist"); sqlx::query( r#" UPDATE user_artists @@ -652,10 +631,7 @@ pub async fn save_user_artist( return Ok(()); } - println!( - "Saving user artist: {}", - format!("{} - {}", user_id, artist_id).magenta() - ); + tracing::info!(user_id = %user_id, artist_id = %artist_id, "Inserting user artist"); sqlx::query( r#" @@ -699,7 +675,7 @@ pub async fn save_user_album( match albums.is_empty() { true => { - println!("Saving album: {}", record.title.magenta()); + tracing::info!(title = %record.title, artist = %record.artist, "Album not found in database, inserting new album"); let did = users[0].did.clone(); sqlx::query( r#" @@ -752,10 +728,7 @@ pub async fn save_user_album( .await?; if !user_albums.is_empty() { - println!( - "User album already exists: {}", - format!("{} - {}", user_id, album_id).magenta() - ); + tracing::info!(user_id = %user_id, album_id = %album_id, "Updating user album"); sqlx::query( r#" UPDATE user_albums @@ -772,10 +745,7 @@ pub async fn save_user_album( return Ok(()); } - println!( - "Saving user album: {}", - format!("{} - {}", user_id, album_id).magenta() - ); + tracing::info!(user_id = %user_id, album_id = %album_id, "Inserting user album"); sqlx::query( r#" @@ -822,7 +792,7 @@ pub async fn save_user_track( match tracks.is_empty() { true => { - println!("Saving track: {}", record.title.magenta()); + tracing::info!(title = %record.title, artist = %record.artist, album = %record.album, "Track not found in database, inserting new track"); let did = users[0].did.clone(); sqlx::query( r#" @@ -894,10 +864,7 @@ pub async fn save_user_track( .await?; if !user_tracks.is_empty() { - println!( - "User track already exists: {}", - format!("{} - {}", user_id, track_id).magenta() - ); + tracing::info!(user_id = %user_id, track_id = %track_id, "Updating user track"); sqlx::query( r#" UPDATE user_tracks @@ -914,10 +881,7 @@ pub async fn save_user_track( return Ok(()); } - println!( - "Saving user track: {}", - format!("{} - {}", user_id, track_id).magenta() - ); + tracing::info!(user_id = %user_id, track_id = %track_id, "Inserting user track"); sqlx::query( r#" @@ -954,7 +918,7 @@ pub async fn update_artist_uri( .await?; if artists.is_empty() { - println!("Artist not found: {}", record.name.magenta()); + tracing::warn!(name = %record.name, "Artist not found in database"); return Ok(()); } @@ -1023,7 +987,7 @@ pub async fn update_album_uri( .fetch_all(&mut **tx) .await?; if albums.is_empty() { - println!("Album not found: {}", record.title.magenta()); + tracing::warn!(title = %record.title, "Album not found in database"); return Ok(()); } let album_id = &albums[0].xata_id; @@ -1082,7 +1046,7 @@ pub async fn update_track_uri( .await?; if tracks.is_empty() { - println!("Track not found: {}", record.title.magenta()); + tracing::warn!(title = %record.title, "Track not found in database"); return Ok(()); } diff --git a/crates/jetstream/src/subscriber.rs b/crates/jetstream/src/subscriber.rs index 4250c497..83237e99 100644 --- a/crates/jetstream/src/subscriber.rs +++ b/crates/jetstream/src/subscriber.rs @@ -40,20 +40,17 @@ impl ScrobbleSubscriber { let pool = Arc::new(Mutex::new(pool)); let (mut ws_stream, _) = connect_async(&self.service_url).await?; - println!( - "Connected to jetstream at {}", - self.service_url.bright_green() - ); + tracing::info!(url = %self.service_url.bright_green(), "Connected to jetstream at"); while let Some(msg) = ws_stream.next().await { match msg { Ok(msg) => { if let Err(e) = handle_message(state.clone(), pool.clone(), msg).await { - eprintln!("Error handling message: {}", e); + tracing::error!(error = %e, "Error handling message"); } } Err(e) => { - eprintln!("WebSocket error: {}", e); + tracing::error!(error = %e, "WebSocket error"); break; } } @@ -76,14 +73,14 @@ async fn handle_message( return Ok::<(), Error>(()); } - println!("Received message: {:#?}", message); + tracing::info!(message = %text.bright_green(), "Received message"); if let Some(commit) = message.commit { match save_scrobble(state, pool, &message.did, commit).await { Ok(_) => { - println!("Scrobble saved successfully"); + tracing::info!(user_id = %message.did.bright_green(), "Scrobble saved successfully"); } Err(e) => { - eprintln!("Error saving scrobble: {}", e); + tracing::error!(error = %e, "Error saving scrobble"); } } } diff --git a/crates/jetstream/src/webhook/discord/mod.rs b/crates/jetstream/src/webhook/discord/mod.rs index c06b3675..f1d22a48 100644 --- a/crates/jetstream/src/webhook/discord/mod.rs +++ b/crates/jetstream/src/webhook/discord/mod.rs @@ -37,7 +37,7 @@ pub async fn post_embeds( embeds: Vec, ) -> reqwest::Result<()> { if discord_webhook_url.is_empty() { - println!("DISCORD_WEBHOOK_URL is not set, skipping webhook post"); + tracing::warn!("DISCORD_WEBHOOK_URL is not set, skipping webhook post"); return Ok(()); } @@ -48,7 +48,7 @@ pub async fn post_embeds( let res = http.post(discord_webhook_url).json(&body).send().await?; if !res.status().is_success() { let text = res.text().await.unwrap_or_default(); - eprintln!("Failed to post to Discord webhook: {}", text); + tracing::error!(error = %text, "Failed to post to Discord webhook"); } Ok(()) } diff --git a/crates/jetstream/src/webhook_worker.rs b/crates/jetstream/src/webhook_worker.rs index 0c072b0d..42358715 100644 --- a/crates/jetstream/src/webhook_worker.rs +++ b/crates/jetstream/src/webhook_worker.rs @@ -79,7 +79,7 @@ async fn run_worker( } Ok(None) => break, Err(e) => { - eprintln!("Failed to pop from Redis: {}", e); + tracing::error!(error = %e, "Failed to pop from Redis"); break; } } @@ -93,7 +93,7 @@ async fn run_worker( tokens -= 1; if let Err(e) = discord::post_embeds(&http, &discord_webhook_url, embeds).await { - eprintln!("Failed to post to Discord webhook: {}", e); + tracing::error!(error = %e, "Failed to post to Discord webhook"); } } } diff --git a/crates/scrobbler/src/auth.rs b/crates/scrobbler/src/auth.rs index a7171db4..831c7bc4 100644 --- a/crates/scrobbler/src/auth.rs +++ b/crates/scrobbler/src/auth.rs @@ -37,7 +37,7 @@ pub async fn authenticate_v1( let expected_password = md5::compute(expected_password); let expected_password = format!("{:x}", expected_password); if expected_password != password_md5 { - println!("{} != {}", expected_password, password_md5); + tracing::error!(expected = %expected_password, provided = %password_md5, "Invalid password"); return Err(Error::msg("Invalid password")); } Ok(()) diff --git a/crates/scrobbler/src/handlers/v1/nowplaying.rs b/crates/scrobbler/src/handlers/v1/nowplaying.rs index 27533ac0..ac019d3c 100644 --- a/crates/scrobbler/src/handlers/v1/nowplaying.rs +++ b/crates/scrobbler/src/handlers/v1/nowplaying.rs @@ -18,7 +18,7 @@ pub fn nowplaying( let a = form.get("a").unwrap().to_string(); let t = form.get("t").unwrap().to_string(); - println!("Now playing: {} - {} {}", a, t, s.cyan()); + tracing::info!(artist = %a, track = %t, user = %s.cyan(), "Now playing"); let user_id = verify_session_id(cache, &s); if let Err(e) = user_id { diff --git a/crates/scrobbler/src/handlers/v1/submission.rs b/crates/scrobbler/src/handlers/v1/submission.rs index 73a997ac..88edc1c2 100644 --- a/crates/scrobbler/src/handlers/v1/submission.rs +++ b/crates/scrobbler/src/handlers/v1/submission.rs @@ -29,7 +29,7 @@ pub async fn submission( } let user_id = user_id.unwrap(); - println!("Submission: {} - {} {} {} {}", a, t, i, user_id, s.cyan()); + tracing::info!(artist = %a, track = %t, timestamp = %i, user_id = %user_id, "Submission"); match scrobble_v1(pool, cache, &form).await { Ok(_) => Ok(HttpResponse::Ok().body("OK\n")), diff --git a/crates/scrobbler/src/lib.rs b/crates/scrobbler/src/lib.rs index e615d465..1b230327 100644 --- a/crates/scrobbler/src/lib.rs +++ b/crates/scrobbler/src/lib.rs @@ -56,10 +56,7 @@ pub async fn run() -> Result<(), Error> { .parse::() .unwrap_or(7882); - println!( - "Starting Scrobble server @ {}", - format!("{}:{}", host, port).green() - ); + tracing::info!(url = %format!("http://{}:{}", host, port).bright_green(), "Starting Scrobble server @"); let limiter = web::Data::new( Limiter::builder("redis://127.0.0.1") diff --git a/crates/scrobbler/src/listenbrainz/core/submit.rs b/crates/scrobbler/src/listenbrainz/core/submit.rs index a642aaf2..7e0dd599 100644 --- a/crates/scrobbler/src/listenbrainz/core/submit.rs +++ b/crates/scrobbler/src/listenbrainz/core/submit.rs @@ -17,7 +17,7 @@ pub async fn submit_listens( token: &str, ) -> Result { if payload.listen_type != "playing_now" { - println!("skipping listen type: {}", payload.listen_type.cyan()); + tracing::info!(listen_type = %payload.listen_type.cyan(), "Skipping listen type"); return Ok(HttpResponse::Ok().json(json!({ "status": "ok", "payload": { @@ -62,13 +62,7 @@ pub async fn submit_listens( cache.del(&format!("listenbrainz:cache:{}:{}:{}", artist, track, did))?; - println!( - "Retryable error on attempt {}/{}: {}", - attempt, - RETRIES, - e.to_string().yellow() - ); - println!("{:#?}", payload); + tracing::error!(error = %e, attempt = attempt, "Retryable error submitting listens for {} - {} (attempt {}/{})", artist, track, attempt, RETRIES); if attempt == RETRIES { return Ok(HttpResponse::BadRequest().json(serde_json::json!({ diff --git a/crates/scrobbler/src/listenbrainz/core/validate_token.rs b/crates/scrobbler/src/listenbrainz/core/validate_token.rs index c8c12939..c6f306e5 100644 --- a/crates/scrobbler/src/listenbrainz/core/validate_token.rs +++ b/crates/scrobbler/src/listenbrainz/core/validate_token.rs @@ -12,7 +12,7 @@ pub async fn validate_token(token: &str) -> Result { }, }))), Err(e) => { - println!("Error validating token: {}", e); + tracing::error!(error = %e, "Failed to validate token"); Ok(HttpResponse::BadRequest().json(serde_json::json!({ "error": 4, "message": format!("Failed to validate token: {}", e) diff --git a/crates/scrobbler/src/listenbrainz/handlers.rs b/crates/scrobbler/src/listenbrainz/handlers.rs index 12deb9d8..55ec2a7e 100644 --- a/crates/scrobbler/src/listenbrainz/handlers.rs +++ b/crates/scrobbler/src/listenbrainz/handlers.rs @@ -58,8 +58,7 @@ pub async fn handle_submit_listens( let body = String::from_utf8_lossy(&payload); let req = serde_json::from_str::(&body) .map_err(|e| { - println!("{}", body); - println!("Error parsing request body: {}", e); + tracing::error!(body = %body, error = %e, "Error parsing request body"); e }) .map_err(actix_web::error::ErrorBadRequest)?; @@ -116,7 +115,7 @@ pub async fn handle_validate_token( })); } Err(e) => { - println!("Error validating token: {}", e); + tracing::error!(error = %e, "Error validating token"); return HttpResponse::InternalServerError().finish(); } } @@ -127,13 +126,13 @@ pub async fn handle_search_users( query: web::Query, data: web::Data>>, ) -> impl Responder { - let pool = data.get_ref(); + let _pool = data.get_ref(); let query = query.into_inner(); match search_users(&query).await { Ok(users) => HttpResponse::Ok().json(users), Err(e) => { - println!("Error searching users: {}", e); + tracing::error!(error = %e, "Error searching users"); HttpResponse::InternalServerError().finish() } } @@ -145,7 +144,7 @@ pub async fn handle_get_listens(user_name: web::Path) -> impl Responder match get_listens(&user_name).await { Ok(listens) => HttpResponse::Ok().json(listens), Err(e) => { - println!("Error getting listens for user {}: {}", user_name, e); + tracing::error!(error = %e, "Error getting listens for user {}", user_name); HttpResponse::InternalServerError().finish() } } @@ -157,7 +156,7 @@ pub async fn handle_get_listen_count(user_name: web::Path) -> impl Respo match get_listen_count(&user_name).await { Ok(count) => HttpResponse::Ok().json(count), Err(e) => { - println!("Error getting listen count for user {}: {}", user_name, e); + tracing::error!(error = %e, "Error getting listen count for user {}", user_name); HttpResponse::InternalServerError().finish() } } @@ -169,7 +168,7 @@ pub async fn handle_get_playing_now(user_name: web::Path) -> impl Respon match get_playing_now(&user_name).await { Ok(playing_now) => HttpResponse::Ok().json(playing_now), Err(e) => { - println!("Error getting playing now for user {}: {}", user_name, e); + tracing::error!(error = %e, "Error getting playing now for user {}", user_name); HttpResponse::InternalServerError().finish() } } @@ -181,7 +180,7 @@ pub async fn handle_get_artists(user_name: web::Path) -> impl Responder match get_top_artists(&user_name).await { Ok(artists) => HttpResponse::Ok().json(artists), Err(e) => { - println!("Error getting top artists: {}", e); + tracing::error!(error = %e, "Error getting top artists"); HttpResponse::InternalServerError().finish() } } @@ -193,7 +192,7 @@ pub async fn handle_get_releases(user_name: web::Path) -> impl Responder match get_top_releases(&user_name).await { Ok(releases) => HttpResponse::Ok().json(releases), Err(e) => { - println!("Error getting top releases: {}", e); + tracing::error!(error = %e, "Error getting top releases"); HttpResponse::InternalServerError().finish() } } @@ -205,7 +204,7 @@ pub async fn handle_get_recordings(user_name: web::Path) -> impl Respond match get_top_recordings(&user_name).await { Ok(recordings) => HttpResponse::Ok().json(recordings), Err(e) => { - println!("Error getting sitewide recordings: {}", e); + tracing::error!(error = %e, "Error getting top recordings"); HttpResponse::InternalServerError().finish() } } @@ -217,7 +216,7 @@ pub async fn handle_get_release_groups(user_name: web::Path) -> impl Res match get_top_release_groups(&user_name).await { Ok(release_groups) => HttpResponse::Ok().json(release_groups), Err(e) => { - println!("Error getting top release groups: {}", e); + tracing::error!(error = %e, "Error getting top release groups"); HttpResponse::InternalServerError().finish() } } @@ -229,7 +228,7 @@ pub async fn handle_get_recording_activity(user_name: web::Path) -> impl match get_top_recordings(&user_name).await { Ok(recordings) => HttpResponse::Ok().json(recordings), Err(e) => { - println!("Error getting top recordings: {}", e); + tracing::error!(error = %e, "Error getting top recordings"); HttpResponse::InternalServerError().finish() } } diff --git a/crates/scrobbler/src/main.rs b/crates/scrobbler/src/main.rs index 65e80e12..61dd9cd8 100644 --- a/crates/scrobbler/src/main.rs +++ b/crates/scrobbler/src/main.rs @@ -58,9 +58,9 @@ async fn main() -> Result<(), Error> { .parse::() .unwrap_or(7882); - println!( - "Starting Scrobble server @ {}", - format!("{}:{}", host, port).green() + tracing::info!( + url = %format!("http://{}:{}", host, port).bright_green(), + "Starting Scrobble server @" ); let limiter = web::Data::new( diff --git a/crates/scrobbler/src/rocksky.rs b/crates/scrobbler/src/rocksky.rs index 816b6649..8dc2d677 100644 --- a/crates/scrobbler/src/rocksky.rs +++ b/crates/scrobbler/src/rocksky.rs @@ -25,7 +25,7 @@ pub async fn scrobble(cache: &Cache, did: &str, track: Track, timestamp: u64) -> let token = generate_token(did)?; let client = Client::new(); - println!("Scrobbling track: \n {:#?}", track); + tracing::info!(did = %did, track = ?track, "Scrobbling track"); let response = client .post(&format!("{}/now-playing", ROCKSKY_API)) @@ -35,11 +35,10 @@ pub async fn scrobble(cache: &Cache, did: &str, track: Track, timestamp: u64) -> .await?; let status = response.status(); - println!("Response status: {}", status); + tracing::info!(did = %did, artist = %track.artist, track = %track.title, status = %status, "Scrobble response"); if !status.is_success() { let response_text = response.text().await?; - println!("did: {}", did); - println!("Failed to scrobble track: {}", response_text); + tracing::error!(did = %did, response = %response_text, "Failed to scrobble track"); return Err(Error::msg(format!( "Failed to scrobble track: {}", response_text diff --git a/crates/scrobbler/src/scrobbler.rs b/crates/scrobbler/src/scrobbler.rs index 09501817..a9f0adcb 100644 --- a/crates/scrobbler/src/scrobbler.rs +++ b/crates/scrobbler/src/scrobbler.rs @@ -133,7 +133,7 @@ pub async fn scrobble( ); let cached = cache.get(&key)?; if cached.is_some() { - println!("{}", format!("Cached: {}", key).yellow()); + tracing::info!(key = %key, "Cached:"); let track = serde_json::from_str::(&cached.unwrap())?; scrobble.album = Some(track.album.clone()); rocksky::scrobble(cache, &did, track, scrobble.timestamp).await?; @@ -144,7 +144,7 @@ pub async fn scrobble( if let Some(mbid) = &scrobble.mbid { // let result = repo::track::get_track_by_mbid(pool, mbid).await?; let result = mb_client.get_recording(mbid).await?; - println!("{}", "Musicbrainz (mbid)".yellow()); + tracing::info!(%scrobble.artist, %scrobble.track, "Musicbrainz (mbid)"); scrobble.album = Some(Track::from(result.clone()).album); rocksky::scrobble(cache, &did, result.into(), scrobble.timestamp).await?; tokio::time::sleep(std::time::Duration::from_secs(1)).await; @@ -154,7 +154,7 @@ pub async fn scrobble( let result = repo::track::get_track(pool, &scrobble.track, &scrobble.artist).await?; if let Some(track) = result { - println!("{}", "Xata (track)".yellow()); + tracing::info!(artist = %scrobble.artist, track = %scrobble.track, "Xata (track)"); scrobble.album = Some(track.album.clone()); let album = repo::album::get_album_by_track_id(pool, &track.xata_id).await?; let artist = repo::artist::get_artist_by_track_id(pool, &track.xata_id).await?; @@ -204,7 +204,7 @@ pub async fn scrobble( .await?; if let Some(track) = result.tracks.items.first() { - println!("{}", "Spotify (track)".yellow()); + tracing::info!(artist = %scrobble.artist, track = %scrobble.track, "Spotify (track)"); scrobble.album = Some(track.album.name.clone()); let mut track = track.clone(); @@ -232,19 +232,14 @@ pub async fn scrobble( if let Some(recording) = result.recordings.first() { let result = mb_client.get_recording(&recording.id).await?; - println!("{}", "Musicbrainz (recording)".yellow()); + tracing::info!(%scrobble.artist, %scrobble.track, "Musicbrainz (recording)"); scrobble.album = Some(Track::from(result.clone()).album); rocksky::scrobble(cache, &did, result.into(), scrobble.timestamp).await?; tokio::time::sleep(std::time::Duration::from_secs(1)).await; continue; } - println!( - "{} {} - {}, skipping", - "Track not found: ".yellow(), - scrobble.artist, - scrobble.track - ); + tracing::info!(artist = %scrobble.artist, track = %scrobble.track, "Track not found, skipping"); scrobble.ignored = Some(true); } @@ -313,7 +308,7 @@ pub async fn scrobble_v1( ); let cached = cache.get(&key)?; if cached.is_some() { - println!("{}", format!("Cached: {}", key).yellow()); + tracing::info!(key = %key, "Cached:"); let track = serde_json::from_str::(&cached.unwrap())?; scrobble.album = Some(track.album.clone()); rocksky::scrobble(cache, &did, track, scrobble.timestamp).await?; @@ -324,7 +319,7 @@ pub async fn scrobble_v1( if let Some(mbid) = &scrobble.mbid { // let result = repo::track::get_track_by_mbid(pool, mbid).await?; let result = mb_client.get_recording(mbid).await?; - println!("{}", "Musicbrainz (mbid)".yellow()); + tracing::info!(%scrobble.artist, %scrobble.track, "Musicbrainz (mbid)"); scrobble.album = Some(Track::from(result.clone()).album); rocksky::scrobble(cache, &did, result.into(), scrobble.timestamp).await?; tokio::time::sleep(std::time::Duration::from_secs(1)).await; @@ -334,7 +329,7 @@ pub async fn scrobble_v1( let result = repo::track::get_track(pool, &scrobble.track, &scrobble.artist).await?; if let Some(track) = result { - println!("{}", "Xata (track)".yellow()); + tracing::info!(artist = %scrobble.artist, track = %scrobble.track, "Xata (track)"); scrobble.album = Some(track.album.clone()); let album = repo::album::get_album_by_track_id(pool, &track.xata_id).await?; let artist = repo::artist::get_artist_by_track_id(pool, &track.xata_id).await?; @@ -384,7 +379,7 @@ pub async fn scrobble_v1( .await?; if let Some(track) = result.tracks.items.first() { - println!("{}", "Spotify (track)".yellow()); + tracing::info!(artist = %scrobble.artist, track = %scrobble.track, "Spotify (track)"); scrobble.album = Some(track.album.name.clone()); let mut track = track.clone(); @@ -412,19 +407,14 @@ pub async fn scrobble_v1( if let Some(recording) = result.recordings.first() { let result = mb_client.get_recording(&recording.id).await?; - println!("{}", "Musicbrainz (recording)".yellow()); + tracing::info!(%scrobble.artist, %scrobble.track, "Musicbrainz (recording)"); scrobble.album = Some(Track::from(result.clone()).album); rocksky::scrobble(cache, &did, result.into(), scrobble.timestamp).await?; tokio::time::sleep(std::time::Duration::from_secs(1)).await; return Ok(()); } - println!( - "{} {} - {}, skipping", - "Track not found: ".yellow(), - artist, - track - ); + tracing::info!(artist = %artist, track = %track, "Track not found, skipping"); Ok(()) } @@ -435,7 +425,7 @@ pub async fn scrobble_listenbrainz( req: &SubmitListensRequest, token: &str, ) -> Result<(), Error> { - println!("Listenbrainz\n{:#?}", req); + tracing::info!(req = ?req, "Listenbrainz submission"); if req.payload.is_empty() { return Err(Error::msg("No payload found")); @@ -481,12 +471,7 @@ pub async fn scrobble_listenbrainz( .get(&format!("listenbrainz:cache:{}:{}:{}", artist, track, did))? .is_some() { - println!( - "{} {} - {}, recently scrobbled", - "Already scrobbled: ".yellow(), - artist, - track - ); + tracing::info!(artist= %artist, track = %track, "Recently scrobbled, skipping"); return Ok(()); } @@ -496,23 +481,13 @@ pub async fn scrobble_listenbrainz( .get(&format!("{}:current", spotify_user.email))? .is_some() { - println!( - "{} {} - {}, currently scrobbling, skipping", - "Currently scrobbling: ".yellow(), - artist, - track - ); + tracing::info!(artist= %artist, track = %track, "Currently scrobbling, skipping"); return Ok(()); } } if cache.get(&format!("nowplaying:{}", did))?.is_some() { - println!( - "{} {} - {}, currently scrobbling, skipping", - "Currently scrobbling: ".yellow(), - artist, - track - ); + tracing::info!(artist= %artist, track = %track, "Currently scrobbling, skipping"); return Ok(()); } @@ -565,7 +540,7 @@ pub async fn scrobble_listenbrainz( ); let cached = cache.get(&key)?; if cached.is_some() { - println!("{}", format!("Cached: {}", key).yellow()); + tracing::info!(key = %key, "Cached"); let track = serde_json::from_str::(&cached.unwrap())?; scrobble.album = Some(track.album.clone()); rocksky::scrobble(cache, &did, track, scrobble.timestamp).await?; @@ -576,7 +551,7 @@ pub async fn scrobble_listenbrainz( if let Some(mbid) = &scrobble.mbid { // let result = repo::track::get_track_by_mbid(pool, mbid).await?; let result = mb_client.get_recording(mbid).await?; - println!("{}", "Musicbrainz (mbid)".yellow()); + tracing::info!("Musicbrainz (mbid)"); scrobble.album = Some(Track::from(result.clone()).album); rocksky::scrobble(cache, &did, result.into(), scrobble.timestamp).await?; tokio::time::sleep(std::time::Duration::from_secs(1)).await; @@ -586,7 +561,7 @@ pub async fn scrobble_listenbrainz( let result = repo::track::get_track(pool, &scrobble.track, &scrobble.artist).await?; if let Some(track) = result { - println!("{}", "Xata (track)".yellow()); + tracing::info!("Xata (track)"); scrobble.album = Some(track.album.clone()); let album = repo::album::get_album_by_track_id(pool, &track.xata_id).await?; let artist = repo::artist::get_artist_by_track_id(pool, &track.xata_id).await?; @@ -636,7 +611,7 @@ pub async fn scrobble_listenbrainz( .await?; if let Some(track) = result.tracks.items.first() { - println!("{}", "Spotify (track)".yellow()); + tracing::info!("Spotify (track)"); scrobble.album = Some(track.album.name.clone()); let mut track = track.clone(); @@ -676,12 +651,7 @@ pub async fn scrobble_listenbrainz( } */ - println!( - "{} {} - {}, skipping", - "Track not found: ".yellow(), - artist, - track - ); + tracing::warn!(artist = %artist, track = %track, "Track not found, skipping"); Ok(()) } diff --git a/crates/scrobbler/src/spotify/client.rs b/crates/scrobbler/src/spotify/client.rs index 70788ea2..e036e482 100644 --- a/crates/scrobbler/src/spotify/client.rs +++ b/crates/scrobbler/src/spotify/client.rs @@ -36,11 +36,7 @@ impl SpotifyClient { let data = response.text().await?; if data == "Too many requests" { - println!( - "> retry-after {}", - headers.get("retry-after").unwrap().to_str().unwrap() - ); - println!("> {} [get_album]", data); + tracing::info!(retry_after = %headers.get("retry-after").unwrap().to_str().unwrap(), data = %data, "Rate limited on get_album"); return Ok(None); } @@ -56,11 +52,7 @@ impl SpotifyClient { let data = response.text().await?; if data == "Too many requests" { - println!( - "> retry-after {}", - headers.get("retry-after").unwrap().to_str().unwrap() - ); - println!("> {} [get_artist]", data); + tracing::info!(retry_after = %headers.get("retry-after").unwrap().to_str().unwrap(), data = %data, "Rate limited on get_artist"); return Ok(None); } diff --git a/crates/webscrobbler/src/handlers.rs b/crates/webscrobbler/src/handlers.rs index ee548fad..0620e983 100644 --- a/crates/webscrobbler/src/handlers.rs +++ b/crates/webscrobbler/src/handlers.rs @@ -32,7 +32,7 @@ async fn handle_scrobble( req: HttpRequest, ) -> Result { let id = req.match_info().get("id").unwrap(); - println!("Received scrobble for ID: {}", id.cyan()); + tracing::info!(id = %id.bright_green(), "Received scrobble"); let pool = data.get_ref().clone(); @@ -50,15 +50,14 @@ async fn handle_scrobble( let body = read_payload!(payload); let params = serde_json::from_slice::(&body).map_err(|err| { let body = String::from_utf8_lossy(&body); - println!("Failed to parse JSON: {}", body); - println!("Failed to parse JSON: {}", err); + tracing::error!(body = %body, error = %err, "Failed to parse JSON"); actix_web::error::ErrorBadRequest(format!("Failed to parse JSON: {}", err)) })?; - println!("Parsed scrobble request: {:#?}", params); + tracing::info!(params = ?params, "Parsed scrobble request"); if params.event_name != "scrobble" { - println!("Skipping non-scrobble event: {}", params.event_name.green()); + tracing::info!(event_name = %params.event_name.cyan(), "Skipping non-scrobble event"); return Ok(HttpResponse::Ok().body("Skipping non-scrobble event")); } @@ -75,7 +74,7 @@ async fn handle_scrobble( })?; if spotify_token.is_some() { - println!("User has a Spotify token, skipping scrobble"); + tracing::info!("User has a Spotify token, skipping scrobble"); return Ok(HttpResponse::Ok().body("User has a Spotify token, skipping scrobble")); } } @@ -91,18 +90,12 @@ async fn handle_scrobble( )); if cached.is_err() { - println!( - "Failed to check cache for Emby scrobble: {}", - cached.unwrap_err() - ); + tracing::error!(artist = %artist, track = %track, error = %cached.unwrap_err(), "Failed to check cache for Emby scrobble"); return Ok(HttpResponse::Ok().body("Failed to check cache for Emby scrobble")); } if cached.unwrap().is_some() { - println!( - "Skipping duplicate scrobble for Emby: {} - {}", - artist, track - ); + tracing::warn!(artist = %artist, track = %track, "Skipping duplicate scrobble for Emby"); return Ok(HttpResponse::Ok().body("Skipping duplicate scrobble for Emby")); } } diff --git a/crates/webscrobbler/src/lib.rs b/crates/webscrobbler/src/lib.rs index 43f9cc3a..4127290e 100644 --- a/crates/webscrobbler/src/lib.rs +++ b/crates/webscrobbler/src/lib.rs @@ -44,10 +44,7 @@ pub async fn start_server() -> Result<(), Error> { .parse::() .unwrap_or(7883); - println!( - "Starting WebScrobbler Webhook @ {}", - format!("{}:{}", host, port).green() - ); + tracing::info!(url = %format!("http://{}:{}", host, port).bright_green(), "Starting WebScrobbler server @"); let limiter = web::Data::new( Limiter::builder("redis://127.0.0.1") diff --git a/crates/webscrobbler/src/rocksky.rs b/crates/webscrobbler/src/rocksky.rs index 1889ee8d..8ba8e4f4 100644 --- a/crates/webscrobbler/src/rocksky.rs +++ b/crates/webscrobbler/src/rocksky.rs @@ -1,5 +1,4 @@ use anyhow::Error; -use owo_colors::OwoColorize; use reqwest::Client; use crate::{auth::generate_token, cache::Cache, types::Track}; @@ -26,7 +25,7 @@ pub async fn scrobble(cache: &Cache, did: &str, track: Track, timestamp: u64) -> let token = generate_token(did)?; let client = Client::new(); - println!("Scrobbling track: \n {:#?}", track); + tracing::info!(did = %did, track = ?track, "Scrobbling track"); let response = client .post(&format!("{}/now-playing", ROCKSKY_API)) @@ -36,16 +35,13 @@ pub async fn scrobble(cache: &Cache, did: &str, track: Track, timestamp: u64) -> .await?; if !response.status().is_success() { - println!( - "Failed to scrobble track: {}", - response.status().to_string() - ); + tracing::error!(did = %did, artist = %track.artist, track = %track.title, status = %response.status(), "Failed to scrobble track"); let text = response.text().await?; - println!("Response: {}", text); + tracing::error!(did = %did, response = %text, "Response"); return Err(Error::msg(format!("Failed to scrobble track: {}", text))); } - println!("Scrobbled track: {}", track.title.green()); + tracing::info!(did = %did, artist = %track.artist, track = %track.title, "Scrobbled track"); Ok(()) } diff --git a/crates/webscrobbler/src/scrobbler.rs b/crates/webscrobbler/src/scrobbler.rs index b332d4dd..700309f7 100644 --- a/crates/webscrobbler/src/scrobbler.rs +++ b/crates/webscrobbler/src/scrobbler.rs @@ -34,7 +34,7 @@ pub async fn scrobble( let cached = cache.get(&key)?; if cached.is_some() { - println!("{}", format!("Cached: {}", key).yellow()); + tracing::info!(artist = %scrobble.data.song.parsed.artist, track = %scrobble.data.song.parsed.track, "Using cached track"); let track = serde_json::from_str::(&cached.unwrap())?; rocksky::scrobble(cache, &did, track, scrobble.time).await?; tokio::time::sleep(std::time::Duration::from_secs(1)).await; @@ -127,7 +127,7 @@ pub async fn scrobble( let result = spotify_client.search(&query).await?; if let Some(track) = result.tracks.items.first() { - println!("{}", "Spotify (track)".yellow()); + tracing::info!("Spotify (track)"); let mut track = track.clone(); if let Some(album) = spotify_client.get_album(&track.album.id).await? { @@ -154,18 +154,13 @@ pub async fn scrobble( if let Some(recording) = result.recordings.first() { let result = mb_client.get_recording(&recording.id).await?; - println!("{}", "Musicbrainz (recording)".yellow()); + tracing::info!("Musicbrainz (recording)"); rocksky::scrobble(cache, &did, result.into(), scrobble.time).await?; tokio::time::sleep(std::time::Duration::from_secs(1)).await; return Ok(()); } - println!( - "{} {} - {}, skipping", - "Track not found: ".yellow(), - scrobble.data.song.parsed.artist, - scrobble.data.song.parsed.track - ); + tracing::warn!(artist = %scrobble.data.song.parsed.artist, track = %scrobble.data.song.parsed.track, "Track not found, skipping"); Ok(()) } diff --git a/crates/webscrobbler/src/spotify/client.rs b/crates/webscrobbler/src/spotify/client.rs index 70788ea2..e036e482 100644 --- a/crates/webscrobbler/src/spotify/client.rs +++ b/crates/webscrobbler/src/spotify/client.rs @@ -36,11 +36,7 @@ impl SpotifyClient { let data = response.text().await?; if data == "Too many requests" { - println!( - "> retry-after {}", - headers.get("retry-after").unwrap().to_str().unwrap() - ); - println!("> {} [get_album]", data); + tracing::info!(retry_after = %headers.get("retry-after").unwrap().to_str().unwrap(), data = %data, "Rate limited on get_album"); return Ok(None); } @@ -56,11 +52,7 @@ impl SpotifyClient { let data = response.text().await?; if data == "Too many requests" { - println!( - "> retry-after {}", - headers.get("retry-after").unwrap().to_str().unwrap() - ); - println!("> {} [get_artist]", data); + tracing::info!(retry_after = %headers.get("retry-after").unwrap().to_str().unwrap(), data = %data, "Rate limited on get_artist"); return Ok(None); } -- 2.51.2