xbang commited on
Commit
de7d5cb
·
1 Parent(s): 483d909

fix: resolve image generation 429 cascade returning 502 to clients

Browse files

Concurrent /v1/images/edits and /v1/images/generations requests were returning
502 Bad Gateway to clients even though images were successfully generated on
the user's ChatGPT account (quota consumed). Three layered bugs caused every
image request to fail:

Bug A (root cause) - stream parser dropped file_ids
update_conversation_state gated file_id extraction on is_image_tool_event
which requires the full {author.role: tool, metadata.async_task_type:
image_gen} structure. ChatGPT delivers asset_pointer via subsequent patch
events that lack those fields, so file_ids were extracted by regex but
silently discarded. Every image request was forced into the polling
fallback path, which then hammered /backend-api/conversation/{id} and
tripped upstream rate limits.

Fix: open the gate when state.tool_invoked is True (set by an earlier
server_ste_metadata event) OR when the event is itself a patch event whose
payload references asset_pointer / file-service://. The patch-event-only
gate prevents user-controlled message content from injecting fake file ids.
The regex now uses a negative lookahead to exclude the literal "file-service"
URI prefix.

Bug B - polling had zero fault tolerance
_poll_image_results called _get_conversation without try/except. A single
429 / 5xx / network blip killed the entire 180s loop. Production logs also
showed the actual root cause of the spurious 429s: every poll started ~218ms
after the SSE stream closed, but the conversation document is not committed
yet on the upstream and returns a misleading 429 "Too many requests"
instead of 425 Too Early.

Fix: add image_poll_initial_wait_secs (default 10s, +jitter) before the
first poll - image generation takes ~30s anyway. Add exponential backoff
with jitter for 429/5xx/network errors, honoring upstream Retry-After.
All sleeps respect the timeout budget; on exhaustion returns ([], []).

Bug C - upstream error messages were Python repr, not valid JSON
ensure_ok used f-string formatting which produced "body={'detail': 'x'}"
with single quotes - not JSON-parseable by clients.

Fix: introduce UpstreamHTTPError(RuntimeError) subclass exposing
structured fields (status_code, body, retry_after) so callers can branch
programmatically. Format dict/list bodies with json.dumps; truncate long
bodies in the str representation to keep logs readable while preserving
the full body on the exception instance.

Files
services/protocol/conversation.py - relax file_id extraction gate (Bug A)
services/openai_backend_api.py - initial wait + retry in _poll_image_results (Bug B)
utils/helper.py - UpstreamHTTPError + JSON body formatting (Bug C)
services/config.py - image_poll_interval_secs, image_poll_initial_wait_secs

services/config.py CHANGED
@@ -187,6 +187,23 @@ class ConfigStore:
187
  except (TypeError, ValueError):
188
  return 120
189
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
190
  @property
191
  def image_account_concurrency(self) -> int:
192
  try:
@@ -277,6 +294,8 @@ class ConfigStore:
277
  data["refresh_account_interval_minute"] = self.refresh_account_interval_minute
278
  data["image_retention_days"] = self.image_retention_days
279
  data["image_poll_timeout_secs"] = self.image_poll_timeout_secs
 
 
280
  data["image_account_concurrency"] = self.image_account_concurrency
281
  data["auto_remove_invalid_accounts"] = self.auto_remove_invalid_accounts
282
  data["auto_remove_rate_limited_accounts"] = self.auto_remove_rate_limited_accounts
 
187
  except (TypeError, ValueError):
188
  return 120
189
 
190
+ @property
191
+ def image_poll_interval_secs(self) -> float:
192
+ try:
193
+ return max(0.5, float(self.data.get("image_poll_interval_secs", 10.0)))
194
+ except (TypeError, ValueError):
195
+ return 10.0
196
+
197
+ @property
198
+ def image_poll_initial_wait_secs(self) -> float:
199
+ """Image generation upstream takes ~30s; polling immediately wastes requests
200
+ and trips a transient 429. Default 10s gives the conversation document time
201
+ to commit before the first poll."""
202
+ try:
203
+ return max(0.0, float(self.data.get("image_poll_initial_wait_secs", 10.0)))
204
+ except (TypeError, ValueError):
205
+ return 10.0
206
+
207
  @property
208
  def image_account_concurrency(self) -> int:
209
  try:
 
294
  data["refresh_account_interval_minute"] = self.refresh_account_interval_minute
295
  data["image_retention_days"] = self.image_retention_days
296
  data["image_poll_timeout_secs"] = self.image_poll_timeout_secs
297
+ data["image_poll_interval_secs"] = self.image_poll_interval_secs
298
+ data["image_poll_initial_wait_secs"] = self.image_poll_initial_wait_secs
299
  data["image_account_concurrency"] = self.image_account_concurrency
300
  data["auto_remove_invalid_accounts"] = self.auto_remove_invalid_accounts
301
  data["auto_remove_rate_limited_accounts"] = self.auto_remove_rate_limited_accounts
services/openai_backend_api.py CHANGED
@@ -1,5 +1,6 @@
1
  import base64
2
  import os
 
3
  import re
4
  import time
5
  from concurrent.futures import ThreadPoolExecutor
@@ -14,7 +15,7 @@ from PIL import Image
14
  from services.account_service import account_service
15
  from services.config import config
16
  from services.proxy_service import proxy_settings
17
- from utils.helper import ensure_ok, iter_sse_payloads, new_uuid
18
  from utils.log import logger
19
  from utils.pow import build_legacy_requirements_token, build_proof_token, parse_pow_resources
20
  from utils.turnstile import solve_turnstile_token
@@ -639,13 +640,76 @@ class OpenAIBackendAPI:
639
  return sorted(records, key=lambda item: item["create_time"])
640
 
641
  def _poll_image_results(self, conversation_id: str, timeout_secs: float = 120.0) -> tuple[list[str], list[str]]:
642
- """轮询 conversation,直到拿到图片文件 id 或超时。"""
 
 
 
 
 
 
 
 
 
 
643
  start = time.time()
644
  attempt = 0
645
- logger.info({"event": "image_poll_start", "conversation_id": conversation_id, "timeout_secs": timeout_secs})
646
- while time.time() - start < timeout_secs:
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
647
  attempt += 1
648
- conversation = self._get_conversation(conversation_id)
 
 
 
 
 
 
 
 
 
 
 
 
649
  file_ids, sediment_ids = [], []
650
  for record in self._extract_image_tool_records(conversation):
651
  for file_id in record["file_ids"]:
@@ -666,8 +730,17 @@ class OpenAIBackendAPI:
666
  return [], sediment_ids
667
  logger.debug({"event": "image_poll_wait", "conversation_id": conversation_id,
668
  "elapsed_secs": round(time.time() - start, 1)})
669
- time.sleep(4)
670
- logger.info({"event": "image_poll_timeout", "conversation_id": conversation_id, "timeout_secs": timeout_secs})
 
 
 
 
 
 
 
 
 
671
  return [], []
672
 
673
  def _get_file_download_url(self, file_id: str) -> str:
 
1
  import base64
2
  import os
3
+ import random
4
  import re
5
  import time
6
  from concurrent.futures import ThreadPoolExecutor
 
15
  from services.account_service import account_service
16
  from services.config import config
17
  from services.proxy_service import proxy_settings
18
+ from utils.helper import UpstreamHTTPError, ensure_ok, iter_sse_payloads, new_uuid
19
  from utils.log import logger
20
  from utils.pow import build_legacy_requirements_token, build_proof_token, parse_pow_resources
21
  from utils.turnstile import solve_turnstile_token
 
640
  return sorted(records, key=lambda item: item["create_time"])
641
 
642
  def _poll_image_results(self, conversation_id: str, timeout_secs: float = 120.0) -> tuple[list[str], list[str]]:
643
+ """Poll the conversation document until image file ids appear or budget runs out.
644
+
645
+ - Sleeps image_poll_initial_wait_secs first (default 10s, +jitter). ChatGPT
646
+ image generation takes ~30s; polling immediately wastes requests and trips
647
+ a transient 429 the upstream returns within ~200ms of the SSE stream
648
+ closing (the conversation document is not yet committed).
649
+ - Subsequent polls are image_poll_interval_secs apart (default 10s).
650
+ - On upstream 429 / 5xx or network errors, backs off exponentially
651
+ (capped at 16s, +jitter) honoring Retry-After when present.
652
+ - All sleeps stay within timeout_secs; on exhaustion returns ([], []).
653
+ """
654
  start = time.time()
655
  attempt = 0
656
+ interval = float(config.image_poll_interval_secs)
657
+ initial_wait = float(config.image_poll_initial_wait_secs)
658
+ logger.info({
659
+ "event": "image_poll_start",
660
+ "conversation_id": conversation_id,
661
+ "timeout_secs": timeout_secs,
662
+ "initial_wait_secs": initial_wait,
663
+ "interval_secs": interval,
664
+ })
665
+
666
+ def _remaining() -> float:
667
+ return timeout_secs - (time.time() - start)
668
+
669
+ if initial_wait > 0:
670
+ jitter = random.uniform(0, min(2.0, initial_wait * 0.2))
671
+ sleep_for = min(initial_wait + jitter, max(0.0, _remaining()))
672
+ if sleep_for > 0:
673
+ time.sleep(sleep_for)
674
+
675
+ def _retry_sleep(reason: str, status_code: int | None, error: str | None, retry_after: int | None) -> bool:
676
+ # retry_after=0 means "retry immediately" — must not be coerced via falsy check.
677
+ base = retry_after if retry_after is not None else min(2 ** min(attempt, 4), 16)
678
+ backoff = base + random.uniform(0, 0.5)
679
+ remaining = _remaining()
680
+ if remaining <= 0:
681
+ return False
682
+ sleep_for = min(backoff, remaining)
683
+ log_payload: Dict[str, Any] = {
684
+ "event": "image_poll_retry",
685
+ "conversation_id": conversation_id,
686
+ "attempt": attempt,
687
+ "reason": reason,
688
+ "sleep_secs": round(sleep_for, 2),
689
+ }
690
+ if status_code is not None:
691
+ log_payload["status_code"] = status_code
692
+ if error is not None:
693
+ log_payload["error"] = error
694
+ logger.warning(log_payload)
695
+ time.sleep(sleep_for)
696
+ return True
697
+
698
+ while _remaining() > 0:
699
  attempt += 1
700
+ try:
701
+ conversation = self._get_conversation(conversation_id)
702
+ except UpstreamHTTPError as exc:
703
+ if exc.status_code in (429, 500, 502, 503, 504):
704
+ if _retry_sleep("upstream_status", exc.status_code, None, exc.retry_after):
705
+ continue
706
+ break
707
+ raise
708
+ except requests.exceptions.RequestException as exc:
709
+ if _retry_sleep("network", None, str(exc), None):
710
+ continue
711
+ break
712
+
713
  file_ids, sediment_ids = [], []
714
  for record in self._extract_image_tool_records(conversation):
715
  for file_id in record["file_ids"]:
 
730
  return [], sediment_ids
731
  logger.debug({"event": "image_poll_wait", "conversation_id": conversation_id,
732
  "elapsed_secs": round(time.time() - start, 1)})
733
+ wait = min(interval, max(0.0, _remaining()))
734
+ if wait > 0:
735
+ time.sleep(wait)
736
+ logger.info({
737
+ "event": "image_poll_timeout",
738
+ "conversation_id": conversation_id,
739
+ "timeout_secs": timeout_secs,
740
+ "attempts_made": attempt,
741
+ # attempts_made == 0 means the initial_wait consumed the entire budget — no HTTP attempted.
742
+ "initial_wait_exhausted_budget": attempt == 0,
743
+ })
744
  return [], []
745
 
746
  def _get_file_download_url(self, file_id: str) -> str:
services/protocol/conversation.py CHANGED
@@ -362,7 +362,8 @@ def add_unique(values: list[str], candidates: list[str]) -> None:
362
  def extract_conversation_ids(payload: str) -> tuple[str, list[str], list[str]]:
363
  conversation_match = re.search(r'"conversation_id"\s*:\s*"([^"]+)"', payload)
364
  conversation_id = conversation_match.group(1) if conversation_match else ""
365
- file_ids = re.findall(r"(file[-_][A-Za-z0-9]+)", payload)
 
366
  sediment_ids = re.findall(r"sediment://([A-Za-z0-9_-]+)", payload)
367
  return conversation_id, file_ids, sediment_ids
368
 
@@ -381,7 +382,19 @@ def update_conversation_state(state: ConversationState, payload: str, event: dic
381
  conversation_id, file_ids, sediment_ids = extract_conversation_ids(payload)
382
  if conversation_id and not state.conversation_id:
383
  state.conversation_id = conversation_id
384
- if isinstance(event, dict) and is_image_tool_event(event):
 
 
 
 
 
 
 
 
 
 
 
 
385
  add_unique(state.file_ids, file_ids)
386
  add_unique(state.sediment_ids, sediment_ids)
387
  if not isinstance(event, dict):
 
362
  def extract_conversation_ids(payload: str) -> tuple[str, list[str], list[str]]:
363
  conversation_match = re.search(r'"conversation_id"\s*:\s*"([^"]+)"', payload)
364
  conversation_id = conversation_match.group(1) if conversation_match else ""
365
+ # Negative lookahead excludes "file-service" (URI prefix, not a real id).
366
+ file_ids = re.findall(r"(file[-_](?!service\b)[A-Za-z0-9]+)", payload)
367
  sediment_ids = re.findall(r"sediment://([A-Za-z0-9_-]+)", payload)
368
  return conversation_id, file_ids, sediment_ids
369
 
 
382
  conversation_id, file_ids, sediment_ids = extract_conversation_ids(payload)
383
  if conversation_id and not state.conversation_id:
384
  state.conversation_id = conversation_id
385
+ # Accept file_id / sediment_id when any of:
386
+ # 1) event is a complete image_gen tool message
387
+ # 2) prior server_ste_metadata already flipped tool_invoked True (in an image_gen turn)
388
+ # 3) patch event whose payload references asset_pointer / file-service://
389
+ # User messages (type=conversation.message) never satisfy these, so attacker-controlled
390
+ # substrings in user input cannot inject file ids into state.
391
+ is_patch_event = isinstance(event, dict) and event.get("o") == "patch"
392
+ image_context = (
393
+ (isinstance(event, dict) and is_image_tool_event(event))
394
+ or state.tool_invoked is True
395
+ or (is_patch_event and ("asset_pointer" in payload or "file-service://" in payload))
396
+ )
397
+ if image_context:
398
  add_unique(state.file_ids, file_ids)
399
  add_unique(state.sediment_ids, sediment_ids)
400
  if not isinstance(event, dict):
utils/helper.py CHANGED
@@ -27,6 +27,41 @@ def is_image_chat_request(body: dict[str, object]) -> bool:
27
  return isinstance(modalities, list) and "image" in {str(item or "").strip().lower() for item in modalities}
28
 
29
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
30
  def ensure_ok(response: requests.Response, context: str) -> None:
31
  if 200 <= response.status_code < 300:
32
  return
@@ -35,7 +70,13 @@ def ensure_ok(response: requests.Response, context: str) -> None:
35
  body = response.json()
36
  except Exception:
37
  pass
38
- raise RuntimeError(f"{context} failed: status={response.status_code}, body={body}")
 
 
 
 
 
 
39
 
40
 
41
  def sse_json_stream(items) -> Iterator[str]:
 
27
  return isinstance(modalities, list) and "image" in {str(item or "").strip().lower() for item in modalities}
28
 
29
 
30
+ _UPSTREAM_BODY_LOG_LIMIT = 500
31
+
32
+
33
+ class UpstreamHTTPError(RuntimeError):
34
+ """Raised when an upstream HTTP call returns a non-2xx status.
35
+
36
+ Carries structured fields (status_code, body, retry_after) so callers can
37
+ branch on status code instead of string-matching on str(exc). The full
38
+ body is preserved on the instance; the formatted message truncates it
39
+ to keep log lines reasonable.
40
+ """
41
+
42
+ def __init__(
43
+ self,
44
+ context: str,
45
+ status_code: int,
46
+ body: Any,
47
+ retry_after: int | None = None,
48
+ ) -> None:
49
+ self.context = context
50
+ self.status_code = status_code
51
+ self.body = body
52
+ self.retry_after = retry_after
53
+ if isinstance(body, (dict, list)):
54
+ try:
55
+ body_str = json.dumps(body, ensure_ascii=False)
56
+ except (TypeError, ValueError):
57
+ body_str = repr(body)
58
+ else:
59
+ body_str = str(body)
60
+ if len(body_str) > _UPSTREAM_BODY_LOG_LIMIT:
61
+ body_str = body_str[:_UPSTREAM_BODY_LOG_LIMIT] + "…[truncated]"
62
+ super().__init__(f"{context} failed: status={status_code}, body={body_str}")
63
+
64
+
65
  def ensure_ok(response: requests.Response, context: str) -> None:
66
  if 200 <= response.status_code < 300:
67
  return
 
70
  body = response.json()
71
  except Exception:
72
  pass
73
+ retry_after_header = response.headers.get("Retry-After") if hasattr(response, "headers") else None
74
+ retry_after: int | None = None
75
+ if retry_after_header is not None:
76
+ ra_str = str(retry_after_header).strip()
77
+ if ra_str.isdigit():
78
+ retry_after = int(ra_str)
79
+ raise UpstreamHTTPError(context, response.status_code, body, retry_after=retry_after)
80
 
81
 
82
  def sse_json_stream(items) -> Iterator[str]: