Merge pull request 'Most-overdue-first scheduling + rich timeout diagnostics' (#36) from dev into main

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(),

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)

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

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