#885: repair-job scheduling is timezone-independent (Australia/Sydney loop)

paksenkin: TZ=Australia/Sydney made the Cache Maintenance job (and any repair
job) run every ~5s. Root cause: finished_at is written by SQLite CURRENT_TIMESTAMP
(always UTC) but the scheduler compared it against datetime.now() (naive LOCAL),
so the local↔UTC offset leaked into the elapsed time. Sydney (+11) made every job
look ~11h stale -> always due -> fired every poll; the Americas (behind UTC)
deflated it and masked the bug (why New_York 'worked').

Fix: compare in UTC. now = datetime.now(timezone.utc), and a new _hours_since()
helper parses the naive CURRENT_TIMESTAMP string AS UTC before subtracting — so
the machine timezone never affects scheduling. 5 tests incl. the literal repro
(a just-run job must not be due under Australia/Sydney) and a due-detection
sanity check; 41 repair-worker tests pass, ruff clean.
This commit is contained in:
BoulderBadgeDad 2026-06-18 14:02:09 -07:00
parent 400b35d655
commit b04010a037
2 changed files with 92 additions and 4 deletions

View file

@ -17,7 +17,7 @@ import threading
import time
import uuid
from difflib import SequenceMatcher
from datetime import datetime, timedelta
from datetime import datetime, timedelta, timezone
from typing import Any, Dict, List, Optional, Tuple
from core.metadata_service import (
@ -585,13 +585,29 @@ class RepairWorker:
logger.info("Repair worker thread finished")
@staticmethod
def _hours_since(finished_at_iso: str, now_utc: datetime) -> float:
"""Hours between a stored ``finished_at`` and ``now_utc``, both in UTC.
``finished_at`` is written by SQLite's CURRENT_TIMESTAMP, which is ALWAYS
UTC (and naive). #885: the scheduler compared it against ``datetime.now()``
(naive LOCAL), so the localUTC offset leaked into the elapsed time. For a
zone AHEAD of UTC (Australia/Sydney = +11) every job looked ~11h stale and
fired every poll; behind UTC (the Americas) it just waited too long. Parse
the naive timestamp AS UTC and subtract a UTC ``now`` so scheduling is
timezone-independent."""
dt = datetime.fromisoformat(finished_at_iso)
if dt.tzinfo is None:
dt = dt.replace(tzinfo=timezone.utc)
return (now_utc - dt).total_seconds() / 3600
def _pick_next_job(self) -> Optional[str]:
"""Pick the next job to run based on staleness priority.
Returns job_id of the stalest job whose interval has elapsed,
or None if nothing is due.
"""
now = datetime.now()
now = datetime.now(timezone.utc)
best_job_id = None
best_staleness = -1
@ -613,8 +629,7 @@ class RepairWorker:
continue
try:
last_finished = datetime.fromisoformat(last_run['finished_at'])
elapsed_hours = (now - last_finished).total_seconds() / 3600
elapsed_hours = self._hours_since(last_run['finished_at'], now)
if elapsed_hours < interval_hours:
continue # Not due yet

View file

@ -0,0 +1,73 @@
"""#885: repair-job scheduling must be timezone-independent.
`finished_at` is written by SQLite's CURRENT_TIMESTAMP (always UTC), but the
scheduler compared it against `datetime.now()` (naive LOCAL). With TZ=Australia/
Sydney (UTC+11) every job looked ~11h stale and ran every poll; America/New_York
(behind UTC) masked it. The fix parses finished_at as UTC and compares against a
UTC now, so the machine timezone no longer leaks into elapsed time.
"""
from __future__ import annotations
import time
from datetime import datetime, timezone
import pytest
from core.repair_worker import RepairWorker
# ── pure helper ───────────────────────────────────────────────────────────────
def test_hours_since_treats_naive_timestamp_as_utc():
now = datetime(2026, 6, 18, 6, 0, 0, tzinfo=timezone.utc)
# SQLite CURRENT_TIMESTAMP style: UTC, no tz suffix.
assert RepairWorker._hours_since('2026-06-18 00:00:00', now) == pytest.approx(6.0)
def test_hours_since_handles_aware_timestamp():
now = datetime(2026, 6, 18, 6, 0, 0, tzinfo=timezone.utc)
assert RepairWorker._hours_since('2026-06-18T00:00:00+00:00', now) == pytest.approx(6.0)
def test_hours_since_recent_is_near_zero():
now = datetime(2026, 6, 18, 0, 0, 30, tzinfo=timezone.utc)
assert RepairWorker._hours_since('2026-06-18 00:00:00', now) == pytest.approx(30 / 3600, abs=1e-6)
# ── the #885 repro: a just-run job is never due, regardless of timezone ────────
def _set_tz(monkeypatch, tz):
monkeypatch.setenv('TZ', tz)
try:
time.tzset()
except AttributeError:
pytest.skip('time.tzset() unavailable on this platform')
def test_just_run_job_not_due_under_any_timezone(monkeypatch):
w = RepairWorker.__new__(RepairWorker)
w._jobs = {'cache_evictor': object()}
monkeypatch.setattr(RepairWorker, 'get_job_config',
lambda self, jid: {'enabled': True, 'interval_hours': 6})
# Job finished "now" in UTC (exactly how CURRENT_TIMESTAMP records it).
finished = datetime.now(timezone.utc).strftime('%Y-%m-%d %H:%M:%S')
monkeypatch.setattr(RepairWorker, '_get_last_run',
lambda self, jid: {'finished_at': finished})
# Australia/Sydney is the exact repro; check the Americas + UTC too.
for tz in ('Australia/Sydney', 'America/New_York', 'UTC'):
_set_tz(monkeypatch, tz)
assert w._pick_next_job() is None, f"just-run job wrongly due under TZ={tz}"
def test_stale_job_is_still_picked_under_sydney(monkeypatch):
# Sanity: a genuinely-overdue job IS picked (we didn't break due-detection).
w = RepairWorker.__new__(RepairWorker)
w._jobs = {'cache_evictor': object()}
monkeypatch.setattr(RepairWorker, 'get_job_config',
lambda self, jid: {'enabled': True, 'interval_hours': 6})
# Finished ~10h ago in UTC.
old = datetime(2026, 1, 1, 0, 0, 0, tzinfo=timezone.utc).strftime('%Y-%m-%d %H:%M:%S')
monkeypatch.setattr(RepairWorker, '_get_last_run',
lambda self, jid: {'finished_at': old})
_set_tz(monkeypatch, 'Australia/Sydney')
assert w._pick_next_job() == 'cache_evictor'