fix(soulseek): suppress connection-error log spam when slskd unreachable (#649)
When slskd_url is configured but the host is unreachable (slskd not running, wrong port, host.docker.internal not resolving), the frontend's /api/downloads/status polling fanned out to every download plugin including Soulseek. soulseek_client._make_request hit a DNS / connect failure on each poll and logged it at ERROR. Result: one "Cannot connect to host host.docker.internal:5030" log line every ~2-3 seconds for the entire duration of any download — visible spam even when the user wasn't using Soulseek at all. Caught aiohttp.ClientConnectorError explicitly in both _make_request and _make_direct_request. First failure emits one WARNING with actionable context (start slskd, or clear soulseek.slskd_url if you don't use Soulseek). Subsequent failures demote to DEBUG. The _last_unreachable_logged flag resets on any successful (200/201/204) response so a later outage warns again — suppression is per-outage, not per-process-lifetime. Same shape as the existing _last_401_logged suppression for auth failures. The architectural gap (status polling fans out to soulseek even when the user has soulseek disabled in their active download sources) is intentionally left for a follow-up. The plugin-iteration code lives in core/download_engine/engine.py and core/download_orchestrator.py; threading a "skip-when-not-active" gate through every caller is a bigger refactor than this user-facing log cleanup warrants. The WARNING-once message tells the user what to do in the meantime. 5 new pinning tests cover the suppression contract: connection error returns None (not raises), first failure WARNs + sets flag, repeats stay quiet, successful response resets the flag, _make_direct_request follows the same pattern, and non-connection exceptions still log at ERROR so real bugs aren't hidden behind the new suppression.
This commit is contained in:
parent
e35bcbd2cb
commit
54e4ba843f
3 changed files with 198 additions and 0 deletions
|
|
@ -250,6 +250,7 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
|
||||
if response.status in [200, 201, 204]: # Accept 200 OK, 201 Created, and 204 No Content
|
||||
self._last_401_logged = False # Reset on success
|
||||
self._last_unreachable_logged = False # Same reset for unreachable-host suppression
|
||||
try:
|
||||
if response_text.strip(): # Only parse if there's content
|
||||
return await response.json()
|
||||
|
|
@ -291,6 +292,25 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
f"{method} {url} — slskd may be overloaded or unreachable"
|
||||
)
|
||||
return None
|
||||
except aiohttp.ClientConnectorError as e:
|
||||
# Issue #649: slskd_url is configured but the host is unreachable
|
||||
# (slskd not running, wrong port, DNS / Docker bridge issue).
|
||||
# Status polling at /api/downloads/status fans out to every plugin
|
||||
# including soulseek even when the user has soulseek toggled out
|
||||
# of their active download sources, so each frontend poll
|
||||
# produced an ERROR log line — visible spam during any
|
||||
# non-soulseek download. Suppress repeats to debug; emit one
|
||||
# WARNING with actionable context, then reset on any successful
|
||||
# response (slskd came back up).
|
||||
if not getattr(self, '_last_unreachable_logged', False):
|
||||
logger.warning(
|
||||
f"slskd unreachable at {self.base_url}: {e}. "
|
||||
f"Either start slskd or clear `soulseek.slskd_url` in settings "
|
||||
f"if you don't use Soulseek. Suppressing further connection errors."
|
||||
)
|
||||
self._last_unreachable_logged = True
|
||||
logger.debug(f"slskd connection failed: {method} {url}: {e}")
|
||||
return None
|
||||
except Exception as e:
|
||||
logger.error(f"Error making API request: {e}")
|
||||
return None
|
||||
|
|
@ -348,6 +368,19 @@ class SoulseekClient(DownloadSourcePlugin):
|
|||
f"{method} {url} — slskd may be overloaded or unreachable"
|
||||
)
|
||||
return None
|
||||
except aiohttp.ClientConnectorError as e:
|
||||
# Issue #649 — same suppression as _make_request. Direct
|
||||
# request is a less common path but uses the same base_url,
|
||||
# so the same unreachable-host condition fires here.
|
||||
if not getattr(self, '_last_unreachable_logged', False):
|
||||
logger.warning(
|
||||
f"slskd unreachable at {self.base_url}: {e}. "
|
||||
f"Either start slskd or clear `soulseek.slskd_url` in settings "
|
||||
f"if you don't use Soulseek. Suppressing further connection errors."
|
||||
)
|
||||
self._last_unreachable_logged = True
|
||||
logger.debug(f"slskd direct connection failed: {method} {url}: {e}")
|
||||
return None
|
||||
except Exception as e:
|
||||
logger.error(f"Error making direct API request: {e}")
|
||||
return None
|
||||
|
|
|
|||
|
|
@ -347,3 +347,167 @@ def test_make_direct_request_returns_none_on_timeout(configured_client):
|
|||
result = _run_async(configured_client._make_direct_request('GET', 'health'))
|
||||
|
||||
assert result is None
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Issue #649 — connection-error log spam suppression
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _build_unreachable_session(error_message: str = 'Cannot connect to host'):
|
||||
"""Stub aiohttp session whose request() raises ClientConnectorError."""
|
||||
import aiohttp
|
||||
from unittest.mock import MagicMock
|
||||
|
||||
class _Cm:
|
||||
async def __aenter__(self_inner):
|
||||
# ClientConnectorError needs a connection_key + OSError. The
|
||||
# exact values don't matter for the test — we just need an
|
||||
# instance of the right class so the except-branch fires.
|
||||
os_err = OSError(-2, 'Name or service not known')
|
||||
raise aiohttp.ClientConnectorError(MagicMock(), os_err)
|
||||
async def __aexit__(self_inner, *args):
|
||||
return None
|
||||
|
||||
class _StubSession:
|
||||
async def __aenter__(self):
|
||||
return self
|
||||
async def __aexit__(self, *args):
|
||||
return None
|
||||
def request(self, *args, **kwargs):
|
||||
return _Cm()
|
||||
async def close(self):
|
||||
return None
|
||||
|
||||
return _StubSession
|
||||
|
||||
|
||||
def test_unreachable_slskd_returns_none_not_raises(configured_client):
|
||||
"""Pin: ClientConnectorError must not propagate. Caller treats None
|
||||
as a normal failure (same as a 5xx) — every consumer that gates on
|
||||
`if response is None` keeps working when slskd is unreachable."""
|
||||
StubSession = _build_unreachable_session()
|
||||
with patch('aiohttp.ClientSession', return_value=StubSession()):
|
||||
result = _run_async(configured_client._make_request('GET', 'transfers/downloads'))
|
||||
assert result is None
|
||||
|
||||
|
||||
def test_unreachable_slskd_logs_warning_once_then_debug(configured_client, caplog):
|
||||
"""Issue #649: status polling at /api/downloads/status fans out to
|
||||
every plugin including soulseek even when the user has soulseek
|
||||
toggled out, so each frontend poll produced an ERROR log line. Pin
|
||||
that the FIRST unreachable response emits one WARNING with
|
||||
actionable context, and subsequent repeats demote to DEBUG so the
|
||||
log isn't spammed for the lifetime of every non-soulseek download."""
|
||||
import logging
|
||||
configured_client._last_unreachable_logged = False
|
||||
StubSession = _build_unreachable_session()
|
||||
|
||||
with patch('aiohttp.ClientSession', return_value=StubSession()):
|
||||
with caplog.at_level(logging.DEBUG, logger='soulseek_client'):
|
||||
# Three repeated polls — first must warn, rest must stay quiet.
|
||||
_run_async(configured_client._make_request('GET', 'transfers/downloads'))
|
||||
_run_async(configured_client._make_request('GET', 'transfers/downloads'))
|
||||
_run_async(configured_client._make_request('GET', 'transfers/downloads'))
|
||||
|
||||
warning_records = [r for r in caplog.records if r.levelno == logging.WARNING
|
||||
and 'slskd unreachable' in r.message]
|
||||
error_records = [r for r in caplog.records if r.levelno == logging.ERROR
|
||||
and 'Error making API request' in r.message]
|
||||
assert len(warning_records) == 1, \
|
||||
f"Expected exactly 1 WARNING (one-time slskd-unreachable notice), got {len(warning_records)}"
|
||||
assert len(error_records) == 0, \
|
||||
"Connection errors must not log at ERROR — that's the spam pattern #649 reported"
|
||||
assert configured_client._last_unreachable_logged is True
|
||||
|
||||
|
||||
def test_unreachable_flag_resets_on_successful_response(configured_client, caplog):
|
||||
"""When slskd comes back up after a stretch of being down, a fresh
|
||||
WARNING should fire if it goes down again later — the suppression is
|
||||
per-outage, not per-process-lifetime. The flag resets on any
|
||||
successful (200/201/204) response."""
|
||||
import logging
|
||||
configured_client._last_unreachable_logged = True # Simulate prior outage already warned
|
||||
|
||||
# Simulate a 200 response — must reset the suppression flag.
|
||||
class _OkCm:
|
||||
async def __aenter__(self_inner):
|
||||
class _Resp:
|
||||
status = 200
|
||||
reason = 'OK'
|
||||
async def text(self_resp):
|
||||
return '{"ok": true}'
|
||||
async def json(self_resp):
|
||||
return {'ok': True}
|
||||
return _Resp()
|
||||
async def __aexit__(self_inner, *args):
|
||||
return None
|
||||
|
||||
class _OkSession:
|
||||
async def __aenter__(self):
|
||||
return self
|
||||
async def __aexit__(self, *args):
|
||||
return None
|
||||
def request(self, *args, **kwargs):
|
||||
return _OkCm()
|
||||
async def close(self):
|
||||
return None
|
||||
|
||||
with patch('aiohttp.ClientSession', return_value=_OkSession()):
|
||||
_run_async(configured_client._make_request('GET', 'server/state'))
|
||||
|
||||
assert configured_client._last_unreachable_logged is False, \
|
||||
"Successful response must reset the suppression flag so a future outage warns again"
|
||||
|
||||
|
||||
def test_make_direct_request_also_suppresses_unreachable_spam(configured_client, caplog):
|
||||
"""`_make_direct_request` shares the same base_url and same outage
|
||||
mode, so it gets the same WARNING-once + DEBUG-after treatment."""
|
||||
import logging
|
||||
configured_client._last_unreachable_logged = False
|
||||
StubSession = _build_unreachable_session()
|
||||
|
||||
with patch('aiohttp.ClientSession', return_value=StubSession()):
|
||||
with caplog.at_level(logging.DEBUG, logger='soulseek_client'):
|
||||
_run_async(configured_client._make_direct_request('GET', 'health'))
|
||||
_run_async(configured_client._make_direct_request('GET', 'health'))
|
||||
|
||||
warning_records = [r for r in caplog.records if r.levelno == logging.WARNING
|
||||
and 'slskd unreachable' in r.message]
|
||||
error_records = [r for r in caplog.records if r.levelno == logging.ERROR
|
||||
and 'Error making direct API request' in r.message]
|
||||
assert len(warning_records) == 1
|
||||
assert len(error_records) == 0
|
||||
|
||||
|
||||
def test_non_connection_exception_still_logs_error(configured_client, caplog):
|
||||
"""Guard: only ClientConnectorError gets the suppression treatment.
|
||||
Any other exception (programming bug, unexpected aiohttp behaviour,
|
||||
etc.) must still surface at ERROR so we don't accidentally hide
|
||||
real problems behind the noise reduction."""
|
||||
import logging
|
||||
|
||||
class _BoomCm:
|
||||
async def __aenter__(self_inner):
|
||||
raise ValueError("not a connection error — should still log ERROR")
|
||||
async def __aexit__(self_inner, *args):
|
||||
return None
|
||||
|
||||
class _BoomSession:
|
||||
async def __aenter__(self):
|
||||
return self
|
||||
async def __aexit__(self, *args):
|
||||
return None
|
||||
def request(self, *args, **kwargs):
|
||||
return _BoomCm()
|
||||
async def close(self):
|
||||
return None
|
||||
|
||||
with patch('aiohttp.ClientSession', return_value=_BoomSession()):
|
||||
with caplog.at_level(logging.DEBUG, logger='soulseek_client'):
|
||||
result = _run_async(configured_client._make_request('GET', 'transfers/downloads'))
|
||||
|
||||
assert result is None # Still returns None — non-raising contract preserved
|
||||
error_records = [r for r in caplog.records if r.levelno == logging.ERROR
|
||||
and 'Error making API request' in r.message]
|
||||
assert len(error_records) == 1, "Non-connection exceptions must still log ERROR"
|
||||
|
|
|
|||
|
|
@ -3424,6 +3424,7 @@ const WHATS_NEW = {
|
|||
{ title: 'Fix popup: paste a MusicBrainz URL or MBID to match directly', desc: 'new escape hatch on the Fix Track Match modal (the 🔧 Fix button on mirrored / YouTube / Tidal / Deezer / Beatport / ListenBrainz / Spotify-public discovery rows). when fuzzy search keeps ranking the wrong recording among many same-title versions, paste the MusicBrainz recording URL like `https://musicbrainz.org/recording/<uuid>` or the bare UUID into the new field and hit "Look up". skips all fuzzy logic, resolves straight to that record, and runs it through the same confirm + match pipeline.' },
|
||||
{ title: 'Fix popup: MusicBrainz added to the auto-search cascade', desc: 'the Fix Track Match modal used to query only Spotify → Deezer → iTunes for the auto-search, leaving MusicBrainz out of the loop entirely — even for users with MusicBrainz set as their primary metadata source. now MB is part of the cascade. when MB is your primary, it gets queried first; otherwise it sits as the last fallback. catches niche / non-mainstream / canonical-with-diacritics recordings that the commercial sources miss. Discogs is intentionally absent — Discogs has no track-level search API.' },
|
||||
{ title: 'Fix: Docker basic-search streaming silently failed under rootless Docker', desc: 'the streaming "Play" flow on the basic search page tried to create `/app/Stream` lazily at runtime, which fails silently when the container runs under rootless Docker / Podman (in-container root can\'t write to `/app`). pre-baked the directory at image build time, matching the same pattern that fixed `/app/Staging` earlier in the cycle. non-persistent — no volume needed.' },
|
||||
{ title: 'Fix: slskd-unreachable log spam during non-Soulseek downloads', desc: 'when slskd was configured but not actually running (or unreachable on its configured port), the `/api/downloads/status` polling loop fanned out to every download plugin including Soulseek, producing one `ERROR - Cannot connect to host ... [Name or service not known]` log line per poll for the entire duration of any download — visible spam even when the user wasn\'t using Soulseek at all. Connection failures now emit one WARNING with actionable context (start slskd, or clear the slskd_url if you don\'t use Soulseek) and demote subsequent failures to debug. The flag resets on the next successful slskd response so a later outage warns again.' },
|
||||
],
|
||||
'2.5.5': [
|
||||
{ date: 'May 17, 2026 — 2.5.5 release' },
|
||||
|
|
|
|||
Loading…
Reference in a new issue