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/backend/app/services/scheduler_service.py b/backend/app/services/scheduler_service.py index 3c42ca1..dd038a4 100644 --- a/backend/app/services/scheduler_service.py +++ b/backend/app/services/scheduler_service.py @@ -116,6 +116,13 @@ async def select_due_sources(session: AsyncSession) -> list[Source]: whose platform is currently in a rate-limit cooldown are excluded — the cooldown is the preventive half of the burst-prevention pair (per-source consecutive_failures backoff handles the offending source itself). + + Ordering: last_checked_at ASC NULLS FIRST, then id. Never-checked + sources go first, then the longest-since-checked, so the most overdue + sources hit Celery's FIFO download queue first. Anti-starvation: if + queue throughput ever falls below the tick rate, a freshly-rerun source + can't keep cutting in line ahead of one that hasn't been checked at all. + Operator-confirmed 2026-05-30. """ rows = (await session.execute( select(Source) @@ -123,6 +130,7 @@ async def select_due_sources(session: AsyncSession) -> list[Source]: .join(Artist, Source.artist_id == Artist.id) .where(Source.enabled.is_(True)) .where(Artist.auto_check.is_(True)) + .order_by(Source.last_checked_at.asc().nulls_first(), Source.id) )).scalars().all() cooldowns = await _platforms_in_cooldown(session) 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 diff --git a/tests/test_scheduler_service.py b/tests/test_scheduler_service.py index 03aab3a..e94c554 100644 --- a/tests/test_scheduler_service.py +++ b/tests/test_scheduler_service.py @@ -233,6 +233,45 @@ async def test_select_ignores_expired_cooldown(db): assert any(s.url == "https://cd-exp" for s in due) +@pytest.mark.asyncio +async def test_select_orders_most_overdue_first_then_id(db): + """Within the due set, sources are ordered by last_checked_at ASC NULLS + FIRST. Combined with Celery FIFO on the download queue, the most-overdue + source in each tick reaches a worker first — preventing the 'a freshly- + rerun source keeps cutting in line ahead of one that's still waiting' + starvation pattern when queue throughput is below the tick population.""" + artist = await _seed_artist(db, interval=60, name="order-test") + now = datetime.now(UTC) + # Newest check — least overdue (but still past its 60s interval). + s_new = Source( + artist_id=artist.id, platform="patreon", url="https://order-new", + enabled=True, consecutive_failures=0, + last_checked_at=now - timedelta(minutes=2), + ) + # Oldest check — most overdue among checked sources. + s_old = Source( + artist_id=artist.id, platform="patreon", url="https://order-old", + enabled=True, consecutive_failures=0, + last_checked_at=now - timedelta(hours=4), + ) + # Never checked — wins the ordering (NULLS FIRST). + s_never = Source( + artist_id=artist.id, platform="patreon", url="https://order-never", + enabled=True, consecutive_failures=0, + ) + db.add_all([s_new, s_old, s_never]) + await db.commit() + + due = await select_due_sources(db) + # Filter to just our test seeds (concurrent tests may add others). + urls = [s.url for s in due if s.url.startswith("https://order-")] + assert urls == [ + "https://order-never", + "https://order-old", + "https://order-new", + ] + + @pytest.mark.asyncio async def test_set_platform_cooldown_upserts(db): """Calling set_platform_cooldown twice on the same platform updates