diff --git a/allstarr/Services/Spotify/SpotifyMissingTracksFetcher.cs b/allstarr/Services/Spotify/SpotifyMissingTracksFetcher.cs index 7d886cd..5570599 100644 --- a/allstarr/Services/Spotify/SpotifyMissingTracksFetcher.cs +++ b/allstarr/Services/Spotify/SpotifyMissingTracksFetcher.cs @@ -302,16 +302,14 @@ public class SpotifyMissingTracksFetcher : BackgroundService { var cacheKey = $"spotify:missing:{playlistName}"; - // Check if we have existing cache and when it was last updated + // Check if we have existing cache var existingTracks = await _cache.GetAsync>(cacheKey); - var existingFileTime = DateTime.MinValue; var filePath = GetCacheFilePath(playlistName); if (File.Exists(filePath)) { - existingFileTime = File.GetLastWriteTimeUtc(filePath); - _logger.LogInformation(" Existing cache file from: {Time} ({Age:F1}h ago)", - existingFileTime, (DateTime.UtcNow - existingFileTime).TotalHours); + var fileAge = DateTime.UtcNow - File.GetLastWriteTimeUtc(filePath); + _logger.LogInformation(" Existing cache file age: {Age:F1}h", fileAge.TotalHours); } if (existingTracks != null && existingTracks.Count > 0) @@ -338,26 +336,28 @@ public class SpotifyMissingTracksFetcher : BackgroundService // Search forward first (newest files), then backwards to handle timezone differences // We want the file with the furthest forward timestamp (most recent) var now = DateTime.UtcNow; - _logger.LogInformation(" Searching +24h forward, then -48h backward from {Now}", now); + _logger.LogInformation(" Current UTC time: {Now:yyyy-MM-dd HH:mm}", now); + _logger.LogInformation(" Searching +24h forward, then -48h backward"); var found = false; DateTime? foundFileTime = null; // First search forward 24 hours (most likely to find newest files with timezone ahead) - _logger.LogInformation(" Phase 1: Searching forward 24 hours..."); + _logger.LogInformation(" Phase 1: Searching forward 24 hours (from {Start:HH:mm} to {End:HH:mm} UTC)...", + now.AddMinutes(1), now.AddMinutes(1440)); for (var minutesAhead = 1; minutesAhead <= 1440; minutesAhead++) { if (cancellationToken.IsCancellationRequested) break; var time = now.AddMinutes(minutesAhead); - var result = await TryFetchMissingTracksFile(playlistName, time, jellyfinUrl, apiKey, httpClient, cancellationToken, existingFileTime); + var result = await TryFetchMissingTracksFile(playlistName, time, jellyfinUrl, apiKey, httpClient, cancellationToken); if (result.found) { found = true; foundFileTime = result.fileTime; if (foundFileTime.HasValue) { - _logger.LogInformation(" ✓ Found file from {Time} (+{Offset:F1}h ahead)", + _logger.LogInformation(" ✓ Found file from {Time:yyyy-MM-dd HH:mm} UTC (+{Offset:F1}h ahead)", foundFileTime.Value, (foundFileTime.Value - now).TotalHours); } break; // Found newest file, stop searching @@ -373,20 +373,21 @@ public class SpotifyMissingTracksFetcher : BackgroundService // If not found forward, search backwards 48 hours if (!found) { - _logger.LogInformation(" Phase 2: Searching backward 48 hours..."); + _logger.LogInformation(" Phase 2: Searching backward 48 hours (from {Start:HH:mm} to {End:HH:mm} UTC)...", + now, now.AddMinutes(-2880)); for (var minutesBehind = 0; minutesBehind <= 2880; minutesBehind++) { if (cancellationToken.IsCancellationRequested) break; var time = now.AddMinutes(-minutesBehind); - var result = await TryFetchMissingTracksFile(playlistName, time, jellyfinUrl, apiKey, httpClient, cancellationToken, existingFileTime); + var result = await TryFetchMissingTracksFile(playlistName, time, jellyfinUrl, apiKey, httpClient, cancellationToken); if (result.found) { found = true; foundFileTime = result.fileTime; if (foundFileTime.HasValue) { - _logger.LogInformation(" ✓ Found file from {Time} (-{Offset:F1}h ago)", + _logger.LogInformation(" ✓ Found file from {Time:yyyy-MM-dd HH:mm} UTC (-{Offset:F1}h ago)", foundFileTime.Value, (now - foundFileTime.Value).TotalHours); } break; @@ -448,8 +449,7 @@ public class SpotifyMissingTracksFetcher : BackgroundService string jellyfinUrl, string apiKey, HttpClient httpClient, - CancellationToken cancellationToken, - DateTime existingFileTime) + CancellationToken cancellationToken) { var filename = $"{playlistName}_missing_{time:yyyy-MM-dd_HH-mm}.json"; var url = $"{jellyfinUrl}/Viperinius.Plugin.SpotifyImport/MissingTracksFile" + @@ -457,7 +457,14 @@ public class SpotifyMissingTracksFetcher : BackgroundService try { - _logger.LogDebug("Trying {Filename}", filename); + // Log first and last attempts in each phase + var minuteDiff = (time - DateTime.UtcNow).TotalMinutes; + if (Math.Abs(minuteDiff - 1) < 0.1 || Math.Abs(minuteDiff - 1440) < 0.1 || + Math.Abs(minuteDiff) < 0.1 || Math.Abs(minuteDiff + 2880) < 0.1) + { + _logger.LogDebug(" Trying: {Filename} ({Time:yyyy-MM-dd HH:mm} UTC)", filename, time); + } + var response = await httpClient.GetAsync(url, cancellationToken); if (response.IsSuccessStatusCode) { @@ -466,13 +473,6 @@ public class SpotifyMissingTracksFetcher : BackgroundService if (tracks.Count > 0) { - // Check if this file is newer than what we already have - if (time <= existingFileTime) - { - _logger.LogDebug(" Skipping {Filename} - not newer than existing cache", filename); - return (false, null); - } - var cacheKey = $"spotify:missing:{playlistName}"; // Save to both Redis and file with extended TTL until next job runs