From 99b66aa85f4147e84a7408778b1fdfad1a477109 Mon Sep 17 00:00:00 2001 From: Bryan Van Deusen Date: Sat, 30 May 2026 14:16:54 -0400 Subject: [PATCH] fix(download): preserve partial output + classify timeouts richer MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Operator-flagged 2026-05-30: "the fail state of timeouts doesn't show anything other than that the task timedout and was cleaned up. I can't tell why it ran over or if it was stuck failed or there was just that much to get." The TimeoutExpired branch was returning a DownloadResult with no stdout, no stderr, no files_downloaded, and a generic "Download timed out after N seconds" message — even though subprocess.TimeoutExpired carries the partial output gallery-dl emitted before being killed. Now: - Capture e.stdout / e.stderr (coerced str if bytes; "" if None). - Count files_downloaded from partial stdout via _count_downloaded_files. - Surface a tail-of-stderr hint in error_message so the UI summary tells the operator at a glance whether it was "lots of content" (high count, clean stderr), "stuck retrying" (any count, 429-spam stderr), or "hung silent" (zero count, "no stderr output"). - Promote error_type to RATE_LIMITED when the partial stderr matches RATE_LIMIT_PATTERNS — gallery-dl spinning on retries through the whole 900s window is the timeout-shaped tail of a real rate limit, and the platform cooldown should kick in for the same reason. Existing test_download_timeout strengthened to also assert empty-partial case stays correctly TIMEOUT-classified with no preserved output. New test_download_timeout_preserves_partial_output_and_classifies covers the rich-partial-output → RATE_LIMITED promotion path. DownloadEvent.metadata already flows stdout/stderr/run_stats from DownloadResult via _phase3_persist — no UI change needed; the existing DownloadDetailModal will surface the captured output automatically once the build redeploys. Co-Authored-By: Claude Opus 4.7 (1M context) --- backend/app/services/gallery_dl.py | 52 +++++++++++++++++++++++++++--- tests/test_gallery_dl_service.py | 48 +++++++++++++++++++++++++++ 2 files changed, 96 insertions(+), 4 deletions(-) diff --git a/backend/app/services/gallery_dl.py b/backend/app/services/gallery_dl.py index 2883bd4..c356908 100644 --- a/backend/app/services/gallery_dl.py +++ b/backend/app/services/gallery_dl.py @@ -641,13 +641,57 @@ class GalleryDLService: started_at=started_at, completed_at=completed_at, ) - except subprocess.TimeoutExpired: + except subprocess.TimeoutExpired as e: duration = time.time() - start_time - log.error("Download timeout for %s/%s after %.1fs", artist_slug, platform, duration) + # subprocess.run(text=True) makes these str if non-None, but the + # caller may have raised TimeoutExpired manually with None or + # bytes (tests do); coerce both cases to str. + partial_stdout = e.stdout or "" + partial_stderr = e.stderr or "" + if isinstance(partial_stdout, bytes): + partial_stdout = partial_stdout.decode("utf-8", "replace") + if isinstance(partial_stderr, bytes): + partial_stderr = partial_stderr.decode("utf-8", "replace") + + files_so_far = self._count_downloaded_files(partial_stdout) + written_so_far = [str(p) for p in self._written_paths(partial_stdout)] + stderr_lines = partial_stderr.strip().splitlines() + tail_hint = stderr_lines[-1] if stderr_lines else "no stderr output" + + # If the partial output already shows a rate-limit pattern, the + # timeout was almost certainly gallery-dl spinning on retries — + # promote to RATE_LIMITED so _update_source_health stamps the + # platform cooldown (same code path as a clean-exit rate limit). + # Otherwise stay TIMEOUT and let the captured stdout/stderr + + # files_so_far tell the operator whether it was "lots of + # content" vs "stuck retrying" vs "hung silent". + combined = (partial_stdout + "\n" + partial_stderr).lower() + if any(p in combined for p in self.RATE_LIMIT_PATTERNS): + error_type = ErrorType.RATE_LIMITED + error_message = ( + f"Rate-limited and never completed within " + f"{source_config.timeout}s ({files_so_far} files written)" + ) + else: + error_type = ErrorType.TIMEOUT + error_message = ( + f"Download timed out after {source_config.timeout}s — " + f"{files_so_far} file(s) written; last stderr: {tail_hint}" + ) + + log.error( + "Download timeout for %s/%s after %.1fs (%d files written, " + "last stderr: %s)", + artist_slug, platform, duration, files_so_far, tail_hint, + ) + return DownloadResult( success=False, url=url, artist_slug=artist_slug, platform=platform, - error_type=ErrorType.TIMEOUT, - error_message=f"Download timed out after {source_config.timeout} seconds", + files_downloaded=files_so_far, + written_paths=written_so_far, + stdout=partial_stdout, stderr=partial_stderr, + return_code=-1, # killed by timeout, no real exit code + error_type=error_type, error_message=error_message, duration_seconds=duration, started_at=started_at, completed_at=datetime.now(UTC).isoformat(), diff --git a/tests/test_gallery_dl_service.py b/tests/test_gallery_dl_service.py index f172643..35d2d04 100644 --- a/tests/test_gallery_dl_service.py +++ b/tests/test_gallery_dl_service.py @@ -91,6 +91,54 @@ async def test_download_timeout(gdl, monkeypatch): ) assert result.success is False assert result.error_type == ErrorType.TIMEOUT + # Empty-partial timeout: no preserved output and zero files. + assert result.stdout == "" + assert result.stderr == "" + assert result.files_downloaded == 0 + + +@pytest.mark.asyncio +async def test_download_timeout_preserves_partial_output_and_classifies(gdl, monkeypatch): + """When gallery-dl is killed by timeout but had emitted partial output, + the DownloadResult preserves stdout/stderr, counts files written so + far, and promotes to RATE_LIMITED if the partial stderr shows a rate- + limit pattern (so the platform cooldown kicks in). Without this, the + operator only sees 'timed out' with no clue whether it was 'lots of + content', 'stuck retrying', or 'hung silent'.""" + import subprocess as sp + + # Simulate gallery-dl writing two files, then spinning on 429s. + partial_stdout = ( + "/tmp/images/alice/file_001.jpg\n" + "/tmp/images/alice/file_002.jpg\n" + ) + partial_stderr = ( + "[urllib3] 429 Too Many Requests; sleeping 60s\n" + "[urllib3] 429 Too Many Requests; sleeping 60s\n" + ) + + def _raise(*a, **k): + raise sp.TimeoutExpired( + cmd="gallery-dl", timeout=900, + output=partial_stdout, stderr=partial_stderr, + ) + + monkeypatch.setattr("backend.app.services.gallery_dl.subprocess.run", _raise) + result = await gdl.download( + url="https://patreon.com/alice", artist_slug="alice", platform="patreon", + source_config=SourceConfig(timeout=900), + ) + assert result.success is False + # Partial output preserved on the DownloadResult — _phase3_persist + # writes them into download_event.metadata so the UI can render them. + assert result.stdout == partial_stdout + assert result.stderr == partial_stderr + # Files counted from partial stdout (lines starting with '/'). + assert result.files_downloaded == 2 + # Rate-limit pattern in partial stderr → promoted to RATE_LIMITED so + # _update_source_health stamps the platform cooldown. + assert result.error_type == ErrorType.RATE_LIMITED + assert "Rate-limited" in result.error_message @pytest.mark.asyncio