Skip to content

SpendLogs queue drops minutes of metering: NUL best-effort race + surrogate regex hole (fix: flush choke-point sanitiser) #157

Closed

Description

@sre-helmcode

Incident (2026-10-08)

nan-spendlogs-queue-error fired on litellm-community. Tracebacks (VictoriaLogs, pods since deleted by KEDA scale-down) classify it as a payload class, not connectivity: 22P05 \u0000 cannot be converted to text. Each firing makes Prisma reject the WHOLE per-minute create_many batch (1-8 rows, mean 5.6, usually belonging to other members) — metering rows are silently lost.

14-day breakdown (218 monitor errors, 2026-09-24..10-08)

class events note
connectivity (pooler) ~141 09-28/29 CNPG incident burst + 4 singles; expected residual
NUL 22P05 (\u0000 in jsonb cast) 8 incl. 3 on 10-08 (07:46 x2 pods, 11:22)
NUL 22021 (raw 0x00 wire byte) 1 10-03
lone surrogate 22P05 16 09-27 x1, 09-28 x8, 10-02 x7 on .6

Root causes (two, distinct)

  1. NUL — the usage hook strips chr(0) request-side (deterministic) and output-side (best-effort); the output side loses when LiteLLM reorders the spend payload. The spend-fix image covers only surrogates.
  2. Regex hole in the surrogate repair (spendlogs-surrogate-and-body-fix.patch, active since -spend-fix.5): the (?<!\\) lookbehind refuses to rewrite a lone \udXXX escape that immediately follows an escaped backslash — exactly a Windows path whose name held a JS-sliced emoji. Reproduced standalone; confirmed live in the 2026-10-02 Prisma error row (...Downloads\\\ud83d\ufffd_Rootwoven_Puppy.3mf, deepseek-v4.1-flash tool_calls from a member's Hermes agent on Windows doing 3D/gcode work).

Fix (authorized in session, 2026-10-08)

Deterministic sanitiser at the flush choke point (proxy/utils.py :: ProxyUpdateSpend.update_spend_logs, the last code before create_many), shipped as spendlogs-chokepoint-sanitize.patch in litellm-community-spend-fix:v1.83.14-spend-fix.7:

  • char-level cleaning of every string leaf of every row: chr(0) dropped, U+D800-U+DFFF -> U+FFFD;
  • serialized-JSON fields (response/messages/metadata/proxy_server_request, jsonb-parsed by Postgres) round-tripped through real characters — json.loads resolves every \uXXXX escape, the char pass cleans what it resolves, json.dumps(ensure_ascii=True) re-emits valid escapes. Unambiguous where a regex is not: \\ud83d (escaped backslash + literal text, traceback repr) survives untouched; \\\ud83d (path backslash + lone-surrogate escape) is repaired.

Acceptance

  • New offline suite tests/spend-fix/test_spendlogs_chokepoint_sanitize.py green (behaviour extracted out of the patch file + wiring)
  • test_imported_patch_guard.py extended (5 patches; synthetic known-good state; guard behaviour check for litellm.proxy.utils)
  • Build rehearsal: strict applier applies the patch against the real upstream file; py_compile; marker greps
  • Image v1.83.14-spend-fix.7 built by CI; values.yaml + rollback-target runbooks updated
  • Post-deploy: 0 queue-monitor errors of the two payload classes; connectivity residual unchanged

Activity

  1. sre-helmcode commented on Oct 9, 2026

    @sre-helmcode
    ContributorAuthor

    Deployed and verified: image v1.83.14-spend-fix.7 rolled out via ArgoCD (merge f1ebeb17), patch markers verified live in prod pods, 0 spend-logs monitor errors since rollout. Reopen if the payload classes reappear; non-blocking follow-ups tracked in the PR review thread.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions