Bound slskd HTTP timeout — fixes worker thread deadlock
GitHub issue #499 (@bafoed). Big initial sync of Spotify playlists worked for 2-3 hours then downloads silently stopped: - 3 active tasks stuck in "Searching" state, replaced every ~10 min by different ones - slskd UI showed no actual searches happening - Debug log: orphaned-task count grew over time, no jobs executed - Container restart was the only fix (bought another 2-3 hours) - Not a rate limit (rates showed 0/min) Root cause: ``core/soulseek_client.py`` constructed ``aiohttp.ClientSession()`` with no timeout at four sites. When slskd hung on a request (overloaded, transient network blip, internal stall), the HTTP call blocked indefinitely — and the worker thread blocked with it. The download executor only has ``ThreadPoolExecutor(max_workers=3)``, so once 3 worker threads were wedged on hung calls, no further downloads could start. Batch-level "stuck detection" (10-minute timer in ``check_batch_completion_v2``) was correctly marking tasks ``not_found`` and trying to start replacements, but the executor pool was exhausted — replacements queued forever inside the executor with no thread to run them. Symptom: tasks rotating every ~10 min at the batch level while the underlying executor stayed wedged. Fix: bounded ``aiohttp.ClientTimeout`` (total 120s, connect 15s, sock_read 60s) on every slskd ``ClientSession`` construction. Module- level constant ``_SLSKD_DEFAULT_TIMEOUT`` so the four sites stay in lockstep — future sites get the same protection by reusing the constant. Why these timeouts are safe: - Every slskd API call is metadata-level (search submission, status polls, download enqueue, transfer state queries). None stream files — slskd handles file transfer via its own peer-to-peer infrastructure entirely outside our HTTP requests. - Legitimate metadata calls finish in seconds. 120s ceiling is ~50× the normal latency. Timeout handling: - ``asyncio.TimeoutError`` caught explicitly BEFORE the generic ``except Exception`` — surfaces "slskd timed out" specifically in logs (debuggable instead of buried as "Error making API request"). - Returns None to the caller (same code path as a 5xx response or any other failure). No new error path; callers already handle None as "request failed". - Worker thread unblocks immediately → executor pool stays healthy → downloads keep flowing. Sites updated: - ``_make_request`` (general /api/v0/ helper, line 152) — used for every slskd API operation - ``_make_direct_request`` (non-/api/v0/ helper, line 235) - ``_explore_api_endpoints`` Swagger fetch (line 1566) — diagnostic - ``_explore_api_endpoints`` per-endpoint probe (line 1617) — diagnostic Tests: 3 new tests in ``tests/downloads/test_soulseek_pinning.py`` pin: - ``_SLSKD_DEFAULT_TIMEOUT`` is bounded (total set, ≤300s ceiling, connect ≤60s) — guards against future regressions that drop or unbound the timeout - ``_make_request`` returns None on ``asyncio.TimeoutError`` rather than raising — pins the caller contract - ``_make_direct_request`` returns None on ``asyncio.TimeoutError`` 2185/2185 full suite green. Closes #499.
This commit is contained in:
Broque Thomas
parent
fdd6700161
commit
5c69b853b4
3 changed files with 174 additions and 27 deletions
|
|
@ -23,6 +23,31 @@ from core.download_plugins.base import DownloadSourcePlugin
|
|||
logger = get_logger("soulseek_client")
|
||||
|
||||
|
||||
# slskd HTTP timeouts. Issue #499: long-running download sessions
|
||||
# (~2-3hr) wedged because ``aiohttp.ClientSession()`` was constructed
|
||||
# with no timeout — when slskd hung on a request (overloaded, network
|
||||
# blip, internal stall), the HTTP call blocked indefinitely. The
|
||||
# download worker thread blocked with it. Once the
|
||||
# ``ThreadPoolExecutor(max_workers=3)`` had all 3 threads wedged,
|
||||
# no further downloads could start and the user had to restart the
|
||||
# container.
|
||||
#
|
||||
# Every slskd API call is metadata-level (search submission, status
|
||||
# polls, download enqueue, transfer state queries) — none stream files.
|
||||
# slskd handles file transfer via its own peer-to-peer infrastructure
|
||||
# entirely outside our HTTP requests. So generous-but-bounded timeouts
|
||||
# are safe and won't kill legitimate operations.
|
||||
#
|
||||
# Failures surface as caught exceptions in the existing
|
||||
# ``except Exception`` blocks → logged + return None → caller treats
|
||||
# as a normal failure (same as a 5xx response). No new error path.
|
||||
_SLSKD_DEFAULT_TIMEOUT = aiohttp.ClientTimeout(
|
||||
total=120, # hard ceiling — no single slskd call should take >2min
|
||||
connect=15, # TCP connect to slskd
|
||||
sock_read=60, # per-chunk read; slskd shouldn't go silent for >60s
|
||||
)
|
||||
|
||||
|
||||
class SoulseekClient(DownloadSourcePlugin):
|
||||
def __init__(self):
|
||||
self.base_url: Optional[str] = None
|
||||
|
|
@ -119,25 +144,27 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
|
||||
url = f"{self.base_url}/api/v0/{endpoint}"
|
||||
|
||||
# Create a fresh session for each thread/event loop to avoid conflicts
|
||||
# Create a fresh session for each thread/event loop to avoid conflicts.
|
||||
# Bounded timeout (issue #499) prevents the worker thread from
|
||||
# wedging if slskd hangs.
|
||||
session = None
|
||||
try:
|
||||
session = aiohttp.ClientSession()
|
||||
|
||||
session = aiohttp.ClientSession(timeout=_SLSKD_DEFAULT_TIMEOUT)
|
||||
|
||||
headers = self._get_headers()
|
||||
|
||||
|
||||
if 'json' in kwargs:
|
||||
logger.debug(f"JSON payload: {kwargs['json']}")
|
||||
|
||||
|
||||
async with session.request(
|
||||
method,
|
||||
url,
|
||||
method,
|
||||
url,
|
||||
headers=headers,
|
||||
**kwargs
|
||||
) as response:
|
||||
response_text = await response.text()
|
||||
|
||||
|
||||
|
||||
|
||||
if response.status in [200, 201, 204]: # Accept 200 OK, 201 Created, and 204 No Content
|
||||
self._last_401_logged = False # Reset on success
|
||||
try:
|
||||
|
|
@ -156,7 +183,7 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
else:
|
||||
# Enhanced error logging for better debugging
|
||||
error_detail = response_text if response_text.strip() else "No error details provided"
|
||||
|
||||
|
||||
# Reduce noise for expected 404s (e.g. status checks for YouTube downloads)
|
||||
# and repeated 401s (slskd not running / bad credentials)
|
||||
if response.status == 404:
|
||||
|
|
@ -170,9 +197,17 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
self._last_401_logged = False
|
||||
logger.error(f"API request failed: HTTP {response.status} ({response.reason}) - {error_detail}")
|
||||
logger.debug(f"Failed request: {method} {url}")
|
||||
|
||||
|
||||
return None
|
||||
|
||||
|
||||
except asyncio.TimeoutError:
|
||||
# Issue #499: explicit handling so the worker thread unblocks
|
||||
# instead of staying wedged on the HTTP call.
|
||||
logger.warning(
|
||||
f"slskd request timed out after {_SLSKD_DEFAULT_TIMEOUT.total}s: "
|
||||
f"{method} {url} — slskd may be overloaded or unreachable"
|
||||
)
|
||||
return None
|
||||
except Exception as e:
|
||||
logger.error(f"Error making API request: {e}")
|
||||
return None
|
||||
|
|
@ -183,34 +218,36 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
await session.close()
|
||||
except:
|
||||
pass
|
||||
|
||||
|
||||
async def _make_direct_request(self, method: str, endpoint: str, **kwargs) -> Optional[Dict[str, Any]]:
|
||||
"""Make a direct request to slskd without /api/v0/ prefix (for endpoints that work directly)"""
|
||||
if not self.base_url:
|
||||
logger.debug("Soulseek client not configured")
|
||||
return None
|
||||
|
||||
|
||||
url = f"{self.base_url}/{endpoint}"
|
||||
|
||||
# Create a fresh session for each thread/event loop to avoid conflicts
|
||||
|
||||
# Create a fresh session for each thread/event loop to avoid conflicts.
|
||||
# Bounded timeout (issue #499) prevents the worker thread from
|
||||
# wedging if slskd hangs.
|
||||
session = None
|
||||
try:
|
||||
session = aiohttp.ClientSession()
|
||||
|
||||
session = aiohttp.ClientSession(timeout=_SLSKD_DEFAULT_TIMEOUT)
|
||||
|
||||
headers = self._get_headers()
|
||||
|
||||
|
||||
if 'json' in kwargs:
|
||||
logger.debug(f"JSON payload: {kwargs['json']}")
|
||||
|
||||
|
||||
async with session.request(
|
||||
method,
|
||||
url,
|
||||
method,
|
||||
url,
|
||||
headers=headers,
|
||||
**kwargs
|
||||
) as response:
|
||||
response_text = await response.text()
|
||||
|
||||
|
||||
|
||||
|
||||
if response.status == 200:
|
||||
try:
|
||||
return await response.json()
|
||||
|
|
@ -221,7 +258,13 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
else:
|
||||
logger.error(f"Direct API request failed: {response.status} - {response_text}")
|
||||
return None
|
||||
|
||||
|
||||
except asyncio.TimeoutError:
|
||||
logger.warning(
|
||||
f"slskd direct request timed out after {_SLSKD_DEFAULT_TIMEOUT.total}s: "
|
||||
f"{method} {url} — slskd may be overloaded or unreachable"
|
||||
)
|
||||
return None
|
||||
except Exception as e:
|
||||
logger.error(f"Error making direct API request: {e}")
|
||||
return None
|
||||
|
|
@ -1520,7 +1563,7 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
# Try to get Swagger/OpenAPI documentation
|
||||
swagger_url = f"{self.base_url}/swagger/v1/swagger.json"
|
||||
|
||||
session = aiohttp.ClientSession()
|
||||
session = aiohttp.ClientSession(timeout=_SLSKD_DEFAULT_TIMEOUT)
|
||||
try:
|
||||
headers = self._get_headers()
|
||||
async with session.get(swagger_url, headers=headers) as response:
|
||||
|
|
@ -1571,7 +1614,7 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
else:
|
||||
# Try different endpoints without /api/v0 prefix
|
||||
simple_url = f"{self.base_url}/{endpoint}"
|
||||
session = aiohttp.ClientSession()
|
||||
session = aiohttp.ClientSession(timeout=_SLSKD_DEFAULT_TIMEOUT)
|
||||
try:
|
||||
headers = self._get_headers()
|
||||
async with session.get(simple_url, headers=headers) as resp:
|
||||
|
|
|
|||
|
|
@ -256,3 +256,94 @@ def test_cancel_download_returns_false_when_username_lookup_fails(configured_cli
|
|||
AsyncMock(return_value=[])):
|
||||
result = _run_async(configured_client.cancel_download('missing-id', None))
|
||||
assert result is False
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# HTTP timeout config (issue #499 — prevent worker thread deadlock)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_default_timeout_constant_has_bounded_values():
|
||||
"""Pin issue #499 fix: the module-level timeout config is defined
|
||||
with a hard ceiling so an unresponsive slskd can't wedge the
|
||||
download worker thread permanently. Any future change that drops
|
||||
or unbounds the timeout would re-introduce the
|
||||
'downloads stop after 2-3 hours' deadlock."""
|
||||
from core.soulseek_client import _SLSKD_DEFAULT_TIMEOUT
|
||||
import aiohttp
|
||||
|
||||
assert isinstance(_SLSKD_DEFAULT_TIMEOUT, aiohttp.ClientTimeout)
|
||||
# Total timeout must be set and bounded — prevents infinite hang.
|
||||
assert _SLSKD_DEFAULT_TIMEOUT.total is not None
|
||||
assert _SLSKD_DEFAULT_TIMEOUT.total > 0
|
||||
assert _SLSKD_DEFAULT_TIMEOUT.total <= 300, (
|
||||
f"Total timeout {_SLSKD_DEFAULT_TIMEOUT.total}s exceeds 5min "
|
||||
"ceiling — slskd metadata calls should never legitimately take this long"
|
||||
)
|
||||
# Connect timeout bounded — TCP connect to slskd should be fast.
|
||||
assert _SLSKD_DEFAULT_TIMEOUT.connect is not None
|
||||
assert _SLSKD_DEFAULT_TIMEOUT.connect <= 60
|
||||
|
||||
|
||||
def test_make_request_returns_none_on_timeout(configured_client):
|
||||
"""Pin: when the slskd HTTP call times out (asyncio.TimeoutError),
|
||||
``_make_request`` returns None rather than raising. The download
|
||||
worker thread unblocks; the caller treats None as a normal failure
|
||||
and the batch's stuck-detection later marks the task not_found.
|
||||
Pre-fix this raised → propagated up the call stack → eventually
|
||||
the worker thread died but only after wedging the executor pool."""
|
||||
|
||||
async def _raise_timeout(*args, **kwargs):
|
||||
raise asyncio.TimeoutError("simulated slskd hang")
|
||||
|
||||
# Patch aiohttp.ClientSession to return a session whose request()
|
||||
# context manager raises TimeoutError on entry.
|
||||
class _StubSession:
|
||||
async def __aenter__(self):
|
||||
return self
|
||||
async def __aexit__(self, *args):
|
||||
return None
|
||||
|
||||
def request(self, *args, **kwargs):
|
||||
class _Cm:
|
||||
async def __aenter__(self_inner):
|
||||
raise asyncio.TimeoutError("simulated slskd hang")
|
||||
async def __aexit__(self_inner, *args):
|
||||
return None
|
||||
return _Cm()
|
||||
|
||||
async def close(self):
|
||||
return None
|
||||
|
||||
with patch('aiohttp.ClientSession', return_value=_StubSession()):
|
||||
result = _run_async(configured_client._make_request('GET', 'transfers/downloads'))
|
||||
|
||||
assert result is None, "Timeout must return None, not raise"
|
||||
|
||||
|
||||
def test_make_direct_request_returns_none_on_timeout(configured_client):
|
||||
"""Same pin for ``_make_direct_request`` (the non-/api/v0/ helper).
|
||||
Both code paths are used by different slskd endpoints — neither
|
||||
can be allowed to wedge."""
|
||||
|
||||
class _StubSession:
|
||||
async def __aenter__(self):
|
||||
return self
|
||||
async def __aexit__(self, *args):
|
||||
return None
|
||||
|
||||
def request(self, *args, **kwargs):
|
||||
class _Cm:
|
||||
async def __aenter__(self_inner):
|
||||
raise asyncio.TimeoutError("simulated slskd hang")
|
||||
async def __aexit__(self_inner, *args):
|
||||
return None
|
||||
return _Cm()
|
||||
|
||||
async def close(self):
|
||||
return None
|
||||
|
||||
with patch('aiohttp.ClientSession', return_value=_StubSession()):
|
||||
result = _run_async(configured_client._make_direct_request('GET', 'health'))
|
||||
|
||||
assert result is None
|
||||
|
|
|
|||
|
|
@ -3432,6 +3432,7 @@ const WHATS_NEW = {
|
|||
'2.4.2': [
|
||||
// --- post-2.4.1 dev work — entries hidden by _getLatestWhatsNewVersion until the build version bumps ---
|
||||
{ date: 'Unreleased — 2.4.2 dev cycle' },
|
||||
{ title: 'Fix: Downloads Stop After 2-3 Hours (slskd HTTP Timeout)', desc: 'github issue #499 (bafoed): big initial sync of spotify playlists worked for 2-3 hours then downloads silently stopped. 3 active tasks stuck in "searching" state, replaced every ~10 min by different ones, but slskd ui showed no actual searches happening. only fix was restarting the soulsync container — which would buy another 2-3 hours. root cause: `core/soulseek_client.py` constructed `aiohttp.ClientSession()` with no timeout at four sites. when slskd hung on a request (overloaded, transient network blip, internal stall), the http call blocked indefinitely — and the worker thread blocked with it. download executor only has `max_workers=3` for download workers. once 3 worker threads were wedged on hung calls, no further downloads could start. batch-level "stuck detection" (10-min) was correctly marking tasks `not_found` and trying to start replacements, but the executor pool was exhausted — replacements queued forever. fix: bounded `aiohttp.ClientTimeout` (total 120s, connect 15s, sock_read 60s) on every slskd `ClientSession` construction. legitimate metadata calls (search submission, status polls, download enqueue) finish in seconds — slskd doesn\'t stream files through these requests, so the timeout can\'t kill a real operation. when timeout fires, the request raises `asyncio.TimeoutError` which is now explicitly caught + logged + returns None to the caller (treats as a normal failure, same code path as a 5xx response). worker thread unblocks → executor pool stays healthy → downloads keep flowing. 3 new tests pin the timeout config + the `asyncio.TimeoutError` handler so future drift fails at the test boundary instead of at runtime against a wedged executor.', page: 'downloads' },
|
||||
{ title: 'Fix: Library Reorganize Job Misclassified Album Tracks As Singles', desc: 'github issue #500 (bafoed): library reorganize repair job moved tracks like `Surf Curse/Surf Curse - Nothing Yet (2017)/01 - Christine F.flac` to single-template paths like `Surf Curse/Surf Curse - Christine F/Surf Curse - Christine F.flac`. root cause: the job used `is_album = (group_size > 1)` where `group_size` was the count of tracks for the same album currently sitting in the transfer folder being scanned — when only one track of an album was in transfer (rest already moved to library, or album tags varied across tracks like "Buds" vs "Buds (Bonus)"), each track became a 1-element group → all routed through single template. fix: rewrote the job to delegate to the per-album planner (`core.library_reorganize.preview_album_reorganize` / `reorganize_queue`) — the same planner the artist-detail "reorganize" modal uses. db-driven: the planner knows the album has multiple tracks regardless of how many sit in the transfer folder, so the album-vs-single classification is structurally correct. apply mode delegates to the existing reorganize queue → file move + post-processing + db update + sidecar handling all flow through one code path. only iterates albums for the ACTIVE media server (matches the artist-detail modal\'s scope) — multi-server users (plex + jellyfin etc) won\'t accidentally have the job touch the inactive server\'s files. albums missing a metadata source id get a single "needs enrichment first" finding instead of n per-track "no source" findings. dropped ~500 loc of tag-reading + transfer-walk + template logic that was duplicated against the per-album path. files in transfer with no db entry are now exclusively the orphan_file_detector\'s domain (clean separation). 12 tests pin the delegation contract.', page: 'library' },
|
||||
{ title: 'Fix: Enrich Honors Manual Album Matches', desc: 'github issue #501 (tacobell444): if you manually matched an album to a specific source ID via the match-chip UI, then clicked "enrich" on that album, the worker would search by name and overwrite your manual match with whatever the search returned (or revert status to "not_found" if it found nothing). reorganize then read the now-wrong id and moved files to the wrong destination. fix: extracted a shared `core/enrichment/manual_match_honoring.py` helper. every per-source enrichment worker (spotify / itunes / deezer / tidal / qobuz) now reads its stored id column at the top of `_process_*_individual` — if present, it fetches via `client.get_album(stored_id)` directly and refreshes metadata without touching the id. fuzzy name search only runs as fallback for never-matched entities. discogs / audiodb / musicbrainz already had inline stored-id fast paths and are left alone. lastfm / genius are name-based and don\'t store ids. cin-shape lift: same fix in 5 workers gets exactly one helper, per-worker variability (column name, client method, response shape) plugs in via callbacks. 11 new helper tests pin: stored-id fast-path, no-id fallthrough, fetch-failure fallthrough, table/column whitelist, callback contract.', page: 'library' },
|
||||
{ title: 'Fix: "no such table: hifi_instances" When Adding HiFi Instance', desc: 'github issue #503 (hadshaw21): adding a hifi instance via downloader settings popped up `no such table: hifi_instances` even though the connection test and "check all instances" both worked. root cause: `_initialize_database` runs every CREATE TABLE + every migration step inside one sqlite transaction. python\'s sqlite3 module doesn\'t autocommit DDL by default, so if any later migration step throws on a user\'s specific DB shape (e.g. an old volume from a prior soulsync version with quirky schema state), the WHOLE batch rolls back — including the hifi_instances CREATE that ran successfully. user\'s next boot retries init, hits the same migration failure, rolls back again. table never lands. fix: defensive lazy-create. every hifi_instances CRUD method now runs `CREATE TABLE IF NOT EXISTS hifi_instances (...)` immediately before its operation. idempotent — costs one PRAGMA-level no-op when the table is already present, fully recovers from a broken init. read methods (`get_hifi_instances`, `get_all_hifi_instances`) now return empty instead of raising when init failed. write methods (`add`, `remove`, `toggle`, `reorder`, `seed`) work end-to-end. doesn\'t paper over the underlying init issue (still worth tracking down which migration breaks for which users) but makes hifi instance management self-healing. 7 new tests pin the lazy-create behavior — every method works against a DB that\'s missing the table.', page: 'settings' },
|
||||
|
|
@ -3780,6 +3781,18 @@ const WHATS_NEW = {
|
|||
// Section shape: { title, description, features: [bullet strings],
|
||||
// usage_note?: 'optional hint shown at the bottom' }
|
||||
const VERSION_MODAL_SECTIONS = [
|
||||
{
|
||||
title: "Big Sync Sessions No Longer Wedge After 2-3 Hours",
|
||||
description: "github issue #499 (bafoed): downloading a big initial sync from spotify playlists worked for 2-3 hours then silently stopped. 3 active tasks stuck in \"searching\" state, replaced every ~10 min, slskd ui showed no actual activity. only fix was restarting the container.",
|
||||
features: [
|
||||
"• root cause: `aiohttp.ClientSession()` was constructed with no timeout — when slskd hung (overloaded / network blip / internal stall), the http call blocked forever and the worker thread blocked with it",
|
||||
"• download executor only has 3 worker threads — once all 3 wedged on hung calls, no further downloads could start",
|
||||
"• fix: bounded `aiohttp.ClientTimeout` (total 120s, connect 15s, sock_read 60s) on every slskd session — slskd metadata calls finish in seconds, so the timeout can\'t kill a real operation",
|
||||
"• timeout fires → caught + logged + return None → caller treats as a normal failure (same code path as a 5xx response) → worker thread unblocks → executor stays healthy",
|
||||
"• 3 new pinning tests on the timeout config + handler so future drift fails at the test boundary, not against a wedged executor in production",
|
||||
],
|
||||
usage_note: "no settings to change — applies on next container restart",
|
||||
},
|
||||
{
|
||||
title: "Library Reorganize No Longer Mistakes Album Tracks for Singles",
|
||||
description: "github issue #500 (bafoed): library reorganize repair job was moving album tracks like `01 - Christine F.flac` to single-template paths because of a fragile classification heuristic.",
|
||||
|
|
|
|||
Loading…
Reference in a new issue