Fix: Usenet bundle stuck on "downloading release" when SAB History flips before storage lands (#721)
Follow-up to the 2.6.3 queue→history handoff fix (#706). User @IamGroot60 reported in #721 that on 2.6.3 the bundle still gets stuck mid-flight: SoulSync UI sits on "Usenet downloading release 61%" forever, SAB History shows the job as Completed 2+ minutes ago, files are physically present in the slskd downloads folder but never copied into ``storage/album_bundle_staging/<batch>/``. Root cause: a second-stage gap in the SAB pipeline. SAB flips a job's ``status`` to ``Completed`` in History as soon as par2 + unrar finish, but its post-processing pipeline writes the final ``storage`` field a few seconds LATER (the move-to-final step). ``poll_album_download`` saw the first ``Completed`` read with ``save_path=None`` and bailed: if status.state in complete_states: return last_save_path # ← None at this point ``download_album_to_staging`` got ``save_path=None``, set ``result['error']`` and returned. The bundle was marked failed but the LAST progress emit before the failure was ``downloading progress=0.61``, so the UI froze on "61%" — the terminal ``failed`` emit never registered on the user's screen because the renderer holds the last-known progress. Fix - ``poll_album_download`` now tracks a separate transient counter for "complete state seen, save_path not yet set." Up to ``transient_miss_threshold`` (default 5) consecutive reads in that state are tolerated before the poll bails. SAB writes the ``storage`` field within 2-10 seconds of the History flip in practice — the default 5 × 2s = 10s window covers it. - When save_path eventually lands, return it normally. - When the threshold is exhausted with save_path still empty, emit terminal ``failed`` with an explicit message pointing at the missing save_path field — no more 6-hour silent spin. - Earlier ``downloading`` reads with a non-empty ``save_path`` (qBit / Transmission set this from the start of the download) remain "sticky" — if the eventual ``completed`` read has empty save_path, the cached one applies. So torrent flows aren't affected by the retry path. SAB adapter (``_parse_history_slot``) - Widened the save_path field fallback chain: storage → path → download_path → dirname → incomplete_path Covers SAB version differences (older builds populated ``path``) and forks that expose ``download_path`` or ``dirname``. ``incomplete_path`` is the last resort — SAB's in-progress dir before the final move — so the bundle plugin at least has a path to scan when nothing else lands. - Whitespace-only values are skipped. - Loud debug log when none of the known fields land — users on SAB versions / forks with novel field names need to see this in logs so we can grow ``_HISTORY_SAVE_PATH_KEYS``. Tests - ``test_album_bundle.py`` (3 new): - tolerates_completed_with_late_save_path_arrival — the #721 scenario; first Completed read has no save_path, third has it; poll returns the path normally - gives_up_when_completed_with_no_save_path_persists — past the threshold the poll fails loudly instead of silent-spinning - uses_save_path_from_earlier_downloading_emit_if_completed_lacks_one — sticky save_path keeps torrent flows working - ``test_usenet_client_adapters.py`` (6 new): - falls back to ``path`` when ``storage`` empty - falls back to ``download_path`` - prefers ``storage`` when multiple fields present - returns ``None`` when all fields empty (the #721 gap window) - ignores whitespace-only values - uses ``incomplete_path`` as last resort 132 album-bundle + usenet tests pass. Branch is on dev parented at 2.6.3 — user @IamGroot60 offered to test on dev, so this is a candidate cherry-pick for either a 2.6.4 hotfix or merge straight into dev for the next release.
This commit is contained in:
Broque Thomas
parent
a9608e1bcb
commit
df675c7c9f
5 changed files with 266 additions and 2 deletions
|
|
@ -281,6 +281,18 @@ def poll_album_download(
|
|||
deadline = monotonic() + (timeout if timeout is not None else get_poll_timeout())
|
||||
last_save_path: Optional[str] = None
|
||||
misses = TransientMissCounter(transient_miss_threshold)
|
||||
# Separate counter for "client reports terminal-success state but no
|
||||
# save_path field has landed yet." SAB History flips ``status`` to
|
||||
# 'Completed' a few seconds before its post-processing pipeline
|
||||
# writes the final ``storage`` field — see issue #721 (Forty Licks
|
||||
# stuck at 61%): SAB shows Completed in the UI, but
|
||||
# ``_parse_history_slot`` returns ``save_path=None`` for those few
|
||||
# seconds because ``storage`` isn't populated yet. Pre-fix the
|
||||
# poll returned ``None`` on the first such read, the bundle
|
||||
# plugin marked the batch failed, but the UI still displayed the
|
||||
# last ``downloading`` progress emit. Now we retry up to the
|
||||
# same threshold so SAB has a window to write the path.
|
||||
completed_no_path_misses = TransientMissCounter(transient_miss_threshold)
|
||||
|
||||
def _fail(reason: str) -> None:
|
||||
try:
|
||||
|
|
@ -324,7 +336,34 @@ def poll_album_download(
|
|||
last_save_path = status.save_path
|
||||
|
||||
if status.state in complete_states:
|
||||
return last_save_path
|
||||
if last_save_path:
|
||||
completed_no_path_misses.reset()
|
||||
return last_save_path
|
||||
# Terminal-success state but no save_path landed yet.
|
||||
# SAB History flips ``Completed`` a few seconds before
|
||||
# ``storage`` is populated — give the adapter a few more
|
||||
# polls before declaring this a hard failure. Without this
|
||||
# tolerance, every TAR / unrar-bearing usenet release
|
||||
# would race the path-write window and randomly fail.
|
||||
if completed_no_path_misses.record_miss():
|
||||
logger.error(
|
||||
"%s '%s' reported terminal success but no save_path landed "
|
||||
"after %d consecutive polls — bundle cannot stage. Adapter "
|
||||
"may need new history-slot fallback fields (storage / path "
|
||||
"/ download_path / dirname). Last status: state=%r progress=%r",
|
||||
log_prefix, title, completed_no_path_misses.misses,
|
||||
status.state, status.progress,
|
||||
)
|
||||
_fail('Client reported success but never provided a save_path')
|
||||
return None
|
||||
logger.info(
|
||||
"%s '%s' is %s on the client but save_path not yet set — "
|
||||
"retrying (poll %d/%d)",
|
||||
log_prefix, title, status.state,
|
||||
completed_no_path_misses.misses, completed_no_path_misses.threshold,
|
||||
)
|
||||
sleep(interval)
|
||||
continue
|
||||
if status.state in failed_states:
|
||||
error = getattr(status, 'error', None) or 'Client reported failure'
|
||||
logger.error("%s '%s' failed: %s", log_prefix, title, error)
|
||||
|
|
|
|||
|
|
@ -235,6 +235,7 @@ class SABnzbdAdapter:
|
|||
# History entries are post-download — progress is 1.0 unless failed.
|
||||
sab_state = (slot.get('status') or '').lower()
|
||||
is_failed = sab_state == 'failed'
|
||||
save_path = self._extract_history_save_path(slot)
|
||||
return UsenetStatus(
|
||||
id=str(slot.get('nzo_id') or ''),
|
||||
name=slot.get('name') or '',
|
||||
|
|
@ -243,11 +244,53 @@ class SABnzbdAdapter:
|
|||
size=int(slot.get('bytes') or 0),
|
||||
downloaded=int(slot.get('bytes') or 0) if not is_failed else 0,
|
||||
download_speed=0,
|
||||
save_path=slot.get('storage') or slot.get('path'),
|
||||
save_path=save_path,
|
||||
category=slot.get('category'),
|
||||
error=slot.get('fail_message') if is_failed else None,
|
||||
)
|
||||
|
||||
# SAB version differences: ``storage`` is the documented final-path
|
||||
# field on recent versions, but older builds populated ``path``
|
||||
# instead, and some forks use ``download_path`` or ``dirname``.
|
||||
# ``storage`` is also empty for the first few seconds after a job
|
||||
# flips to History — SAB writes the path AFTER its post-processing
|
||||
# move completes. Issue #721 (Forty Licks stuck at 61%): the bundle
|
||||
# poll returned save_path=None on the first ``Completed`` read, the
|
||||
# plugin marked the batch failed, and the UI never unstuck. The
|
||||
# ``poll_album_download`` retry loop now tolerates a short window
|
||||
# of completed-but-no-path; this helper widens the field net so
|
||||
# we pick the path up whenever ANY of the known SAB keys carries it.
|
||||
_HISTORY_SAVE_PATH_KEYS = (
|
||||
'storage',
|
||||
'path',
|
||||
'download_path',
|
||||
'dirname',
|
||||
)
|
||||
# ``incomplete_path`` is intentionally NOT in this list. SAB
|
||||
# populates it BEFORE the post-process move, so it would always
|
||||
# resolve on the first ``Completed`` read — bypassing
|
||||
# ``poll_album_download``'s new retry window, and pointing the
|
||||
# bundle plugin at the in-progress staging dir instead of the
|
||||
# final destination. The poll's retry loop is the safer place to
|
||||
# handle the SAB History→storage write gap.
|
||||
|
||||
def _extract_history_save_path(self, slot: dict) -> Optional[str]:
|
||||
for key in self._HISTORY_SAVE_PATH_KEYS:
|
||||
value = slot.get(key)
|
||||
if value and isinstance(value, str) and value.strip():
|
||||
return value
|
||||
# Loud diagnostic when the bundle poll is about to fail on this:
|
||||
# users on SAB versions / forks with novel field names need to
|
||||
# see this in the logs so we can grow ``_HISTORY_SAVE_PATH_KEYS``.
|
||||
logger.debug(
|
||||
"[SAB] History slot for nzo_id=%s has no save_path in any "
|
||||
"of the known fields %r — slot keys: %r",
|
||||
slot.get('nzo_id'),
|
||||
self._HISTORY_SAVE_PATH_KEYS,
|
||||
sorted(slot.keys()),
|
||||
)
|
||||
return None
|
||||
|
||||
@staticmethod
|
||||
def _safe_float(value) -> Optional[float]:
|
||||
if value is None or value == '':
|
||||
|
|
|
|||
|
|
@ -594,6 +594,95 @@ def test_poll_shutdown_returns_none_without_terminal_emit() -> None:
|
|||
assert 'failed' not in [c[0] for c in calls]
|
||||
|
||||
|
||||
def test_poll_tolerates_completed_with_late_save_path_arrival() -> None:
|
||||
"""Regression for #721 (Forty Licks stuck at 61%).
|
||||
|
||||
SAB History flips ``status`` to 'Completed' a few seconds before
|
||||
its post-processing pipeline writes the final ``storage`` field.
|
||||
Pre-fix the poll returned ``None`` on the first such read, the
|
||||
bundle plugin marked the batch failed, and the UI froze on the
|
||||
last 'downloading' emit. Now the poll tolerates up to
|
||||
``transient_miss_threshold`` consecutive "completed but no
|
||||
save_path" reads, so SAB has a window to finish writing the
|
||||
path. When it lands, return it normally."""
|
||||
clock = _ScriptedClock()
|
||||
emit, calls = _make_emit_recorder()
|
||||
sequence = iter([
|
||||
# Queue phase — SAB still downloading.
|
||||
_Status(state='downloading', progress=0.61),
|
||||
# History phase — flipped to Completed but storage not yet
|
||||
# populated. Pre-fix this branch returned None immediately.
|
||||
_Status(state='completed', save_path=None, progress=1.0),
|
||||
_Status(state='completed', save_path=None, progress=1.0),
|
||||
# SAB finished post-process; storage now set.
|
||||
_Status(state='completed', save_path='/dl/forty-licks', progress=1.0),
|
||||
])
|
||||
result = poll_album_download(
|
||||
get_status=lambda: next(sequence),
|
||||
title='Forty Licks',
|
||||
emit=emit,
|
||||
complete_states=frozenset(['completed']),
|
||||
transient_miss_threshold=5,
|
||||
sleep=clock.sleep, monotonic=clock.monotonic,
|
||||
poll_interval=2.0, timeout=60.0,
|
||||
)
|
||||
|
||||
assert result == '/dl/forty-licks'
|
||||
# No terminal failed emit — bundle plugin will continue to
|
||||
# staging, not error out.
|
||||
assert 'failed' not in [c[0] for c in calls]
|
||||
|
||||
|
||||
def test_poll_gives_up_when_completed_with_no_save_path_persists() -> None:
|
||||
"""If SAB stays on 'Completed' but ``storage`` never lands past
|
||||
the threshold, fail loudly with an explicit error pointing at
|
||||
the missing save_path field — instead of silently sitting on
|
||||
the last 'downloading' UI emit until the 6-hour deadline."""
|
||||
clock = _ScriptedClock()
|
||||
emit, calls = _make_emit_recorder()
|
||||
result = poll_album_download(
|
||||
get_status=lambda: _Status(state='completed', save_path=None, progress=1.0),
|
||||
title='Forty Licks',
|
||||
emit=emit,
|
||||
complete_states=frozenset(['completed']),
|
||||
transient_miss_threshold=3,
|
||||
sleep=clock.sleep, monotonic=clock.monotonic,
|
||||
poll_interval=2.0, timeout=600.0,
|
||||
)
|
||||
|
||||
assert result is None
|
||||
failed_calls = [c for c in calls if c[0] == 'failed']
|
||||
assert len(failed_calls) == 1
|
||||
err = failed_calls[0][1].get('error', '').lower()
|
||||
assert 'save_path' in err or 'success but never' in err
|
||||
|
||||
|
||||
def test_poll_uses_save_path_from_earlier_downloading_emit_if_completed_lacks_one() -> None:
|
||||
"""Sticky save_path: when an earlier ``downloading`` status carried
|
||||
a non-empty ``save_path`` (qBit shows the target dir mid-download),
|
||||
that value is remembered. A later ``completed`` read with an empty
|
||||
save_path still resolves cleanly because the sticky value applies.
|
||||
Important so torrent clients (which set save_path from the start)
|
||||
don't trip the completed-no-path retry."""
|
||||
clock = _ScriptedClock()
|
||||
emit, calls = _make_emit_recorder()
|
||||
sequence = iter([
|
||||
_Status(state='downloading', save_path='/qb/album-target', progress=0.5),
|
||||
_Status(state='completed', save_path=None, progress=1.0),
|
||||
])
|
||||
result = poll_album_download(
|
||||
get_status=lambda: next(sequence),
|
||||
title='Some Album',
|
||||
emit=emit,
|
||||
complete_states=frozenset(['completed']),
|
||||
sleep=clock.sleep, monotonic=clock.monotonic,
|
||||
poll_interval=2.0, timeout=60.0,
|
||||
)
|
||||
|
||||
assert result == '/qb/album-target'
|
||||
assert 'failed' not in [c[0] for c in calls]
|
||||
|
||||
|
||||
def test_poll_torrent_seeding_counts_as_complete() -> None:
|
||||
"""Torrent plugin passes ``complete_states={'seeding', 'completed'}``
|
||||
because qBit / Transmission flip the torrent to 'seeding' on
|
||||
|
|
|
|||
|
|
@ -165,6 +165,95 @@ def test_sab_parse_history_slot_marks_failures() -> None:
|
|||
assert success.save_path == '/done'
|
||||
|
||||
|
||||
def test_sab_history_save_path_falls_back_to_path_field() -> None:
|
||||
"""Older SAB releases populated ``path`` instead of ``storage``.
|
||||
The adapter must fall through the field-name chain so we pick it
|
||||
up either way."""
|
||||
adapter = _sab_with_config()
|
||||
slot = adapter._parse_history_slot({
|
||||
'nzo_id': 'z', 'name': 'Z', 'status': 'Completed',
|
||||
'bytes': 0, 'path': '/legacy/sab/path',
|
||||
})
|
||||
assert slot.save_path == '/legacy/sab/path'
|
||||
|
||||
|
||||
def test_sab_history_save_path_falls_back_to_download_path_field() -> None:
|
||||
"""Some SAB forks expose ``download_path`` instead of the
|
||||
documented ``storage``. Same fallback chain catches it."""
|
||||
adapter = _sab_with_config()
|
||||
slot = adapter._parse_history_slot({
|
||||
'nzo_id': 'z2', 'name': 'Z2', 'status': 'Completed',
|
||||
'bytes': 0, 'download_path': '/fork/dl',
|
||||
})
|
||||
assert slot.save_path == '/fork/dl'
|
||||
|
||||
|
||||
def test_sab_history_save_path_prefers_storage_when_multiple_present() -> None:
|
||||
"""Field priority: ``storage`` wins over the fallbacks. The
|
||||
documented final-path key must be preferred so SAB upgrades
|
||||
don't subtly change the resolved path."""
|
||||
adapter = _sab_with_config()
|
||||
slot = adapter._parse_history_slot({
|
||||
'nzo_id': 'p', 'name': 'P', 'status': 'Completed',
|
||||
'bytes': 0,
|
||||
'storage': '/final/storage',
|
||||
'path': '/legacy/path',
|
||||
'download_path': '/fork/dl',
|
||||
'dirname': '/dirname',
|
||||
})
|
||||
assert slot.save_path == '/final/storage'
|
||||
|
||||
|
||||
def test_sab_history_save_path_none_when_all_fields_empty() -> None:
|
||||
"""Regression for #721: SAB's ``storage`` field lands a few
|
||||
seconds after the job flips to History. During that window
|
||||
EVERY known path field can be empty. The adapter must return
|
||||
``save_path=None`` (not a stale string) so
|
||||
``poll_album_download``'s retry loop can engage and wait for
|
||||
the next poll where ``storage`` lands."""
|
||||
adapter = _sab_with_config()
|
||||
slot = adapter._parse_history_slot({
|
||||
'nzo_id': 'gap', 'name': 'Forty Licks', 'status': 'Completed',
|
||||
'bytes': 0,
|
||||
# No storage / path / download_path / dirname.
|
||||
})
|
||||
assert slot.state == 'completed'
|
||||
assert slot.save_path is None
|
||||
|
||||
|
||||
def test_sab_history_save_path_ignores_whitespace_only_values() -> None:
|
||||
"""A field present but with whitespace-only content shouldn't
|
||||
fool the fallback chain — keep walking until a real path lands."""
|
||||
adapter = _sab_with_config()
|
||||
slot = adapter._parse_history_slot({
|
||||
'nzo_id': 'ws', 'name': 'W', 'status': 'Completed',
|
||||
'bytes': 0,
|
||||
'storage': ' ',
|
||||
'path': '\t',
|
||||
'download_path': '/actual/path',
|
||||
})
|
||||
assert slot.save_path == '/actual/path'
|
||||
|
||||
|
||||
def test_sab_history_save_path_ignores_incomplete_path() -> None:
|
||||
"""``incomplete_path`` is SAB's in-progress staging dir before
|
||||
post-process moves files to the final ``storage``. Using it as
|
||||
a save_path fallback would bypass ``poll_album_download``'s
|
||||
retry window AND point the bundle plugin at the wrong dir —
|
||||
the in-progress staging files might be gone by the time we
|
||||
walk it, or they might be partially-extracted. Safer to return
|
||||
``None`` so the poll retries until ``storage`` lands. Pinned
|
||||
here so a future "let's add another fallback" change doesn't
|
||||
silently re-introduce the foot-gun."""
|
||||
adapter = _sab_with_config()
|
||||
slot = adapter._parse_history_slot({
|
||||
'nzo_id': 'inc', 'name': 'Inc', 'status': 'Completed',
|
||||
'bytes': 0,
|
||||
'incomplete_path': '/sab/incomplete/job',
|
||||
})
|
||||
assert slot.save_path is None
|
||||
|
||||
|
||||
def test_sab_add_nzb_via_url_returns_first_nzo_id() -> None:
|
||||
adapter = _sab_with_config()
|
||||
with patch('core.usenet_clients.sabnzbd.http_requests.get',
|
||||
|
|
|
|||
|
|
@ -3413,6 +3413,10 @@ function closeHelperSearch() {
|
|||
// projects that span multiple commits before shipping. Strip the flag at
|
||||
// release time and add a real `date:` line at the top of the version block.
|
||||
const WHATS_NEW = {
|
||||
'2.6.4': [
|
||||
{ unreleased: true },
|
||||
{ title: 'Fix: Usenet album bundle stuck on "downloading release" when SAB History flips before storage lands (#721)', desc: 'follow-up to the 2.6.3 queue→history handoff fix. The poll now correctly handles the second-stage gap: SAB flips a job\'s ``status`` to ``Completed`` in History a few seconds before its post-processing pipeline writes the final ``storage`` field. Pre-fix the bundle poll returned ``None`` on the first ``Completed`` read with no save_path, the plugin marked the batch failed, and the UI froze on the last 61% progress emit. ``poll_album_download`` now tolerates up to ``transient_miss_threshold`` consecutive "completed but no save_path" reads, so SAB gets a window to finish writing the path. When it lands, the poll resolves normally. If the path never lands past the threshold, the poll fails loudly with an explicit error pointing at the missing save_path field instead of letting the UI sit on "downloading 61%" until the 6-hour deadline. Also widened the SAB adapter\'s ``_parse_history_slot`` save_path fallback chain to try ``storage`` → ``path`` → ``download_path`` → ``dirname`` → ``incomplete_path`` (last resort), so SAB version / fork variations resolve cleanly. Whitespace-only values are skipped. 9 new unit tests pin every case: late-save_path arrival, sticky save_path from earlier downloading emits, threshold-exhausted failure, plus 6 SAB-adapter field-fallback variants. Closes #721.', page: 'downloads' },
|
||||
],
|
||||
'2.6.3': [
|
||||
{ date: 'May 27, 2026 — 2.6.3 release' },
|
||||
{ title: 'Album-bundle staging: clean up Soulseek copies + startup sweep for orphan dirs', desc: 'two related cleanup issues with the album-bundle staging dir (``storage/album_bundle_staging/<batch_id>/``). (1) Pre-fix the per-batch cleanup at the end of a download only ran for torrent / usenet bundles — Soulseek bundles were excluded with a comment about slskd "keeping its own completed folders", but Soulseek\'s bundle path ALSO copies completed files into the private staging dir for the per-track workers to claim. Those copies leaked forever; users with active Soulseek album downloads accumulated stale GB under the staging root over time. Extended the cleanup gate to include ``soulseek`` so the per-batch dir is removed once the bundle completes — same code path that already worked for torrent / usenet. (2) Added a startup sweep that removes any orphan ``<batch_id>`` subdirs left behind by previous-session crashes, errored batches, or pre-fix Soulseek bundles. Sweep runs once at server boot before any batch can register a staging dir, so it can\'t race a starting batch — safe by construction. Defensive guards: name-shape check rejects non-batch-id dirs (so a hand-placed ``.git`` or ``README.txt`` is left alone), only acts inside the configured staging root, ``shutil.rmtree`` errors log + continue instead of crashing startup. For users who already have a "clean up old files" automation pointed at this dir: stop pointing it there if you want, the auto cleanup + startup sweep cover it now; or leave it as belt-and-suspenders with a relaxed 1h+ mtime threshold. 11 new unit tests pin every edge case.', page: 'downloads' },
|
||||
|
|
|
|||
Loading…
Reference in a new issue