fix(admin): avoid startup hangs and log external match timeouts

This commit is contained in:
joshpatra committed 2026-04-07 16:38:33 -04:00
1 parent c3f6e8e3b7
commit b1ad871632
3 files changed
+279 -145

No files matched your search

+5 -1
View File
@@ -965,7 +965,11 @@ if (app.Environment.IsDevelopment())
app.UseSwaggerUI(); app.UseSwaggerUI();
} }
app.UseHttpsRedirection(); // The admin UI is documented and intended to be reachable directly over HTTP on port 5275.
// Keep HTTPS redirection for non-admin traffic only.
app.UseWhen(
context => context.Connection.LocalPort != 5275,
branch => branch.UseHttpsRedirection());
// Serve static files only on admin port (5275) // Serve static files only on admin port (5275)
app.UseMiddleware<allstarr.Middleware.AdminNetworkAllowlistMiddleware>(); app.UseMiddleware<allstarr.Middleware.AdminNetworkAllowlistMiddleware>();
@@ -14,6 +14,8 @@ public class VersionUpgradeRebuildService : IHostedService
private readonly SpotifyTrackMatchingService _matchingService; private readonly SpotifyTrackMatchingService _matchingService;
private readonly SpotifyImportSettings _spotifyImportSettings; private readonly SpotifyImportSettings _spotifyImportSettings;
private readonly ILogger<VersionUpgradeRebuildService> _logger; private readonly ILogger<VersionUpgradeRebuildService> _logger;
private CancellationTokenSource? _backgroundRebuildCts;
private Task? _backgroundRebuildTask;
public VersionUpgradeRebuildService( public VersionUpgradeRebuildService(
SpotifyTrackMatchingService matchingService, SpotifyTrackMatchingService matchingService,
@@ -53,15 +55,12 @@ public class VersionUpgradeRebuildService : IHostedService
} }
else else
{ {
_logger.LogInformation("Triggering full rebuild for all playlists after version upgrade"); _logger.LogInformation(
try "Scheduling full rebuild for all playlists in background after version upgrade");
{
await _matchingService.TriggerRebuildAllAsync(); _backgroundRebuildCts = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken);
} _backgroundRebuildTask = RunBackgroundRebuildAsync(currentVersion, _backgroundRebuildCts.Token);
catch (Exception ex) return;
{
_logger.LogError(ex, "Failed to trigger auto rebuild after version upgrade");
}
} }
} }
else else
@@ -76,7 +75,51 @@ public class VersionUpgradeRebuildService : IHostedService
public Task StopAsync(CancellationToken cancellationToken) public Task StopAsync(CancellationToken cancellationToken)
{ {
return Task.CompletedTask; return StopBackgroundRebuildAsync(cancellationToken);
}
private async Task RunBackgroundRebuildAsync(string currentVersion, CancellationToken cancellationToken)
{
try
{
_logger.LogInformation("Starting background full rebuild for all playlists after version upgrade");
await _matchingService.TriggerRebuildAllAsync(cancellationToken);
_logger.LogInformation("Background full rebuild after version upgrade completed");
await WriteCurrentVersionAsync(currentVersion, cancellationToken);
}
catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested)
{
_logger.LogWarning("Background full rebuild after version upgrade was cancelled before completion");
}
catch (Exception ex)
{
_logger.LogError(ex, "Failed to trigger auto rebuild after version upgrade");
await WriteCurrentVersionAsync(currentVersion, CancellationToken.None);
}
}
private async Task StopBackgroundRebuildAsync(CancellationToken cancellationToken)
{
if (_backgroundRebuildTask == null)
{
return;
}
try
{
_backgroundRebuildCts?.Cancel();
await _backgroundRebuildTask.WaitAsync(cancellationToken);
}
catch (OperationCanceledException)
{
// Host shutdown is in progress or the background task observed cancellation.
}
finally
{
_backgroundRebuildCts?.Dispose();
_backgroundRebuildCts = null;
_backgroundRebuildTask = null;
}
} }
private async Task<string?> ReadPreviousVersionAsync(CancellationToken cancellationToken) private async Task<string?> ReadPreviousVersionAsync(CancellationToken cancellationToken)
@@ -38,6 +38,7 @@ public class SpotifyTrackMatchingService : BackgroundService
private readonly IServiceProvider _serviceProvider; private readonly IServiceProvider _serviceProvider;
private const int DelayBetweenSearchesMs = 150; // 150ms = ~6.6 searches/second to avoid rate limiting 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 const int BatchSize = 11; // Number of parallel searches (matches SquidWTF provider count)
private static readonly TimeSpan ExternalProviderSearchTimeout = TimeSpan.FromSeconds(30);
// Track last run time per playlist to prevent duplicate runs // Track last run time per playlist to prevent duplicate runs
private readonly Dictionary<string, DateTime> _lastRunTimes = new(); private readonly Dictionary<string, DateTime> _lastRunTimes = new();
@@ -365,10 +366,10 @@ public class SpotifyTrackMatchingService : BackgroundService
/// Public method to trigger full rebuild for all playlists (called from "Rebuild All Remote" button). /// Public method to trigger full rebuild for all playlists (called from "Rebuild All Remote" button).
/// This clears caches, fetches fresh data, and re-matches everything immediately. /// This clears caches, fetches fresh data, and re-matches everything immediately.
/// </summary> /// </summary>
public async Task TriggerRebuildAllAsync() public async Task TriggerRebuildAllAsync(CancellationToken cancellationToken = default)
{ {
_logger.LogInformation("Manual full rebuild triggered for all playlists"); _logger.LogInformation("Full rebuild triggered for all playlists");
await RebuildAllPlaylistsAsync(CancellationToken.None); await RebuildAllPlaylistsAsync(cancellationToken);
} }
/// <summary> /// <summary>
@@ -773,11 +774,28 @@ public class SpotifyTrackMatchingService : BackgroundService
if (cancellationToken.IsCancellationRequested) break; if (cancellationToken.IsCancellationRequested) break;
var batch = unmatchedSpotifyTracks.Skip(i).Take(BatchSize).ToList(); var batch = unmatchedSpotifyTracks.Skip(i).Take(BatchSize).ToList();
var batchStart = i + 1;
var batchEnd = i + batch.Count;
var batchStopwatch = System.Diagnostics.Stopwatch.StartNew();
_logger.LogInformation(
"Starting external matching batch for {Playlist}: tracks {Start}-{End}/{Total}",
playlistName,
batchStart,
batchEnd,
unmatchedSpotifyTracks.Count);
var batchTasks = batch.Select(async spotifyTrack => var batchTasks = batch.Select(async spotifyTrack =>
{ {
var primaryArtist = spotifyTrack.PrimaryArtist;
var trackStopwatch = System.Diagnostics.Stopwatch.StartNew();
try try
{ {
using var timeoutCts = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken);
timeoutCts.CancelAfter(ExternalProviderSearchTimeout);
var trackCancellationToken = timeoutCts.Token;
var candidates = new List<(Song Song, double Score, string MatchType)>(); var candidates = new List<(Song Song, double Score, string MatchType)>();
// Check global external mapping first // Check global external mapping first
@@ -789,12 +807,23 @@ public class SpotifyTrackMatchingService : BackgroundService
if (!string.IsNullOrEmpty(globalMapping.ExternalProvider) && if (!string.IsNullOrEmpty(globalMapping.ExternalProvider) &&
!string.IsNullOrEmpty(globalMapping.ExternalId)) !string.IsNullOrEmpty(globalMapping.ExternalId))
{ {
mappedSong = await metadataService.GetSongAsync(globalMapping.ExternalProvider, globalMapping.ExternalId); mappedSong = await metadataService.GetSongAsync(
globalMapping.ExternalProvider,
globalMapping.ExternalId,
trackCancellationToken);
} }
if (mappedSong != null) if (mappedSong != null)
{ {
candidates.Add((mappedSong, 100.0, "global-mapping-external")); candidates.Add((mappedSong, 100.0, "global-mapping-external"));
trackStopwatch.Stop();
_logger.LogDebug(
"External candidate search finished for {Playlist} track #{Position}: {Title} by {Artist} in {ElapsedMs}ms using global mapping",
playlistName,
spotifyTrack.Position,
spotifyTrack.Title,
primaryArtist,
trackStopwatch.ElapsedMilliseconds);
return (spotifyTrack, candidates); return (spotifyTrack, candidates);
} }
} }
@@ -802,10 +831,31 @@ public class SpotifyTrackMatchingService : BackgroundService
// Try ISRC match // Try ISRC match
if (_spotifyApiSettings.PreferIsrcMatching && !string.IsNullOrEmpty(spotifyTrack.Isrc)) if (_spotifyApiSettings.PreferIsrcMatching && !string.IsNullOrEmpty(spotifyTrack.Isrc))
{ {
var isrcSong = await TryMatchByIsrcAsync(spotifyTrack.Isrc, metadataService); try
if (isrcSong != null)
{ {
candidates.Add((isrcSong, 100.0, "isrc")); var isrcSong = await TryMatchByIsrcAsync(
spotifyTrack.Isrc,
metadataService,
trackCancellationToken);
if (isrcSong != null)
{
candidates.Add((isrcSong, 100.0, "isrc"));
}
}
catch (OperationCanceledException) when (!cancellationToken.IsCancellationRequested)
{
throw;
}
catch (Exception ex)
{
_logger.LogWarning(
ex,
"ISRC lookup failed for {Playlist} track #{Position}: {Title} by {Artist}",
playlistName,
spotifyTrack.Position,
spotifyTrack.Title,
primaryArtist);
} }
} }
@@ -813,7 +863,8 @@ public class SpotifyTrackMatchingService : BackgroundService
var fuzzySongs = await TryMatchByFuzzyMultipleAsync( var fuzzySongs = await TryMatchByFuzzyMultipleAsync(
spotifyTrack.Title, spotifyTrack.Title,
spotifyTrack.Artists, spotifyTrack.Artists,
metadataService); metadataService,
trackCancellationToken);
foreach (var (song, score) in fuzzySongs) foreach (var (song, score) in fuzzySongs)
{ {
@@ -823,16 +874,48 @@ public class SpotifyTrackMatchingService : BackgroundService
} }
} }
trackStopwatch.Stop();
_logger.LogDebug(
"External candidate search finished for {Playlist} track #{Position}: {Title} by {Artist} in {ElapsedMs}ms with {CandidateCount} candidates",
playlistName,
spotifyTrack.Position,
spotifyTrack.Title,
primaryArtist,
trackStopwatch.ElapsedMilliseconds,
candidates.Count);
return (spotifyTrack, candidates); return (spotifyTrack, candidates);
} }
catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested)
{
return (spotifyTrack, new List<(Song, double, string)>());
}
catch (OperationCanceledException)
{
_logger.LogWarning(
"External candidate search timed out for {Playlist} track #{Position}: {Title} by {Artist} after {TimeoutSeconds}s",
playlistName,
spotifyTrack.Position,
spotifyTrack.Title,
primaryArtist,
ExternalProviderSearchTimeout.TotalSeconds);
return (spotifyTrack, new List<(Song, double, string)>());
}
catch (Exception ex) catch (Exception ex)
{ {
_logger.LogError(ex, "Failed to match track: {Title}", spotifyTrack.Title); _logger.LogError(
ex,
"Failed to match track for {Playlist} track #{Position}: {Title} by {Artist}",
playlistName,
spotifyTrack.Position,
spotifyTrack.Title,
primaryArtist);
return (spotifyTrack, new List<(Song, double, string)>()); return (spotifyTrack, new List<(Song, double, string)>());
} }
}).ToList(); }).ToList();
var batchResults = await Task.WhenAll(batchTasks); var batchResults = await Task.WhenAll(batchTasks);
batchStopwatch.Stop();
foreach (var result in batchResults) foreach (var result in batchResults)
{ {
@@ -842,6 +925,16 @@ public class SpotifyTrackMatchingService : BackgroundService
} }
} }
var batchCandidateCount = batchResults.Sum(result => result.Item2.Count);
_logger.LogInformation(
"Finished external matching batch for {Playlist}: tracks {Start}-{End}/{Total} in {ElapsedMs}ms ({CandidateCount} candidates)",
playlistName,
batchStart,
batchEnd,
unmatchedSpotifyTracks.Count,
batchStopwatch.ElapsedMilliseconds,
batchCandidateCount);
if (i + BatchSize < unmatchedSpotifyTracks.Count) if (i + BatchSize < unmatchedSpotifyTracks.Count)
{ {
await Task.Delay(DelayBetweenSearchesMs, cancellationToken); await Task.Delay(DelayBetweenSearchesMs, cancellationToken);
@@ -1014,140 +1107,136 @@ public class SpotifyTrackMatchingService : BackgroundService
private async Task<List<(Song Song, double Score)>> TryMatchByFuzzyMultipleAsync( private async Task<List<(Song Song, double Score)>> TryMatchByFuzzyMultipleAsync(
string title, string title,
List<string> artists, List<string> artists,
IMusicMetadataService metadataService) IMusicMetadataService metadataService,
CancellationToken cancellationToken)
{ {
try var primaryArtist = artists.FirstOrDefault() ?? "";
var titleStripped = FuzzyMatcher.StripDecorators(title);
var query = $"{titleStripped} {primaryArtist}";
var allCandidates = new List<(Song Song, double Score)>();
// STEP 1: Search LOCAL Jellyfin library FIRST
using var scope = _serviceProvider.CreateScope();
var proxyService = scope.ServiceProvider.GetService<JellyfinProxyService>();
if (proxyService != null)
{ {
var primaryArtist = artists.FirstOrDefault() ?? ""; try
var titleStripped = FuzzyMatcher.StripDecorators(title);
var query = $"{titleStripped} {primaryArtist}";
var allCandidates = new List<(Song Song, double Score)>();
// STEP 1: Search LOCAL Jellyfin library FIRST
using var scope = _serviceProvider.CreateScope();
var proxyService = scope.ServiceProvider.GetService<JellyfinProxyService>();
if (proxyService != null)
{ {
try // Search Jellyfin for local tracks
var searchParams = new Dictionary<string, string>
{ {
// Search Jellyfin for local tracks ["searchTerm"] = query,
var searchParams = new Dictionary<string, string> ["includeItemTypes"] = "Audio",
{ ["recursive"] = "true",
["searchTerm"] = query, ["limit"] = "10"
["includeItemTypes"] = "Audio", };
["recursive"] = "true",
["limit"] = "10"
};
var (searchResponse, _) = await proxyService.GetJsonAsyncInternal("Items", searchParams); var (searchResponse, _) = await proxyService.GetJsonAsyncInternal("Items", searchParams);
if (searchResponse != null && searchResponse.RootElement.TryGetProperty("Items", out var items)) if (searchResponse != null && searchResponse.RootElement.TryGetProperty("Items", out var items))
{
var localResults = new List<Song>();
foreach (var item in items.EnumerateArray())
{ {
var localResults = new List<Song>(); var id = item.TryGetProperty("Id", out var idEl) ? idEl.GetString() ?? "" : "";
foreach (var item in items.EnumerateArray()) var songTitle = item.TryGetProperty("Name", out var nameEl) ? nameEl.GetString() ?? "" : "";
var artist = "";
if (item.TryGetProperty("Artists", out var artistsEl) && artistsEl.GetArrayLength() > 0)
{ {
var id = item.TryGetProperty("Id", out var idEl) ? idEl.GetString() ?? "" : ""; artist = artistsEl[0].GetString() ?? "";
var songTitle = item.TryGetProperty("Name", out var nameEl) ? nameEl.GetString() ?? "" : ""; }
var artist = ""; else if (item.TryGetProperty("AlbumArtist", out var albumArtistEl))
{
if (item.TryGetProperty("Artists", out var artistsEl) && artistsEl.GetArrayLength() > 0) artist = albumArtistEl.GetString() ?? "";
{
artist = artistsEl[0].GetString() ?? "";
}
else if (item.TryGetProperty("AlbumArtist", out var albumArtistEl))
{
artist = albumArtistEl.GetString() ?? "";
}
localResults.Add(new Song
{
Id = id,
Title = songTitle,
Artist = artist,
IsLocal = true
});
} }
if (localResults.Count > 0) localResults.Add(new Song
{ {
// Score local results Id = id,
var scoredLocal = localResults Title = songTitle,
.Select(song => new Artist = artist,
{ IsLocal = true
Song = song, });
TitleScore = FuzzyMatcher.CalculateSimilarityAggressive(title, song.Title), }
ArtistScore = FuzzyMatcher.CalculateArtistMatchScore(artists, song.Artist, song.Contributors)
})
.Select(x => new
{
x.Song,
x.TitleScore,
x.ArtistScore,
TotalScore = (x.TitleScore * 0.7) + (x.ArtistScore * 0.3)
})
.Where(x =>
x.TotalScore >= 40 ||
(x.ArtistScore >= 70 && x.TitleScore >= 30) ||
x.TitleScore >= 85)
.OrderByDescending(x => x.TotalScore)
.Select(x => (x.Song, x.TotalScore))
.ToList();
allCandidates.AddRange(scoredLocal); if (localResults.Count > 0)
{
// If we found good local matches, return them (don't search external) // Score local results
if (scoredLocal.Any(x => x.TotalScore >= 70)) var scoredLocal = localResults
.Select(song => new
{ {
_logger.LogDebug("Found {Count} local matches for '{Title}', skipping external search", Song = song,
scoredLocal.Count, title); TitleScore = FuzzyMatcher.CalculateSimilarityAggressive(title, song.Title),
return allCandidates; ArtistScore = FuzzyMatcher.CalculateArtistMatchScore(artists, song.Artist, song.Contributors)
} })
.Select(x => new
{
x.Song,
x.TitleScore,
x.ArtistScore,
TotalScore = (x.TitleScore * 0.7) + (x.ArtistScore * 0.3)
})
.Where(x =>
x.TotalScore >= 40 ||
(x.ArtistScore >= 70 && x.TitleScore >= 30) ||
x.TitleScore >= 85)
.OrderByDescending(x => x.TotalScore)
.Select(x => (x.Song, x.TotalScore))
.ToList();
allCandidates.AddRange(scoredLocal);
// If we found good local matches, return them (don't search external)
if (scoredLocal.Any(x => x.TotalScore >= 70))
{
_logger.LogDebug("Found {Count} local matches for '{Title}', skipping external search",
scoredLocal.Count, title);
return allCandidates;
} }
} }
} }
catch (Exception ex)
{
_logger.LogWarning(ex, "Failed to search local library for '{Title}'", title);
}
} }
catch (Exception ex)
// STEP 2: Only search EXTERNAL if no good local match found
var externalResults = await metadataService.SearchSongsAsync(query, limit: 10);
if (externalResults.Count > 0)
{ {
var scoredExternal = externalResults _logger.LogWarning(ex, "Failed to search local library for '{Title}'", title);
.Select(song => new
{
Song = song,
TitleScore = FuzzyMatcher.CalculateSimilarityAggressive(title, song.Title),
ArtistScore = FuzzyMatcher.CalculateArtistMatchScore(artists, song.Artist, song.Contributors)
})
.Select(x => new
{
x.Song,
x.TitleScore,
x.ArtistScore,
TotalScore = (x.TitleScore * 0.7) + (x.ArtistScore * 0.3)
})
.Where(x =>
x.TotalScore >= 40 ||
(x.ArtistScore >= 70 && x.TitleScore >= 30) ||
x.TitleScore >= 85)
.OrderByDescending(x => x.TotalScore)
.Select(x => (x.Song, x.TotalScore))
.ToList();
allCandidates.AddRange(scoredExternal);
} }
}
return allCandidates; cancellationToken.ThrowIfCancellationRequested();
}
catch // STEP 2: Only search EXTERNAL if no good local match found
var externalResults = await metadataService.SearchSongsAsync(query, limit: 10, cancellationToken);
if (externalResults.Count > 0)
{ {
return new List<(Song, double)>(); var scoredExternal = externalResults
.Select(song => new
{
Song = song,
TitleScore = FuzzyMatcher.CalculateSimilarityAggressive(title, song.Title),
ArtistScore = FuzzyMatcher.CalculateArtistMatchScore(artists, song.Artist, song.Contributors)
})
.Select(x => new
{
x.Song,
x.TitleScore,
x.ArtistScore,
TotalScore = (x.TitleScore * 0.7) + (x.ArtistScore * 0.3)
})
.Where(x =>
x.TotalScore >= 40 ||
(x.ArtistScore >= 70 && x.TitleScore >= 30) ||
x.TitleScore >= 85)
.OrderByDescending(x => x.TotalScore)
.Select(x => (x.Song, x.TotalScore))
.ToList();
allCandidates.AddRange(scoredExternal);
} }
return allCandidates;
} }
private double CalculateMatchScore(string jellyfinTitle, string jellyfinArtist, string spotifyTitle, string spotifyArtist) private double CalculateMatchScore(string jellyfinTitle, string jellyfinArtist, string spotifyTitle, string spotifyArtist)
@@ -1161,21 +1250,19 @@ public class SpotifyTrackMatchingService : BackgroundService
/// Attempts to match a track by ISRC. /// Attempts to match a track by ISRC.
/// SEARCHES LOCAL FIRST, then external if no local match found. /// SEARCHES LOCAL FIRST, then external if no local match found.
/// </summary> /// </summary>
private async Task<Song?> TryMatchByIsrcAsync(string isrc, IMusicMetadataService metadataService) private async Task<Song?> TryMatchByIsrcAsync(
string isrc,
IMusicMetadataService metadataService,
CancellationToken cancellationToken)
{ {
try // STEP 1: Search LOCAL Jellyfin library FIRST by ISRC
{ // Note: Jellyfin doesn't have ISRC search, so we skip local ISRC search
// STEP 1: Search LOCAL Jellyfin library FIRST by ISRC // Local tracks will be found via fuzzy matching instead
// Note: Jellyfin doesn't have ISRC search, so we skip local ISRC search
// Local tracks will be found via fuzzy matching instead
// STEP 2: Search EXTERNAL by ISRC cancellationToken.ThrowIfCancellationRequested();
return await metadataService.FindSongByIsrcAsync(isrc);
} // STEP 2: Search EXTERNAL by ISRC
catch return await metadataService.FindSongByIsrcAsync(isrc, cancellationToken);
{
return null;
}
} }
/// <summary> /// <summary>