fix: retry asset downloads on 5xx and recover them across runs
An asset download is two hops — mint a signed URL, then fetch the bytes — and only the first went through _make_request. The second was a bare session.request with no 5xx handling, which lost two images in the 2026-10-20 09:00 run: one to a 500 the retried first hop had already recovered from, one to a 503. Both re-downloaded cleanly an hour later (106 KB and 1.3 MB), so the bytes were there all along. A third asset timed out and aborted its whole conversation. curl_cffi's RequestException subclasses OSError, so the un-wrapped timeout slipped past resolve_media's except ProviderError into the export loop's except OSError and was reported as "File write failed for conversation 6a945155" — a conversation that had already downloaded ~20 images. Nothing was wrong with any file write. The retry loop is factored out of _make_request into _send_with_retries, which returns the raw response so a bytes caller gets the same handling as a JSON one. Hop 2 goes through it: 5xx retried, Retry-After honoured, timeouts surfacing as ProviderError for resolve_media to placeholder. The hop is now logged, which it never was. Assets get their own ladder — an immediate retry, then ~2/4/8/16s with jitter kept, since a storage incident fails many assets at once — bounded by a per-asset wall-clock budget, because the timeout case costs 40s a go. Beyond the retry: - Transient failures (5xx, timeout, network) are recorded as pending_media so a later run re-fetches just that asset; capped at 3 runs. 404/403 stay permanent — settled 2026-08-17 for 19 assets. - A circuit breaker stops downloads after 5 consecutive transient failures, recording the rest as retryable. Permanent failures never trip it; any success resets the streak. - Media failures now appear in the set ids. The run that lost two assets pushed a clean "OK". Keeps FUTURE.md's per-conversation cache reset correctly closed. The README split (FUTURE.md §2) stays otial enough to justify breaking every anchor link. 37 new tests (414 passing). Verified live: both lost assets recovered, doctor green, a read-only chatgpt dns. The cross-run retry and breaker are unit-tested only. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/cwa7qnGp Claude-Session: https://claude.ai/code/session_012gCWSknsWvhLnMFwa7qnGp
This commit is contained in:
JesseMarkowitz
co-authored by
Claude Opus 5
Claude Opus 5
parent
805689c649
commit
8c3e00a520
@@ -1399,6 +1399,8 @@ class TestDeletedAssetReporting:
|
||||
"""The probe costs a request — it must not fire on a good download."""
|
||||
class _Bytes:
|
||||
status_code = 200
|
||||
ok = True
|
||||
reason = "OK"
|
||||
content = b"data"
|
||||
headers = {"content-type": "image/png"}
|
||||
|
||||
@@ -1506,3 +1508,236 @@ class TestProjectAttribution:
|
||||
with caplog.at_level(logging.INFO):
|
||||
p.normalize_conversation(self._raw(gizmo_id="g-p-known"))
|
||||
assert not [r for r in caplog.records if "not in CHATGPT_PROJECT_IDS" in r.message]
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Asset download retries. Measured 2026-10-20 in one scheduled run:
|
||||
#
|
||||
# 09:04:05 .../files/<id>/download → 500 Retry 1/3 in 2.2s
|
||||
# 09:04:17 → 500 Retry 2/3 in 4.3s
|
||||
# 09:04:32 → 500 Retry 3/3 in 9.1s
|
||||
# 09:04:42 → 200 ← metadata hop recovered
|
||||
# 09:04:47 WARNING Signed URL returned HTTP 500 ← second hop, no retry
|
||||
#
|
||||
# The metadata hop went through _make_request and won; the signed-URL hop was
|
||||
# a bare request and lost on its first try. A second asset lost the same way
|
||||
# to a 503, and a third timed out — and because curl_cffi's RequestException
|
||||
# subclasses OSError, that timeout escaped resolve_media's `except
|
||||
# ProviderError` and was reported by the export loop as "File write failed",
|
||||
# aborting a conversation that had already downloaded ~20 images.
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
class TestAssetDownloadRetries:
|
||||
class _Resp:
|
||||
def __init__(self, status=200, payload=None, content=b"", headers=None):
|
||||
self.status_code = status
|
||||
self.ok = 200 <= status < 400
|
||||
self.reason = ""
|
||||
self.content = content
|
||||
self.text = ""
|
||||
self.headers = headers or {}
|
||||
self._payload = payload
|
||||
|
||||
def json(self):
|
||||
if self._payload is None:
|
||||
raise ValueError("not json")
|
||||
return self._payload
|
||||
|
||||
class _ScriptedSession:
|
||||
"""Returns scripted responses in order; an Exception entry is raised."""
|
||||
|
||||
def __init__(self, script):
|
||||
self.script = list(script)
|
||||
self.requests = []
|
||||
self.headers = {}
|
||||
|
||||
def request(self, method, url, **kwargs):
|
||||
self.requests.append((method, url, kwargs))
|
||||
item = self.script.pop(0)
|
||||
if isinstance(item, BaseException):
|
||||
raise item
|
||||
return item
|
||||
|
||||
def _provider(self, script):
|
||||
from src.providers.chatgpt import ChatGPTProvider
|
||||
|
||||
p = ChatGPTProvider.__new__(ChatGPTProvider)
|
||||
p._request_delay = 0
|
||||
p._last_request_at = None
|
||||
p._session = self._ScriptedSession(script)
|
||||
return p
|
||||
|
||||
def _meta(self):
|
||||
"""Hop 1: metadata response carrying the signed download_url."""
|
||||
return self._Resp(payload={"download_url": "https://files.example/signed"})
|
||||
|
||||
def test_signed_url_5xx_is_retried_and_recovers(self, monkeypatch):
|
||||
"""The exact 2026-10-20 failure: hop 2 500s once, then succeeds."""
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
p = self._provider([
|
||||
self._meta(),
|
||||
self._Resp(500),
|
||||
self._Resp(200, content=b"PNGDATA", headers={"content-type": "image/png"}),
|
||||
])
|
||||
content, mime, _ = p.download_asset("sediment://file_x")
|
||||
assert content == b"PNGDATA"
|
||||
assert mime == "image/png"
|
||||
assert len(p._session.requests) == 3, "hop 2 must be retried, not abandoned"
|
||||
|
||||
def test_signed_url_503_is_retried(self, monkeypatch):
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
p = self._provider([
|
||||
self._meta(),
|
||||
self._Resp(503),
|
||||
self._Resp(200, content=b"OK", headers={"content-type": "image/png"}),
|
||||
])
|
||||
assert p.download_asset("sediment://file_x")[0] == b"OK"
|
||||
|
||||
def test_signed_url_timeout_raises_provider_error_not_oserror(self, monkeypatch):
|
||||
"""The conversation-killer: a hop-2 timeout must be a ProviderError.
|
||||
|
||||
curl_cffi's RequestException is an OSError subclass, so an un-wrapped
|
||||
timeout here bypassed resolve_media's handler and was caught by the
|
||||
export loop's `except OSError` as "File write failed".
|
||||
"""
|
||||
from curl_cffi.requests.exceptions import Timeout
|
||||
from src.providers.base import ProviderError
|
||||
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
assert issubclass(Timeout, OSError), "premise of this test"
|
||||
|
||||
p = self._provider([self._meta()] + [Timeout("timed out")] * 8)
|
||||
with pytest.raises(ProviderError) as exc:
|
||||
p.download_asset("sediment://file_x")
|
||||
assert "Signed URL" in str(exc.value.original), "must name the failing hop"
|
||||
|
||||
def test_which_hop_failed_stays_in_the_message(self, monkeypatch):
|
||||
"""Hop 1 vs hop 2 fail for different reasons; the message must say which."""
|
||||
from src.providers.base import ProviderError
|
||||
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
p = self._provider([self._meta()] + [self._Resp(500)] * 8)
|
||||
with pytest.raises(ProviderError) as exc:
|
||||
p.download_asset("sediment://file_x")
|
||||
detail = str(exc.value.original)
|
||||
assert detail.startswith("Signed URL:")
|
||||
assert "500" in detail
|
||||
|
||||
def test_hop_two_is_paced_once_per_attempt_not_twice(self, monkeypatch):
|
||||
"""Pacing twice per asset would add REQUEST_DELAY to every image."""
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
p = self._provider([
|
||||
self._meta(),
|
||||
self._Resp(200, content=b"X", headers={"content-type": "image/png"}),
|
||||
])
|
||||
calls = []
|
||||
real_pace = p._pace
|
||||
monkeypatch.setattr(p, "_pace", lambda: calls.append(1) or real_pace())
|
||||
p.download_asset("sediment://file_x")
|
||||
assert len(calls) == len(p._session.requests) == 2
|
||||
|
||||
|
||||
class TestRetryLadder:
|
||||
def test_immediate_first_retry_costs_nothing(self):
|
||||
from src.providers.base import BaseProvider
|
||||
|
||||
assert BaseProvider._backoff_wait(None, 1, immediate_first=True) == 0.0
|
||||
|
||||
def test_ladder_shifts_down_so_it_reads_0_2_4_8_16(self):
|
||||
from src.providers.base import BaseProvider
|
||||
|
||||
for attempt, lo in ((2, 2), (3, 4), (4, 8), (5, 16)):
|
||||
wait = BaseProvider._backoff_wait(None, attempt, immediate_first=True)
|
||||
assert lo <= wait <= lo * 1.3, f"attempt {attempt} → {wait}"
|
||||
|
||||
def test_jitter_is_never_dropped(self):
|
||||
"""A storage incident fails many assets; un-jittered retries sync up."""
|
||||
from src.providers.base import BaseProvider
|
||||
|
||||
waits = {
|
||||
BaseProvider._backoff_wait(None, 3, immediate_first=True)
|
||||
for _ in range(25)
|
||||
}
|
||||
assert len(waits) > 1
|
||||
|
||||
def test_conversation_api_ladder_is_unchanged(self):
|
||||
from src.providers.base import BaseProvider
|
||||
|
||||
assert 2 <= BaseProvider._backoff_wait(None, 1) <= 2.6
|
||||
assert 4 <= BaseProvider._backoff_wait(None, 2) <= 5.2
|
||||
|
||||
def test_retry_after_wins_over_the_immediate_retry(self):
|
||||
"""A server naming a time knows better than we do; 503s often do."""
|
||||
from src.providers.base import BaseProvider
|
||||
|
||||
class _R:
|
||||
headers = {"Retry-After": "7"}
|
||||
|
||||
assert BaseProvider._backoff_wait(_R(), 1, immediate_first=True) == 7.0
|
||||
|
||||
|
||||
class TestMediaTimeBudget:
|
||||
def test_budget_refuses_a_wait_it_cannot_afford(self, monkeypatch):
|
||||
"""Bounds the timeout case, which costs 40s a go and has no cheap end."""
|
||||
from src.providers.base import ProviderError
|
||||
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
p = TestAssetDownloadRetries()._provider([
|
||||
TestAssetDownloadRetries._Resp(500) for _ in range(9)
|
||||
])
|
||||
# First backoff is 2-2.6s, which does not fit in a 1s budget.
|
||||
with pytest.raises(ProviderError):
|
||||
p._send_with_retries(
|
||||
"GET", "https://files.example/signed",
|
||||
max_retries=5, time_budget=1.0,
|
||||
)
|
||||
assert len(p._session.requests) == 1
|
||||
|
||||
def test_budget_still_allows_the_free_immediate_retry(self, monkeypatch):
|
||||
"""The 0s retry costs nothing, so a small budget can still fund it."""
|
||||
from src.providers.base import ProviderError
|
||||
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
p = TestAssetDownloadRetries()._provider([
|
||||
TestAssetDownloadRetries._Resp(500) for _ in range(9)
|
||||
])
|
||||
with pytest.raises(ProviderError):
|
||||
p._send_with_retries(
|
||||
"GET", "https://files.example/signed",
|
||||
max_retries=5, immediate_first_retry=True, time_budget=1.0,
|
||||
)
|
||||
# Attempt 1, free retry, then the 2s backoff exceeds what is left.
|
||||
assert len(p._session.requests) == 2
|
||||
|
||||
def test_read_timeout_is_clamped_to_the_remaining_budget(self, monkeypatch):
|
||||
"""So a final attempt cannot overrun the budget by a whole timeout."""
|
||||
from src.providers.base import ProviderError
|
||||
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
p = TestAssetDownloadRetries()._provider([
|
||||
TestAssetDownloadRetries._Resp(500) for _ in range(9)
|
||||
])
|
||||
with pytest.raises(ProviderError):
|
||||
p._send_with_retries(
|
||||
"GET", "https://files.example/signed",
|
||||
max_retries=5, time_budget=3.0, timeout=(10, 20),
|
||||
)
|
||||
_, _, kwargs = p._session.requests[0]
|
||||
connect_to, read_to = kwargs["timeout"]
|
||||
assert connect_to == 10
|
||||
assert read_to <= 3.0, "read timeout must not exceed the budget"
|
||||
|
||||
def test_without_a_budget_the_full_ladder_runs(self, monkeypatch):
|
||||
from src.providers.base import ProviderError
|
||||
|
||||
monkeypatch.setattr("src.providers.base.time.sleep", lambda s: None)
|
||||
p = TestAssetDownloadRetries()._provider([
|
||||
TestAssetDownloadRetries._Resp(500) for _ in range(9)
|
||||
])
|
||||
with pytest.raises(ProviderError):
|
||||
p._send_with_retries(
|
||||
"GET", "https://files.example/signed",
|
||||
max_retries=5, immediate_first_retry=True,
|
||||
)
|
||||
assert len(p._session.requests) == 6, "5 retries = 6 attempts"
|
||||
|
||||
Reference in New Issue
Block a user