chore: move suggestions engine logs to debug level

Keep only start/result summary at INFO for user issue reports.
Move all intermediate steps (MBID resolution, config, engine steps) to DEBUG.

Also moved to debug:
- playlist_get_settings, playlist_get_stats
- playlist_get_local_tracks_with_position
- All [SuggestionsEngine] step logs
This commit is contained in:
vicrodh committed 2026-02-02 21:55:11 -06:00
1 parent 4e80dcf731
commit 1540146df6
3 files changed
+18 -18

No files matched your search

+12 -12
View File
@@ -149,9 +149,9 @@ impl SuggestionsEngine {
// 1. Ensure vectors exist for playlist artists (skip if configured) // 1. Ensure vectors exist for playlist artists (skip if configured)
let step1_start = Instant::now(); let step1_start = Instant::now();
if self.config.skip_vector_build { if self.config.skip_vector_build {
log::info!("[SuggestionsEngine] Step 1: SKIPPED (skip_vector_build=true), using only cached vectors"); log::debug!("[SuggestionsEngine] Step 1: SKIPPED (skip_vector_build=true), using only cached vectors");
} else { } else {
log::info!("[SuggestionsEngine] Step 1: Ensuring vectors for {} artists", playlist_artists.len()); log::debug!("[SuggestionsEngine] Step 1: Ensuring vectors for {} artists", playlist_artists.len());
for (i, (mbid, name)) in playlist_artists.iter().enumerate() { for (i, (mbid, name)) in playlist_artists.iter().enumerate() {
let artist_start = Instant::now(); let artist_start = Instant::now();
let _ = self let _ = self
@@ -160,14 +160,14 @@ impl SuggestionsEngine {
.await; .await;
log::debug!("[SuggestionsEngine] ensure_vector {}/{} took {:?}", i + 1, playlist_artists.len(), artist_start.elapsed()); log::debug!("[SuggestionsEngine] ensure_vector {}/{} took {:?}", i + 1, playlist_artists.len(), artist_start.elapsed());
} }
log::info!("[SuggestionsEngine] Step 1 completed in {:?}", step1_start.elapsed()); log::debug!("[SuggestionsEngine] Step 1 completed in {:?}", step1_start.elapsed());
} }
// 2. Compute combined playlist vector // 2. Compute combined playlist vector
log::info!("[SuggestionsEngine] Step 2: Computing playlist vector"); log::debug!("[SuggestionsEngine] Step 2: Computing playlist vector");
let step2_start = Instant::now(); let step2_start = Instant::now();
let playlist_vector = self.compute_playlist_vector(&playlist_artist_mbids).await?; let playlist_vector = self.compute_playlist_vector(&playlist_artist_mbids).await?;
log::info!("[SuggestionsEngine] Step 2 completed in {:?}, vector empty={}", step2_start.elapsed(), playlist_vector.is_empty()); log::debug!("[SuggestionsEngine] Step 2 completed in {:?}, vector empty={}", step2_start.elapsed(), playlist_vector.is_empty());
if playlist_vector.is_empty() { if playlist_vector.is_empty() {
log::warn!("[SuggestionsEngine] Playlist vector is empty, returning empty result"); log::warn!("[SuggestionsEngine] Playlist vector is empty, returning empty result");
@@ -180,7 +180,7 @@ impl SuggestionsEngine {
} }
// 3. Find related artists (using direct relationships, not vector similarity) // 3. Find related artists (using direct relationships, not vector similarity)
log::info!("[SuggestionsEngine] Step 3: Finding related artists"); log::debug!("[SuggestionsEngine] Step 3: Finding related artists");
let step3_start = Instant::now(); let step3_start = Instant::now();
let exclude_vec: Vec<String> = playlist_artist_mbids.to_vec(); let exclude_vec: Vec<String> = playlist_artist_mbids.to_vec();
let similar_artists = { let similar_artists = {
@@ -189,14 +189,14 @@ impl SuggestionsEngine {
// This finds members, collaborators, etc. from the MusicBrainz data // This finds members, collaborators, etc. from the MusicBrainz data
store.get_all_related_artists(&playlist_artist_mbids, &exclude_vec, self.config.max_artists)? store.get_all_related_artists(&playlist_artist_mbids, &exclude_vec, self.config.max_artists)?
}; };
log::info!("[SuggestionsEngine] Step 3 completed in {:?}, found {} related artists", step3_start.elapsed(), similar_artists.len()); log::debug!("[SuggestionsEngine] Step 3 completed in {:?}, found {} related artists", step3_start.elapsed(), similar_artists.len());
let similar_artists_count = similar_artists.len(); let similar_artists_count = similar_artists.len();
let mut source_artists = Vec::new(); let mut source_artists = Vec::new();
let mut all_tracks = Vec::new(); let mut all_tracks = Vec::new();
// 4a. First, search for tracks by playlist artists themselves (highest relevance) // 4a. First, search for tracks by playlist artists themselves (highest relevance)
log::info!("[SuggestionsEngine] Step 4a: Searching tracks for {} playlist artists", playlist_artists.len()); log::debug!("[SuggestionsEngine] Step 4a: Searching tracks for {} playlist artists", playlist_artists.len());
let step4a_start = Instant::now(); let step4a_start = Instant::now();
for (mbid, name) in playlist_artists { for (mbid, name) in playlist_artists {
@@ -220,10 +220,10 @@ impl SuggestionsEngine {
all_tracks.push(track); all_tracks.push(track);
} }
} }
log::info!("[SuggestionsEngine] Step 4a completed in {:?}, got {} tracks from playlist artists", step4a_start.elapsed(), all_tracks.len()); log::debug!("[SuggestionsEngine] Step 4a completed in {:?}, got {} tracks from playlist artists", step4a_start.elapsed(), all_tracks.len());
// 4b. Then search for tracks by related/similar artists // 4b. Then search for tracks by related/similar artists
log::info!("[SuggestionsEngine] Step 4b: Searching tracks for {} related artists", similar_artists.len()); log::debug!("[SuggestionsEngine] Step 4b: Searching tracks for {} related artists", similar_artists.len());
let step4b_start = Instant::now(); let step4b_start = Instant::now();
for (i, artist) in similar_artists.iter().enumerate() { for (i, artist) in similar_artists.iter().enumerate() {
@@ -263,11 +263,11 @@ impl SuggestionsEngine {
// Stop if we have enough tracks // Stop if we have enough tracks
if all_tracks.len() >= self.config.max_pool_size * 2 { if all_tracks.len() >= self.config.max_pool_size * 2 {
log::info!("[SuggestionsEngine] Reached extended pool size {} after {} related artists", all_tracks.len(), i + 1); log::debug!("[SuggestionsEngine] Reached extended pool size {} after {} related artists", all_tracks.len(), i + 1);
break; break;
} }
} }
log::info!("[SuggestionsEngine] Step 4b completed in {:?}, got {} total tracks", step4b_start.elapsed(), all_tracks.len()); log::debug!("[SuggestionsEngine] Step 4b completed in {:?}, got {} total tracks", step4b_start.elapsed(), all_tracks.len());
// 5. Deduplicate by title+artist (keeps highest similarity version) // 5. Deduplicate by title+artist (keeps highest similarity version)
let mut seen_titles: HashSet<String> = HashSet::new(); let mut seen_titles: HashSet<String> = HashSet::new();
@@ -142,7 +142,7 @@ pub async fn get_playlist_suggestions_v2(
} }
let resolve_elapsed = resolve_start.elapsed(); let resolve_elapsed = resolve_start.elapsed();
log::info!( log::debug!(
"[Suggestions] MBID resolution took {:?}: {} cached, {} resolved, {} skipped (skip_network={})", "[Suggestions] MBID resolution took {:?}: {} cached, {} resolved, {} skipped (skip_network={})",
resolve_elapsed, resolve_elapsed,
cached_count, cached_count,
@@ -171,7 +171,7 @@ pub async fn get_playlist_suggestions_v2(
)); ));
// Log config (already extracted above for skip_network check) // Log config (already extracted above for skip_network check)
log::info!("[Suggestions] Config: max_artists={}, tracks_per={}, pool_size={}, skip_build={}", log::debug!("[Suggestions] Config: max_artists={}, tracks_per={}, pool_size={}, skip_build={}",
config.max_artists, config.tracks_per_artist, config.max_pool_size, config.skip_vector_build); config.max_artists, config.tracks_per_artist, config.max_pool_size, config.skip_vector_build);
let engine = SuggestionsEngine::new( let engine = SuggestionsEngine::new(
@@ -185,7 +185,7 @@ pub async fn get_playlist_suggestions_v2(
let exclude_set: HashSet<u64> = input.exclude_track_ids.into_iter().collect(); let exclude_set: HashSet<u64> = input.exclude_track_ids.into_iter().collect();
// Generate suggestions // Generate suggestions
log::info!("[Suggestions] Calling engine.generate_suggestions with {} artists", artist_info.len()); log::debug!("[Suggestions] Calling engine.generate_suggestions with {} artists", artist_info.len());
let engine_start = std::time::Instant::now(); let engine_start = std::time::Instant::now();
let result = engine let result = engine
+3 -3
View File
@@ -1218,7 +1218,7 @@ pub async fn playlist_get_settings(
playlist_id: u64, playlist_id: u64,
state: State<'_, LibraryState>, state: State<'_, LibraryState>,
) -> Result<Option<PlaylistSettings>, String> { ) -> Result<Option<PlaylistSettings>, String> {
log::info!("Command: playlist_get_settings {}", playlist_id); log::debug!("Command: playlist_get_settings {}", playlist_id);
let db = state.db.lock().await; let db = state.db.lock().await;
db.get_playlist_settings(playlist_id) db.get_playlist_settings(playlist_id)
@@ -1340,7 +1340,7 @@ pub async fn playlist_get_local_tracks_with_position(
playlist_id: u64, playlist_id: u64,
state: State<'_, LibraryState>, state: State<'_, LibraryState>,
) -> Result<Vec<crate::library::PlaylistLocalTrack>, String> { ) -> Result<Vec<crate::library::PlaylistLocalTrack>, String> {
log::info!("Command: playlist_get_local_tracks_with_position {}", playlist_id); log::debug!("Command: playlist_get_local_tracks_with_position {}", playlist_id);
let db = state.db.lock().await; let db = state.db.lock().await;
db.get_playlist_local_tracks_with_position(playlist_id) db.get_playlist_local_tracks_with_position(playlist_id)
@@ -1457,7 +1457,7 @@ pub async fn playlist_get_stats(
playlist_id: u64, playlist_id: u64,
state: State<'_, LibraryState>, state: State<'_, LibraryState>,
) -> Result<Option<PlaylistStats>, String> { ) -> Result<Option<PlaylistStats>, String> {
log::info!("Command: playlist_get_stats {}", playlist_id); log::debug!("Command: playlist_get_stats {}", playlist_id);
let db = state.db.lock().await; let db = state.db.lock().await;
db.get_playlist_stats(playlist_id) db.get_playlist_stats(playlist_id)