From 925bd64e38ce30828ba0703aee28b6bc33c08942 Mon Sep 17 00:00:00 2001 From: AFE123x Date: Sun, 15 Feb 2026 23:41:46 -0500 Subject: [PATCH 1/2] Implement new logging system - Implemented system that logs into /tmp/spotatui_logs/spotatuilog{PID} - PID is your process ID - TUI will indicate file location on start (when you call cargo run, or spotatui) - use fern for formatting log messages, and log for the logging itself. - in main.rs: replaced various println!() and eprintln!() statements with info!() and error!() - in app.rs: added info!() logs statements to indicate certain events were hapenning (like changing volume) --- Cargo.lock | 11 +++++ Cargo.toml | 2 + src/app.rs | 24 +++++++++++ src/main.rs | 115 +++++++++++++++++++++++++++++++++++++------------- src/ui/mod.rs | 5 +++ 5 files changed, 128 insertions(+), 29 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 9d6d48e7..98276d4e 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1328,6 +1328,15 @@ dependencies = [ "simd-adler32", ] +[[package]] +name = "fern" +version = "0.7.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4316185f709b23713e41e3195f90edef7fb00c3ed4adc79769cf09cc762a3b29" +dependencies = [ + "log", +] + [[package]] name = "fiat-crypto" version = "0.2.9" @@ -4644,6 +4653,7 @@ dependencies = [ "crossterm", "dirs", "discord-rich-presence", + "fern", "futures", "librespot-connect", "librespot-core", @@ -4651,6 +4661,7 @@ dependencies = [ "librespot-oauth", "librespot-playback", "librespot-protocol", + "log", "mpris-server", "objc2", "objc2-foundation", diff --git a/Cargo.toml b/Cargo.toml index 0c0bd1b3..697a9f20 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -61,6 +61,8 @@ librespot-metadata = { version = "0.8", optional = true } librespot-protocol = { version = "0.8", optional = true, default-features = false } protobuf = { version = "3.7", optional = true } futures = "0.3.31" +log = "0.4.29" +fern = "0.7.1" [target.'cfg(all(target_os = "linux", not(target_env = "musl")))'.dependencies] pipewire = { version = "0.9", optional = true } diff --git a/src/app.rs b/src/app.rs index 0f36379c..b1b9bb36 100644 --- a/src/app.rs +++ b/src/app.rs @@ -33,6 +33,7 @@ use std::{ }; use arboard::Clipboard; +use log::info; pub const LIBRARY_OPTIONS: [&str; 6] = [ "Discover", @@ -1039,6 +1040,7 @@ impl App { } pub fn seek_forwards(&mut self) { + info!("seeking forwards by {} ms", self.user_config.behavior.seek_milliseconds); if let Some(CurrentPlaybackContext { item: Some(item), .. }) = &self.current_playback_context @@ -1088,6 +1090,7 @@ impl App { } pub fn seek_backwards(&mut self) { + info!("seeking backwards by {} ms", self.user_config.behavior.seek_milliseconds); let old_progress = match self.seek_ms { Some(seek_ms) => seek_ms, None => self.song_progress_ms, @@ -1251,6 +1254,7 @@ impl App { ); if next_volume != current_volume { + info!("increasing volume: {} -> {}", current_volume, next_volume); // Use native streaming player for instant control (bypasses event channel latency) #[cfg(feature = "streaming")] if self.is_native_streaming_active_for_playback() { @@ -1283,6 +1287,7 @@ impl App { if next_volume != current_volume { let next_volume_u8 = next_volume as u8; + info!("decreasing volume: {} -> {}", current_volume, next_volume_u8); // Use native streaming player for instant control (bypasses event channel latency) #[cfg(feature = "streaming")] @@ -1307,6 +1312,7 @@ impl App { } pub fn handle_error(&mut self, e: anyhow::Error) { + info!("error occurred: {}", e); self.push_navigation_stack(RouteId::Error, ActiveBlock::Error); self.api_error = e.to_string(); } @@ -1410,6 +1416,7 @@ impl App { } pub fn previous_track(&mut self) { + info!("playing previous track or restarting current track"); if self.song_progress_ms >= 3_000 { // If more than 3 seconds into the song, restart from beginning #[cfg(feature = "streaming")] @@ -1451,6 +1458,7 @@ impl App { } pub fn next_track(&mut self) { + info!("skipping to next track"); // Use native streaming player for instant control (bypasses event channel latency) #[cfg(feature = "streaming")] if self.is_native_streaming_active_for_playback() { @@ -1478,6 +1486,7 @@ impl App { // The navigation_stack actually only controls the large block to the right of `library` and // `playlists` pub fn push_navigation_stack(&mut self, next_route_id: RouteId, next_active_block: ActiveBlock) { + info!("navigating to {:?}", next_route_id); if !self .navigation_stack .last() @@ -1493,6 +1502,7 @@ impl App { } pub fn pop_navigation_stack(&mut self) -> Option { + info!("navigating back"); if self.navigation_stack.len() == 1 { None } else { @@ -1524,6 +1534,7 @@ impl App { } pub fn copy_song_url(&mut self) { + info!("copying song url to clipboard"); let clipboard = match &mut self.clipboard { Some(ctx) => ctx, None => return, @@ -1561,6 +1572,7 @@ impl App { } pub fn copy_album_url(&mut self) { + info!("copying album url to clipboard"); let clipboard = match &mut self.clipboard { Some(ctx) => ctx, None => return, @@ -1683,6 +1695,7 @@ impl App { pub fn shuffle(&mut self) { if let Some(context) = &self.current_playback_context.clone() { let new_shuffle_state = !context.shuffle_state; + info!("toggling shuffle: {}", new_shuffle_state); // Use native streaming player for instant control (bypasses event channel latency) #[cfg(feature = "streaming")] @@ -1736,6 +1749,7 @@ impl App { } pub fn current_user_saved_album_delete(&mut self, block: ActiveBlock) { + info!("removing album from saved albums"); match block { ActiveBlock::SearchResultBlock => { if let Some(albums) = &self.search_results.albums { @@ -1769,6 +1783,7 @@ impl App { } pub fn current_user_saved_album_add(&mut self, block: ActiveBlock) { + info!("adding album to saved albums"); match block { ActiveBlock::SearchResultBlock => { if let Some(albums) = &self.search_results.albums { @@ -1842,6 +1857,7 @@ impl App { } pub fn user_unfollow_artists(&mut self, block: ActiveBlock) { + info!("unfollowing artist"); match block { ActiveBlock::SearchResultBlock => { if let Some(artists) = &self.search_results.artists { @@ -1878,6 +1894,7 @@ impl App { } pub fn user_follow_artists(&mut self, block: ActiveBlock) { + info!("following artist"); match block { ActiveBlock::SearchResultBlock => { if let Some(artists) = &self.search_results.artists { @@ -1904,6 +1921,7 @@ impl App { } pub fn user_follow_playlist(&mut self) { + info!("following playlist"); if let SearchResult { playlists: Some(ref playlists), selected_playlists_index: Some(selected_index), @@ -1923,6 +1941,7 @@ impl App { } pub fn user_unfollow_playlist(&mut self) { + info!("unfollowing playlist"); if let (Some(selected_index), Some(user)) = (self.selected_playlist_index, &self.user) { if let Some(PlaylistFolderItem::Playlist { index, .. }) = self.get_playlist_display_item_at(selected_index) @@ -1940,6 +1959,7 @@ impl App { } pub fn user_unfollow_playlist_search_result(&mut self) { + info!("unfollowing playlist from search results"); if let (Some(playlists), Some(selected_index), Some(user)) = ( &self.search_results.playlists, self.search_results.selected_playlists_index, @@ -1956,6 +1976,7 @@ impl App { } pub fn user_follow_show(&mut self, block: ActiveBlock) { + info!("following show"); match block { ActiveBlock::SearchResultBlock => { if let Some(shows) = &self.search_results.shows { @@ -1985,6 +2006,7 @@ impl App { } pub fn user_unfollow_show(&mut self, block: ActiveBlock) { + info!("unfollowing show"); match block { ActiveBlock::Podcasts => { if let Some(shows) = self.library.saved_shows.get_results(None) { @@ -2023,6 +2045,7 @@ impl App { /// Toggle the audio analysis visualization view /// This now uses local FFT analysis instead of the deprecated Spotify API pub fn get_audio_analysis(&mut self) { + info!("entering audio analysis view"); if self.get_current_route().id != RouteId::Analysis { // Enter visualization mode self.push_navigation_stack(RouteId::Analysis, ActiveBlock::Analysis); @@ -2033,6 +2056,7 @@ impl App { pub fn repeat(&mut self) { if let Some(context) = &self.current_playback_context.clone() { let current_repeat_state = context.repeat_state; + info!("toggling repeat mode: {:?}", current_repeat_state); // Use native streaming player for instant control (bypasses event channel latency) #[cfg(feature = "streaming")] diff --git a/src/main.rs b/src/main.rs index 14342322..82b45a93 100644 --- a/src/main.rs +++ b/src/main.rs @@ -62,6 +62,7 @@ use crossterm::{ terminal::SetTitle, ExecutableCommand, }; +use log::info; use network::{IoEvent, Network}; use ratatui::backend::Backend; use redirect_uri::redirect_uri_web_server; @@ -331,7 +332,7 @@ async fn save_token_to_file(spotify: &AuthCodePkceSpotify, path: &PathBuf) -> Re if let Some(ref token) = *token_lock { let token_json = serde_json::to_string_pretty(token)?; fs::write(path, token_json)?; - println!("Token saved to {}", path.display()); + info!("token cached to {}", path.display()); } Ok(()) } @@ -348,7 +349,7 @@ async fn load_token_from_file(spotify: &AuthCodePkceSpotify, path: &PathBuf) -> *token_lock = Some(token); drop(token_lock); - println!("Found cached authentication token"); + info!("authentication token loaded from cache"); Ok(true) } @@ -405,11 +406,11 @@ async fn ensure_auth_token( let mut needs_auth = match load_token_from_file(spotify, token_cache_path).await { Ok(true) => false, Ok(false) => { - println!("No cached token found, need to authenticate"); + info!("no cached token found, authentication required"); true } Err(e) => { - println!("Failed to read token cache: {}", e); + info!("failed to read token cache: {}", e); true } }; @@ -426,11 +427,11 @@ async fn ensure_auth_token( || err_text_lower.contains("token expired"); if should_reauth { - println!("Cached token is no longer valid. Re-authentication required."); + info!("cached authentication token is invalid, re-authentication required"); if token_cache_path.exists() { if let Err(remove_err) = fs::remove_file(token_cache_path) { - println!( - "Failed to remove stale token cache {}: {}", + info!( + "failed to remove stale token cache {}: {}", token_cache_path.display(), remove_err ); @@ -444,6 +445,7 @@ async fn ensure_auth_token( } if needs_auth { + info!("starting spotify authentication flow on port {}", auth_port); let auth_url = spotify.get_authorize_url(None)?; println!("\nAttempting to open this URL in your browser:"); @@ -462,9 +464,10 @@ async fn ensure_auth_token( match redirect_uri_web_server(auth_port) { Ok(url) => { if let Some(code) = spotify.parse_response_code(&url) { + info!("authorization code received, requesting access token"); spotify.request_token(&code).await?; save_token_to_file(spotify, token_cache_path).await?; - println!("✓ Successfully authenticated with Spotify!"); + info!("successfully authenticated with spotify"); } else { return Err(anyhow!( "Failed to parse authorization code from callback URL" @@ -472,14 +475,17 @@ async fn ensure_auth_token( } } Err(()) => { + info!("redirect uri web server failed, using manual authentication"); println!("Starting webserver failed. Continuing with manual authentication"); println!("Please open this URL in your browser: {}", auth_url); println!("Enter the URL you were redirected to: "); let mut input = String::new(); io::stdin().read_line(&mut input)?; if let Some(code) = spotify.parse_response_code(&input) { + info!("authorization code received from manual input, requesting access token"); spotify.request_token(&code).await?; save_token_to_file(spotify, token_cache_path).await?; + info!("successfully authenticated with spotify"); } else { return Err(anyhow!("Failed to parse authorization code from input URL")); } @@ -498,6 +504,42 @@ fn init_audio_backend() { #[cfg(not(all(target_os = "linux", feature = "streaming")))] fn init_audio_backend() {} +fn setup_logging() -> anyhow::Result<()> { + // Get the current Process ID + let pid = std::process::id(); + + // Construct the log file path using the PID + let log_dir = "/tmp/spotatui_logs/"; + let log_path = format!("{}/spotatuilog{}", log_dir, pid); + + // Ensure the directory exists. If not, create. + if !std::path::Path::new(log_dir).exists() { + std::fs::create_dir_all(log_dir).map_err(|e| { + anyhow::anyhow!("Failed to create log directory {}: {}", log_dir, e) + })?; + } + // define format of log messages. + fern::Dispatch::new() + .format(|out, message, record| { + out.finish(format_args!( + "{}[{}][{}] {}", + chrono::Local::now().format("[%Y-%m-%d][%H:%M:%S]"), + record.target(), + record.level(), + message + )) + }) + .level(log::LevelFilter::Info) + .chain(fern::log_file(&log_path)?) // Use the dynamic path + .apply() + .map_err(|e| anyhow::anyhow!("Failed to initialize logger: {}", e))?; + + // Print the location of log for user reference. + println!("Logging to: {}", log_path); + + Ok(()) +} + fn install_panic_hook() { let default_hook = panic::take_hook(); panic::set_hook(Box::new(move |info| { @@ -540,9 +582,13 @@ fn install_panic_hook() { #[tokio::main] async fn main() -> Result<()> { + setup_logging()?; + info!("spotatui {} starting up", env!("CARGO_PKG_VERSION")); init_audio_backend(); + info!("audio backend initialized"); install_panic_hook(); + info!("panic hook configured"); let mut clap_app = ClapApp::new(env!("CARGO_PKG_NAME")) .version(env!("CARGO_PKG_VERSION")) @@ -631,6 +677,7 @@ of the app. Beware that this comes at a CPU cost!", user_config.path_to_config.replace(path); } user_config.load_config()?; + info!("user config loaded successfully"); let initial_shuffle_enabled = user_config.behavior.shuffle_enabled; if let Some(tick_rate) = matches @@ -646,6 +693,7 @@ of the app. Beware that this comes at a CPU cost!", let mut client_config = ClientConfig::new(); client_config.load_config()?; + info!("client authentication config loaded"); let reconfigure_auth = matches.get_flag("reconfigure-auth"); @@ -822,6 +870,7 @@ of the app. Beware that this comes at a CPU cost!", drop(token_lock); // Release the lock let (sync_io_tx, sync_io_rx) = std::sync::mpsc::channel::(); + info!("app state initialized"); // Initialise app state let app = Arc::new(Mutex::new(App::new( @@ -832,6 +881,7 @@ of the app. Beware that this comes at a CPU cost!", // Work with the cli (not really async) if let Some(cmd) = matches.subcommand_name() { + info!("running in cli mode with command: {}", cmd); // Save, because we checked if the subcommand is present at runtime let m = matches.subcommand_matches(cmd).unwrap(); #[cfg(feature = "streaming")] @@ -844,9 +894,11 @@ of the app. Beware that this comes at a CPU cost!", ); // Launch the UI (async) } else { + info!("launching interactive terminal ui"); // Initialize streaming player if enabled #[cfg(feature = "streaming")] let streaming_player = if client_config.enable_streaming { + info!("initializing native streaming player"); let streaming_config = player::StreamingConfig { device_name: client_config.streaming_device_name.clone(), bitrate: client_config.streaming_bitrate, @@ -878,26 +930,21 @@ of the app. Beware that this comes at a CPU cost!", match init_result { Some(Ok(Ok(p))) => { - println!("Streaming player initialized as '{}'", p.device_name()); + info!("native streaming player initialized as '{}'", p.device_name()); // Note: We don't activate() here - that's handled by AutoSelectStreamingDevice // which respects the user's saved device preference (e.g., spotifyd) Some(Arc::new(p)) } Some(Ok(Err(e))) => { - println!("Failed to initialize streaming: {}", e); - println!("Falling back to API-based playback control"); + info!("failed to initialize streaming: {} - falling back to web api", e); None } Some(Err(e)) => { - println!("Streaming initialization panicked: {}", e); - println!("Falling back to API-based playback control"); + info!("streaming initialization panicked: {} - falling back to web api", e); None } None => { - println!( - "Streaming initialization timed out after {}s; falling back to API-based playback control (set SPOTATUI_STREAMING_INIT_TIMEOUT_SECS to adjust)", - init_timeout_secs - ); + info!("streaming initialization timed out after {}s - falling back to web api", init_timeout_secs); //you can adjust timeout using SPOTATUI_STREAMING_INIT_TIMEOUT_SECS environment variable None } } @@ -907,7 +954,7 @@ of the app. Beware that this comes at a CPU cost!", #[cfg(feature = "streaming")] if streaming_player.is_some() { - println!("Native playback enabled - 'spotatui' is available as a Spotify Connect device"); + info!("native playback enabled - spotatui is available as a spotify connect device"); } // Store streaming player reference in App for direct control (bypasses event channel) @@ -953,14 +1000,11 @@ of the app. Beware that this comes at a CPU cost!", let mpris_manager: Option> = if streaming_player.is_some() { match mpris::MprisManager::new() { Ok(mgr) => { - println!("MPRIS D-Bus interface registered - media keys and playerctl enabled"); + info!("mpris d-bus interface registered - media keys and playerctl enabled"); Some(Arc::new(mgr)) } Err(e) => { - println!( - "Failed to initialize MPRIS: {} - media key control disabled", - e - ); + info!("failed to initialize mpris: {} - media key control disabled", e); None } } @@ -982,14 +1026,11 @@ of the app. Beware that this comes at a CPU cost!", if streaming_player.is_some() { match macos_media::MacMediaManager::new() { Ok(mgr) => { - println!("macOS Now Playing interface registered - media keys enabled"); + info!("macos now playing interface registered - media keys enabled"); Some(Arc::new(mgr)) } Err(e) => { - println!( - "Failed to initialize macOS media control: {} - media keys disabled", - e - ); + info!("failed to initialize macos media control: {} - media keys disabled", e); None } } @@ -999,9 +1040,20 @@ of the app. Beware that this comes at a CPU cost!", #[cfg(feature = "discord-rpc")] let discord_rpc_manager: DiscordRpcHandle = if user_config.behavior.enable_discord_rpc { - resolve_discord_app_id(&user_config) + match resolve_discord_app_id(&user_config) .and_then(|app_id| discord_rpc::DiscordRpcManager::new(app_id).ok()) + { + Some(mgr) => { + info!("discord rich presence enabled"); + Some(mgr) + } + None => { + info!("discord rich presence failed to initialize"); + None + } + } } else { + info!("discord rich presence disabled"); None }; #[cfg(not(feature = "discord-rpc"))] @@ -1057,6 +1109,7 @@ of the app. Beware that this comes at a CPU cost!", if let Some(ref player) = streaming_player { let event_rx = player.get_event_channel(); let app_for_events = Arc::clone(&app); + info!("spawning native player event handler"); #[cfg(all(feature = "mpris", target_os = "linux"))] tokio::spawn(async move { handle_player_events( @@ -1081,6 +1134,7 @@ of the app. Beware that this comes at a CPU cost!", } let cloned_app = Arc::clone(&app); + info!("spawning spotify network event handler"); tokio::spawn(async move { #[cfg(feature = "streaming")] let mut network = Network::new(spotify, client_config, &app, streaming_player_clone); @@ -1154,6 +1208,7 @@ of the app. Beware that this comes at a CPU cost!", start_tokio(sync_io_rx, &mut network).await; }); // The UI must run in the "main" thread + info!("starting terminal ui event loop"); #[cfg(all(feature = "streaming", feature = "mpris", target_os = "linux"))] start_ui( user_config, @@ -1773,6 +1828,7 @@ async fn start_ui( mpris_manager: Option>, discord_rpc_manager: DiscordRpcHandle, ) -> Result<()> { + info!("ui thread initialized"); #[cfg(not(feature = "discord-rpc"))] let _ = discord_rpc_manager; // Terminal initialization @@ -2069,6 +2125,7 @@ async fn start_ui( _mpris_manager: Option<()>, discord_rpc_manager: DiscordRpcHandle, ) -> Result<()> { + info!("ui thread initialized"); #[cfg(not(feature = "discord-rpc"))] let _ = discord_rpc_manager; #[cfg(not(feature = "streaming"))] diff --git a/src/ui/mod.rs b/src/ui/mod.rs index 94821b4d..843bc6b4 100644 --- a/src/ui/mod.rs +++ b/src/ui/mod.rs @@ -1668,6 +1668,11 @@ fn build_changelog_lines( let mut lines: Vec> = vec![]; let max_width = usize::from(max_width); + lines.push(Line::from(Span::styled( + format!("Log located in /tmp/spotatui_logs/spotatuilog{}",std::process::id()), + Style::default().fg(theme.hint), + ))); + lines.push(Line::from(Span::styled( "Please report any bugs or missing features to https://github.com/LargeModGames/spotatui", Style::default().fg(theme.hint), From 001e6354a366607dc6a7f32e99d02977c1eedaa8 Mon Sep 17 00:00:00 2001 From: LargeModGames Date: Mon, 16 Feb 2026 13:24:15 +0100 Subject: [PATCH 2/2] chore: update version to 0.36.3-debug.1 and add session log file for runtime diagnostics --- CHANGELOG.md | 8 +++++++- Cargo.lock | 2 +- Cargo.toml | 2 +- 3 files changed, 9 insertions(+), 3 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a4948997..a4d8bed2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,6 +1,12 @@ # Changelog -## [0.36.2] +## [0.36.3-debug.1] - 2026-02-16 + +### Added + +- **Session Log File for Runtime Diagnostics**: spotatui now writes runtime logs to `/tmp/spotatui_logs/spotatuilog{PID}` so testers can tail logs while reproducing issue #96 ([#102](https://github.com/LargeModGames/spotatui/pull/102)). + +## [0.36.2] - 2026-02-15 ### Added diff --git a/Cargo.lock b/Cargo.lock index 98276d4e..e5e0ed7a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4639,7 +4639,7 @@ dependencies = [ [[package]] name = "spotatui" -version = "0.36.2" +version = "0.36.3-debug.1" dependencies = [ "anyhow", "arboard", diff --git a/Cargo.toml b/Cargo.toml index 697a9f20..16445d77 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -6,7 +6,7 @@ documentation = "https://github.com/LargeModGames/spotatui" repository = "https://github.com/LargeModGames/spotatui" keywords = ["spotify", "tui", "cli", "terminal"] categories = ["command-line-utilities"] -version = "0.36.2" +version = "0.36.3-debug.1" authors = ["LargeModGames "] edition = "2021" license = "MIT"