Files
allstarr/allstarr/Services/Spotify/SpotifyMissingTracksFetcher.cs
Josh Patra eb46692b25 Extend backward search window to 24 hours for Spotify missing tracks
- Search forward 12 hours from sync time
- Search backward 24 hours from sync time (was 12 hours)
- Ensures yesterday's file is always found when running at 11 AM after 4 PM sync
- Sync runs daily at 4:15 PM, so 24h backward always catches previous day's file
2026-02-01 11:33:42 -05:00

473 lines
18 KiB
C#

using allstarr.Models.Settings;
using allstarr.Models.Spotify;
using allstarr.Services.Common;
using allstarr.Services.Jellyfin;
using Microsoft.Extensions.Options;
using System.Text.Json;
namespace allstarr.Services.Spotify;
public class SpotifyMissingTracksFetcher : BackgroundService
{
private readonly IOptions<SpotifyImportSettings> _spotifySettings;
private readonly IOptions<JellyfinSettings> _jellyfinSettings;
private readonly IHttpClientFactory _httpClientFactory;
private readonly RedisCacheService _cache;
private readonly ILogger<SpotifyMissingTracksFetcher> _logger;
private readonly IServiceProvider _serviceProvider;
private bool _hasRunOnce = false;
private Dictionary<string, string> _playlistIdToName = new();
private const string CacheDirectory = "/app/cache/spotify";
public SpotifyMissingTracksFetcher(
IOptions<SpotifyImportSettings> spotifySettings,
IOptions<JellyfinSettings> jellyfinSettings,
IHttpClientFactory httpClientFactory,
RedisCacheService cache,
IServiceProvider serviceProvider,
ILogger<SpotifyMissingTracksFetcher> logger)
{
_spotifySettings = spotifySettings;
_jellyfinSettings = jellyfinSettings;
_httpClientFactory = httpClientFactory;
_cache = cache;
_serviceProvider = serviceProvider;
_logger = logger;
}
protected override async Task ExecuteAsync(CancellationToken stoppingToken)
{
_logger.LogInformation("========================================");
_logger.LogInformation("SpotifyMissingTracksFetcher: Starting up...");
// Ensure cache directory exists
Directory.CreateDirectory(CacheDirectory);
if (!_spotifySettings.Value.Enabled)
{
_logger.LogInformation("Spotify playlist injection is DISABLED");
_logger.LogInformation("========================================");
return;
}
var jellyfinUrl = _jellyfinSettings.Value.Url;
var apiKey = _jellyfinSettings.Value.ApiKey;
if (string.IsNullOrEmpty(jellyfinUrl) || string.IsNullOrEmpty(apiKey))
{
_logger.LogWarning("Jellyfin URL or API key not configured, Spotify playlist injection disabled");
_logger.LogInformation("========================================");
return;
}
_logger.LogInformation("Spotify Import ENABLED");
_logger.LogInformation("Configured Playlist IDs: {Count}", _spotifySettings.Value.PlaylistIds.Count);
// Fetch playlist names from Jellyfin
await LoadPlaylistNamesAsync();
foreach (var kvp in _playlistIdToName)
{
_logger.LogInformation(" - {Name} (ID: {Id})", kvp.Value, kvp.Key);
}
_logger.LogInformation("========================================");
// Run once on startup if we haven't run in the last 24 hours
if (!_hasRunOnce)
{
var shouldRunOnStartup = await ShouldRunOnStartupAsync();
if (shouldRunOnStartup)
{
_logger.LogInformation("Running initial fetch on startup (bypassing sync window check)");
try
{
await FetchMissingTracksAsync(stoppingToken, bypassSyncWindowCheck: true);
_hasRunOnce = true;
}
catch (Exception ex)
{
_logger.LogError(ex, "Error during startup fetch");
}
}
else
{
_logger.LogInformation("Skipping startup fetch - already have recent cache");
_hasRunOnce = true;
}
}
while (!stoppingToken.IsCancellationRequested)
{
try
{
await FetchMissingTracksAsync(stoppingToken);
}
catch (Exception ex)
{
_logger.LogError(ex, "Error fetching Spotify missing tracks");
}
await Task.Delay(TimeSpan.FromMinutes(5), stoppingToken);
}
}
private async Task LoadPlaylistNamesAsync()
{
_playlistIdToName.Clear();
// Use configured playlist names instead of fetching from API
for (int i = 0; i < _spotifySettings.Value.PlaylistIds.Count; i++)
{
var playlistId = _spotifySettings.Value.PlaylistIds[i];
var playlistName = i < _spotifySettings.Value.PlaylistNames.Count
? _spotifySettings.Value.PlaylistNames[i]
: playlistId; // Fallback to ID if name not configured
_playlistIdToName[playlistId] = playlistName;
}
}
private async Task<bool> ShouldRunOnStartupAsync()
{
_logger.LogInformation("=== STARTUP CACHE CHECK ===");
_logger.LogInformation("Cache directory: {Dir}", CacheDirectory);
_logger.LogInformation("Checking {Count} playlists", _playlistIdToName.Count);
// List all files in cache directory for debugging
try
{
if (Directory.Exists(CacheDirectory))
{
var files = Directory.GetFiles(CacheDirectory, "*.json");
_logger.LogInformation("Found {Count} JSON files in cache directory:", files.Length);
foreach (var file in files)
{
var fileInfo = new FileInfo(file);
var age = DateTime.UtcNow - fileInfo.LastWriteTimeUtc;
_logger.LogInformation(" - {Name} (age: {Age:F1}h, size: {Size} bytes)",
Path.GetFileName(file), age.TotalHours, fileInfo.Length);
}
}
else
{
_logger.LogWarning("Cache directory does not exist: {Dir}", CacheDirectory);
}
}
catch (Exception ex)
{
_logger.LogError(ex, "Error listing cache directory");
}
// Check file cache first, then Redis
foreach (var playlistName in _playlistIdToName.Values)
{
var filePath = GetCacheFilePath(playlistName);
_logger.LogInformation("Checking playlist: {Playlist}", playlistName);
_logger.LogInformation(" Expected file path: {Path}", filePath);
if (File.Exists(filePath))
{
var fileAge = DateTime.UtcNow - File.GetLastWriteTimeUtc(filePath);
_logger.LogInformation(" File exists! Age: {Age:F1}h", fileAge.TotalHours);
if (fileAge < TimeSpan.FromHours(24))
{
_logger.LogInformation(" ✓ Found recent file cache (age: {Age:F1}h)", fileAge.TotalHours);
// Load from file into Redis if not already there
var key = $"spotify:missing:{playlistName}";
if (!await _cache.ExistsAsync(key))
{
_logger.LogInformation(" Loading into Redis...");
await LoadFromFileCache(playlistName);
}
else
{
_logger.LogInformation(" Already in Redis");
}
return false;
}
else
{
_logger.LogInformation(" File too old ({Age:F1}h > 24h), will fetch new", fileAge.TotalHours);
}
}
else
{
_logger.LogInformation(" File does not exist at expected path");
}
var cacheKey = $"spotify:missing:{playlistName}";
if (await _cache.ExistsAsync(cacheKey))
{
_logger.LogInformation(" ✓ Found in Redis cache");
return false;
}
else
{
_logger.LogInformation(" Not in Redis cache");
}
}
_logger.LogInformation("=== NO RECENT CACHE FOUND - WILL FETCH ===");
return true;
}
private string GetCacheFilePath(string playlistName)
{
var safeName = string.Join("_", playlistName.Split(Path.GetInvalidFileNameChars()));
return Path.Combine(CacheDirectory, $"{safeName}_missing.json");
}
private async Task LoadFromFileCache(string playlistName)
{
try
{
var filePath = GetCacheFilePath(playlistName);
if (!File.Exists(filePath))
return;
var json = await File.ReadAllTextAsync(filePath);
var tracks = JsonSerializer.Deserialize<List<MissingTrack>>(json);
if (tracks != null && tracks.Count > 0)
{
var cacheKey = $"spotify:missing:{playlistName}";
var fileAge = DateTime.UtcNow - File.GetLastWriteTimeUtc(filePath);
var ttl = TimeSpan.FromHours(24) - fileAge;
if (ttl > TimeSpan.Zero)
{
await _cache.SetAsync(cacheKey, tracks, ttl);
_logger.LogInformation("Loaded {Count} tracks from file cache for {Playlist}",
tracks.Count, playlistName);
}
}
}
catch (Exception ex)
{
_logger.LogWarning(ex, "Failed to load file cache for {Playlist}", playlistName);
}
}
private async Task SaveToFileCache(string playlistName, List<MissingTrack> tracks)
{
try
{
var filePath = GetCacheFilePath(playlistName);
var json = JsonSerializer.Serialize(tracks, new JsonSerializerOptions { WriteIndented = true });
await File.WriteAllTextAsync(filePath, json);
_logger.LogInformation("Saved {Count} tracks to file cache for {Playlist}",
tracks.Count, playlistName);
}
catch (Exception ex)
{
_logger.LogError(ex, "Failed to save file cache for {Playlist}", playlistName);
}
}
private async Task FetchMissingTracksAsync(CancellationToken cancellationToken, bool bypassSyncWindowCheck = false)
{
var settings = _spotifySettings.Value;
var now = DateTime.UtcNow;
var syncStart = now.Date
.AddHours(settings.SyncStartHour)
.AddMinutes(settings.SyncStartMinute);
var syncEnd = syncStart.AddHours(settings.SyncWindowHours);
// Only run after the sync window has passed (unless bypassing for startup)
if (!bypassSyncWindowCheck && now < syncEnd)
{
_logger.LogInformation("Skipping fetch - sync window not passed yet (now: {Now}, window ends: {End})",
now, syncEnd);
return;
}
if (bypassSyncWindowCheck)
{
_logger.LogInformation("=== FETCHING MISSING TRACKS (STARTUP MODE) ===");
}
else
{
_logger.LogInformation("=== FETCHING MISSING TRACKS (SYNC WINDOW PASSED) ===");
}
_logger.LogInformation("Processing {Count} playlists", _playlistIdToName.Count);
foreach (var kvp in _playlistIdToName)
{
_logger.LogInformation("Fetching playlist: {Name}", kvp.Value);
await FetchPlaylistMissingTracksAsync(kvp.Value, cancellationToken);
}
_logger.LogInformation("=== FINISHED FETCHING MISSING TRACKS ===");
}
private async Task FetchPlaylistMissingTracksAsync(
string playlistName,
CancellationToken cancellationToken)
{
var cacheKey = $"spotify:missing:{playlistName}";
if (await _cache.ExistsAsync(cacheKey))
{
_logger.LogInformation(" ✓ Cache already exists for {Playlist}, skipping fetch", playlistName);
return;
}
_logger.LogInformation(" No cache found, will search for missing tracks file...");
var settings = _spotifySettings.Value;
var jellyfinUrl = _jellyfinSettings.Value.Url;
var apiKey = _jellyfinSettings.Value.ApiKey;
if (string.IsNullOrEmpty(jellyfinUrl) || string.IsNullOrEmpty(apiKey))
{
_logger.LogWarning(" Jellyfin URL or API key not configured, skipping fetch");
return;
}
var httpClient = _httpClientFactory.CreateClient();
// Start from the configured sync time (most likely time)
var now = DateTime.UtcNow;
var todaySync = now.Date
.AddHours(settings.SyncStartHour)
.AddMinutes(settings.SyncStartMinute);
// If we haven't reached today's sync time yet, start from yesterday's sync time
var syncTime = now >= todaySync ? todaySync : todaySync.AddDays(-1);
_logger.LogInformation(" Searching +12h forward, -24h backward from {SyncTime}", syncTime);
var found = false;
// Search forward 12 hours from sync time
_logger.LogInformation(" Phase 1: Searching forward 12 hours from sync time...");
for (var minutesAhead = 0; minutesAhead <= 720; minutesAhead++) // 720 minutes = 12 hours
{
if (cancellationToken.IsCancellationRequested) break;
var time = syncTime.AddMinutes(minutesAhead);
if (await TryFetchMissingTracksFile(playlistName, time, jellyfinUrl, apiKey, httpClient, cancellationToken))
{
found = true;
break;
}
// Small delay every 60 requests
if (minutesAhead > 0 && minutesAhead % 60 == 0)
{
await Task.Delay(TimeSpan.FromSeconds(1), cancellationToken);
}
}
// Then search backwards 24 hours from sync time to catch yesterday's file
if (!found)
{
_logger.LogInformation(" Phase 2: Searching backward 24 hours from sync time...");
for (var minutesBehind = 1; minutesBehind <= 1440; minutesBehind++) // 1440 minutes = 24 hours
{
if (cancellationToken.IsCancellationRequested) break;
var time = syncTime.AddMinutes(-minutesBehind);
if (await TryFetchMissingTracksFile(playlistName, time, jellyfinUrl, apiKey, httpClient, cancellationToken))
{
found = true;
break;
}
// Small delay every 60 requests
if (minutesBehind % 60 == 0)
{
await Task.Delay(TimeSpan.FromSeconds(1), cancellationToken);
}
}
}
if (!found)
{
_logger.LogWarning(" ✗ Could not find missing tracks file (searched +12h/-24h window)");
}
}
private async Task<bool> TryFetchMissingTracksFile(
string playlistName,
DateTime time,
string jellyfinUrl,
string apiKey,
HttpClient httpClient,
CancellationToken cancellationToken)
{
var filename = $"{playlistName}_missing_{time:yyyy-MM-dd_HH-mm}.json";
var url = $"{jellyfinUrl}/Viperinius.Plugin.SpotifyImport/MissingTracksFile" +
$"?name={Uri.EscapeDataString(filename)}&api_key={apiKey}";
try
{
_logger.LogDebug("Trying {Filename}", filename);
var response = await httpClient.GetAsync(url, cancellationToken);
if (response.IsSuccessStatusCode)
{
var json = await response.Content.ReadAsStringAsync(cancellationToken);
var tracks = ParseMissingTracks(json);
if (tracks.Count > 0)
{
var cacheKey = $"spotify:missing:{playlistName}";
// Save to both Redis and file
await _cache.SetAsync(cacheKey, tracks, TimeSpan.FromHours(24));
await SaveToFileCache(playlistName, tracks);
_logger.LogInformation(
"✓ Cached {Count} missing tracks for {Playlist} from {Filename}",
tracks.Count, playlistName, filename);
return true;
}
}
}
catch (Exception ex)
{
_logger.LogDebug(ex, "Failed to fetch {Filename}", filename);
}
return false;
}
private List<MissingTrack> ParseMissingTracks(string json)
{
var tracks = new List<MissingTrack>();
try
{
var doc = JsonDocument.Parse(json);
foreach (var item in doc.RootElement.EnumerateArray())
{
var track = new MissingTrack
{
SpotifyId = item.GetProperty("Id").GetString() ?? "",
Title = item.GetProperty("Name").GetString() ?? "",
Album = item.GetProperty("AlbumName").GetString() ?? "",
Artists = item.GetProperty("ArtistNames")
.EnumerateArray()
.Select(a => a.GetString() ?? "")
.Where(a => !string.IsNullOrEmpty(a))
.ToList()
};
if (!string.IsNullOrEmpty(track.Title))
{
tracks.Add(track);
}
}
}
catch (Exception ex)
{
_logger.LogError(ex, "Failed to parse missing tracks JSON");
}
return tracks;
}
}