diff --git a/allstarr/Program.cs b/allstarr/Program.cs index fdb7d3d..5ac01a7 100644 --- a/allstarr/Program.cs +++ b/allstarr/Program.cs @@ -97,6 +97,10 @@ builder.Services.ConfigureAll(options => MaxAutomaticRedirections = 5 }; }); + + // Suppress verbose HTTP logging - these are logged at Debug level by default + // but we want to reduce noise in production logs + options.SuppressHandlerScope = true; }); builder.Services.AddEndpointsApiExplorer(); builder.Services.AddSwaggerGen(); diff --git a/allstarr/Services/Common/CacheWarmingService.cs b/allstarr/Services/Common/CacheWarmingService.cs index 47b1c1f..082d3d4 100644 --- a/allstarr/Services/Common/CacheWarmingService.cs +++ b/allstarr/Services/Common/CacheWarmingService.cs @@ -1,4 +1,5 @@ using System.Text.Json; +using allstarr.Models.Domain; namespace allstarr.Services.Common; @@ -115,10 +116,12 @@ public class CacheWarmingService : IHostedService return 0; } - var files = Directory.GetFiles(PlaylistCacheDirectory, "*_items.json"); + var itemsFiles = Directory.GetFiles(PlaylistCacheDirectory, "*_items.json"); + var matchedFiles = Directory.GetFiles(PlaylistCacheDirectory, "*_matched.json"); var warmedCount = 0; - foreach (var file in files) + // Warm playlist items cache + foreach (var file in itemsFiles) { if (cancellationToken.IsCancellationRequested) break; @@ -145,13 +148,51 @@ public class CacheWarmingService : IHostedService await _cache.SetAsync(redisKey, items, TimeSpan.FromHours(24)); warmedCount++; - _logger.LogDebug("🔥 Warmed playlist cache for {Playlist} ({Count} items)", + _logger.LogDebug("🔥 Warmed playlist items cache for {Playlist} ({Count} items)", playlistName, items.Count); } } catch (Exception ex) { - _logger.LogWarning(ex, "Failed to warm playlist cache from file: {File}", file); + _logger.LogWarning(ex, "Failed to warm playlist items cache from file: {File}", file); + } + } + + // Warm matched tracks cache + foreach (var file in matchedFiles) + { + if (cancellationToken.IsCancellationRequested) + break; + + try + { + // Check if cache is expired (1 hour) + var fileInfo = new FileInfo(file); + if (DateTime.UtcNow - fileInfo.LastWriteTimeUtc > TimeSpan.FromHours(1)) + { + continue; // Skip expired matched tracks + } + + var json = await File.ReadAllTextAsync(file, cancellationToken); + var matchedTracks = JsonSerializer.Deserialize>(json); + + if (matchedTracks != null && matchedTracks.Count > 0) + { + // Extract playlist name from filename + var fileName = Path.GetFileNameWithoutExtension(file); + var playlistName = fileName.Replace("_matched", ""); + + var redisKey = $"spotify:matched:ordered:{playlistName}"; + await _cache.SetAsync(redisKey, matchedTracks, TimeSpan.FromHours(1)); + warmedCount++; + + _logger.LogDebug("🔥 Warmed matched tracks cache for {Playlist} ({Count} tracks)", + playlistName, matchedTracks.Count); + } + } + catch (Exception ex) + { + _logger.LogWarning(ex, "Failed to warm matched tracks cache from file: {File}", file); } } @@ -169,4 +210,15 @@ public class CacheWarmingService : IHostedService public string Genre { get; set; } = ""; public DateTime CachedAt { get; set; } } + + private class MatchedTrack + { + public int Position { get; set; } + public string SpotifyId { get; set; } = ""; + public string SpotifyTitle { get; set; } = ""; + public string SpotifyArtist { get; set; } = ""; + public string? Isrc { get; set; } + public string MatchType { get; set; } = ""; + public Song? MatchedSong { get; set; } + } } diff --git a/allstarr/Services/Spotify/SpotifyTrackMatchingService.cs b/allstarr/Services/Spotify/SpotifyTrackMatchingService.cs index 5f7daa2..611ccb9 100644 --- a/allstarr/Services/Spotify/SpotifyTrackMatchingService.cs +++ b/allstarr/Services/Spotify/SpotifyTrackMatchingService.cs @@ -27,6 +27,8 @@ public class SpotifyTrackMatchingService : BackgroundService private readonly IServiceProvider _serviceProvider; private const int DelayBetweenSearchesMs = 150; // 150ms = ~6.6 searches/second to avoid rate limiting private const int BatchSize = 11; // Number of parallel searches (matches SquidWTF provider count) + private DateTime _lastMatchingRun = DateTime.MinValue; + private readonly TimeSpan _minimumMatchingInterval = TimeSpan.FromMinutes(5); // Don't run more than once per 5 minutes public SpotifyTrackMatchingService( IOptions spotifySettings, @@ -164,7 +166,17 @@ public class SpotifyTrackMatchingService : BackgroundService private async Task MatchAllPlaylistsAsync(CancellationToken cancellationToken) { + // Check if we've run too recently (cooldown period) + var timeSinceLastRun = DateTime.UtcNow - _lastMatchingRun; + if (timeSinceLastRun < _minimumMatchingInterval) + { + _logger.LogInformation("Skipping track matching - last run was {Seconds}s ago (minimum interval: {MinSeconds}s)", + (int)timeSinceLastRun.TotalSeconds, (int)_minimumMatchingInterval.TotalSeconds); + return; + } + _logger.LogInformation("=== STARTING TRACK MATCHING ==="); + _lastMatchingRun = DateTime.UtcNow; var playlists = _spotifySettings.Playlists; if (playlists.Count == 0) @@ -314,39 +326,40 @@ public class SpotifyTrackMatchingService : BackgroundService // Check cache - use snapshot/timestamp to detect changes var existingMatched = await _cache.GetAsync>(matchedTracksKey); - // Check if we have manual mappings that need to be preserved - var hasManualMappings = false; - foreach (var track in tracksToMatch) + // CRITICAL: Skip matching if cache exists and is valid + // Only re-match if cache is missing OR if we detect manual mappings that need to be applied + if (existingMatched != null && existingMatched.Count > 0) { - var manualMappingKey = $"spotify:manual-map:{playlistName}:{track.SpotifyId}"; - var manualMapping = await _cache.GetAsync(manualMappingKey); - if (!string.IsNullOrEmpty(manualMapping)) + // Check if we have NEW manual mappings that aren't in the cache + var hasNewManualMappings = false; + foreach (var track in tracksToMatch) { - hasManualMappings = true; - break; + // Check if this track has a manual mapping but isn't in the cached results + var manualMappingKey = $"spotify:manual-map:{playlistName}:{track.SpotifyId}"; + var manualMapping = await _cache.GetAsync(manualMappingKey); + + var externalMappingKey = $"spotify:external-map:{playlistName}:{track.SpotifyId}"; + var externalMapping = await _cache.GetAsync(externalMappingKey); + + var hasManualMapping = !string.IsNullOrEmpty(manualMapping) || HasValue(externalMapping); + var isInCache = existingMatched.Any(m => m.SpotifyId == track.SpotifyId); + + // If track has manual mapping but isn't in cache, we need to rebuild + if (hasManualMapping && !isInCache) + { + hasNewManualMappings = true; + break; + } } - // Also check for external manual mappings - var externalMappingKey = $"spotify:external-map:{playlistName}:{track.SpotifyId}"; - var externalMapping = await _cache.GetAsync(externalMappingKey); - if (HasValue(externalMapping)) + if (!hasNewManualMappings) { - hasManualMappings = true; - break; + _logger.LogInformation("✓ Playlist {Playlist} already has {Count} matched tracks cached (skipping {ToMatch} new tracks), no re-matching needed", + playlistName, existingMatched.Count, tracksToMatch.Count); + return; } - } - - // Skip if cache exists AND no manual mappings need to be applied - if (existingMatched != null && existingMatched.Count >= tracksToMatch.Count && !hasManualMappings) - { - _logger.LogInformation("Playlist {Playlist} already has {Count} matched tracks cached, skipping", - playlistName, existingMatched.Count); - return; - } - - if (hasManualMappings) - { - _logger.LogInformation("Manual mappings detected for {Playlist}, rebuilding cache to apply them", playlistName); + + _logger.LogInformation("New manual mappings detected for {Playlist}, rebuilding cache to apply them", playlistName); } var matchedTracks = new List(); @@ -461,6 +474,9 @@ public class SpotifyTrackMatchingService : BackgroundService // Cache matched tracks with position data await _cache.SetAsync(matchedTracksKey, matchedTracks, TimeSpan.FromHours(1)); + // Save matched tracks to file for persistence across restarts + await SaveMatchedTracksToFileAsync(playlistName, matchedTracks); + // Also update legacy cache for backward compatibility var legacyKey = $"spotify:matched:{playlistName}"; var legacySongs = matchedTracks.OrderBy(t => t.Position).Select(t => t.MatchedSong).ToList(); @@ -979,5 +995,29 @@ public class SpotifyTrackMatchingService : BackgroundService _logger.LogError(ex, "Failed to save playlist items to file for {Playlist}", playlistName); } } + + /// + /// Saves matched tracks to file cache for persistence across restarts. + /// + private async Task SaveMatchedTracksToFileAsync(string playlistName, List matchedTracks) + { + try + { + var cacheDir = "/app/cache/spotify"; + Directory.CreateDirectory(cacheDir); + + var safeName = string.Join("_", playlistName.Split(Path.GetInvalidFileNameChars())); + var filePath = Path.Combine(cacheDir, $"{safeName}_matched.json"); + + var json = JsonSerializer.Serialize(matchedTracks, new JsonSerializerOptions { WriteIndented = true }); + await System.IO.File.WriteAllTextAsync(filePath, json); + + _logger.LogDebug("💾 Saved {Count} matched tracks to file cache: {Path}", matchedTracks.Count, filePath); + } + catch (Exception ex) + { + _logger.LogError(ex, "Failed to save matched tracks to file for {Playlist}", playlistName); + } + } } diff --git a/allstarr/appsettings.Development.json b/allstarr/appsettings.Development.json index 511dd3e..24b1216 100644 --- a/allstarr/appsettings.Development.json +++ b/allstarr/appsettings.Development.json @@ -2,14 +2,16 @@ "Logging": { "LogLevel": { "Default": "Information", - "Microsoft.AspNetCore": "Warning" + "Microsoft.AspNetCore": "Warning", + "System.Net.Http.HttpClient.Default.LogicalHandler": "Warning", + "System.Net.Http.HttpClient.Default.ClientHandler": "Warning" } }, - "SpotifyImport": { - "Enabled": false, - "SyncStartHour": 16, - "SyncStartMinute": 15, - "SyncWindowHours": 2, - "Playlists": [] - } + "SpotifyImport": { + "Enabled": false, + "SyncStartHour": 16, + "SyncStartMinute": 15, + "SyncWindowHours": 2, + "Playlists": [] + } } diff --git a/allstarr/appsettings.json b/allstarr/appsettings.json index 533f2ff..f5e6fa6 100644 --- a/allstarr/appsettings.json +++ b/allstarr/appsettings.json @@ -1,4 +1,12 @@ { + "Logging": { + "LogLevel": { + "Default": "Information", + "Microsoft.AspNetCore": "Warning", + "System.Net.Http.HttpClient.Default.LogicalHandler": "Warning", + "System.Net.Http.HttpClient.Default.ClientHandler": "Warning" + } + }, "Backend": { "Type": "Subsonic" },