mirror of
https://github.com/SoPat712/allstarr.git
synced 2026-02-09 23:55:10 -05:00
Fix excessive track matching and reduce HTTP logging noise
- Added 5-minute cooldown between matching runs to prevent spam - Improved cache checking to skip unnecessary matching - Persist matched tracks cache to file for faster restarts - Cache warming service now loads matched tracks on startup - Suppress verbose HTTP client logs (LogicalHandler/ClientHandler) - Only run matching when cache is missing or manual mappings added
This commit is contained in:
@@ -97,6 +97,10 @@ builder.Services.ConfigureAll<HttpClientFactoryOptions>(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();
|
||||
|
||||
@@ -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<List<MatchedTrack>>(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; }
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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<SpotifyImportSettings> 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<List<MatchedTrack>>(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<string>(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<string>(manualMappingKey);
|
||||
|
||||
var externalMappingKey = $"spotify:external-map:{playlistName}:{track.SpotifyId}";
|
||||
var externalMapping = await _cache.GetAsync<dynamic>(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<dynamic>(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<MatchedTrack>();
|
||||
@@ -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);
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Saves matched tracks to file cache for persistence across restarts.
|
||||
/// </summary>
|
||||
private async Task SaveMatchedTracksToFileAsync(string playlistName, List<MatchedTrack> 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);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -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": []
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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"
|
||||
},
|
||||
|
||||
Reference in New Issue
Block a user