Skip to content

fix(proxy-extras): retry P3009 when a peer already recovered the named migration row - #44283

Merged
yuneng-berri merged 4 commits into
mainfrom
litellm_fix_f5ccbf
Oct 3, 2026
Merged

yuneng-berri merged 4 commits into
mainfrom
litellm_fix_f5ccbf

Conversation

@devin-ai-integration

@devin-ai-integration devin-ai-integration Bot commented Oct 2, 2026 •

Copy link
Copy Markdown
Contributor

TLDR

Problem this solves:

  • With 3+ replicas booting together, one can exit on startup
  • It says "Migration completion could not be verified" after a peer already fixed it

How it solves it:

  • Read back the exact ledger row P3009 named, by name and start time
  • If a peer already rolled it back or finished it, log and retry

User Flow

Before: an operator scales a fresh deployment to 3 replicas and one replica crash-loops at startup

  1. The operator starts 3 replicas against one empty database at the same time
  2. Two replicas hit a deadlock on the same migration and one of them rolls the failed attempt back
  3. The third replica, which saw the failure before that rollback, logs "Migration completion could not be verified. LiteLLM startup has stopped." and exits

After: the same rollout comes up with every replica healthy

  1. The operator starts 3 replicas against one empty database at the same time
  2. Two replicas hit a deadlock on the same migration and one of them rolls the failed attempt back
  3. The third replica logs that a peer already recovered the migration, retries, and finishes startup

Screenshots / Proof of Fix

Root cause: when replica C gets P3009 naming a deadlocked row, it reads that row's logs to decide whether to recover. The read only matched rows with finished_at IS NULL AND rolled_back_at IS NULL, so if replica B rolled the row back first, C read nothing and stopped. A plain "any unresolved row for this name" check is not enough either, because B's retry can already have inserted a fresh in-flight row with the same name. P3009 prints the failed row's start time (The <name> migration started at <ts> failed), so both ledger reads now key on migration_name and started_at = <ts>::timestamptz

P3009 for (name, ts):
  row (name, ts) unresolved, logs contain "deadlock detected" -> roll back, retry  (unchanged)
  row (name, ts) rolled back or finished                        -> log info, retry   (new, no rollback issued)
  otherwise (no marker, no row, no DATABASE_URL, no psycopg, DB error) -> same RuntimeError as today

I checked the stderr format and the timestamp match against real Prisma 5.4.2 (the CLI the image ships) and Postgres 16: P3009 prints one started at line per unresolved row with a variable fraction (23:30:00 UTC, 23:31:00.500 UTC, 23:20:56.439594 UTC), and started_at = '<ts>'::timestamptz matches only the reported row, including after it is rolled back and a fresh in-flight row with the same name is inserted

Before (b94eaa6)

New regression tests on main

  1. uv run --no-sync pytest tests/unit/litellm_proxy_extras/test_litellm_proxy_extras_utils.py -k TestConcurrentP3009Recovery -p no:cacheprovider -q
  2. Output:
FFF.                                                                     [100%]
E           RuntimeError: Migration completion could not be verified. LiteLLM startup has stopped.
E           Prisma migration history (migration name and start time):
E           Error: P3009
E           The `20260415120000_health_check_latest_per_model_index` migration started at 2026-10-02 23:20:56.439594 UTC failed
FAILED tests/unit/litellm_proxy_extras/test_litellm_proxy_extras_utils.py::TestConcurrentP3009Recovery::test_a_p3009_row_a_peer_already_recovered_is_retried[rolled-back]
FAILED tests/unit/litellm_proxy_extras/test_litellm_proxy_extras_utils.py::TestConcurrentP3009Recovery::test_a_p3009_row_a_peer_already_recovered_is_retried[rolled-back-beside-a-fresh-in-flight-row]
FAILED tests/unit/litellm_proxy_extras/test_litellm_proxy_extras_utils.py::TestConcurrentP3009Recovery::test_a_p3009_row_a_peer_already_recovered_is_retried[finished]
3 failed, 1 passed, 96 deselected in 4.33s

fresh-3 pooling e2e on main

  1. Image built with docker build --label org.opencontainers.image.revision=b94eaa65c3213bd79015f8e3b3f52c7d44a03c53 -t litellm-docker-database:main -f docker/Dockerfile.database ., Postgres 16 container on port 55432
  2. LITELLM_MIGRATION_TESTS=1 LITELLM_MIGRATION_TEST_IMAGE=litellm-docker-database:main MIGRATION_TEST_ADMIN_URL=postgresql://postgres:postgres@127.0.0.1:55432/postgres MIGRATION_TEST_CONTAINER_ADMIN_URL=postgresql://postgres:postgres@host.docker.internal:55432/postgres MIGRATION_TEST_OUTPUT=<run dir> PYTHONPATH=tests/e2e pytest tests/e2e/migrations/test_pooling.py -k "fresh-3" -vv --tb=short -o addopts= --reruns=0, 5 times
  3. 5 of 5 passed on this box, so the flake did not reproduce locally; the unit test above is the deterministic repro

After (dec1a31)

New regression tests on the PR

  1. Same command as Before
  2. Output: 5 passed, 96 deselected in 3.41s, and the whole mapped file is 101 passed
  3. Mutation check: with the new peer-recovered if block deleted, the same command gives FFF. and 3 failed, 1 passed: the rolled-back, rolled-back-beside-a-fresh-in-flight-row, and finished cases all go red
  4. Second mutation check: with the started_at condition dropped from the recovered-row query (name only), beside-a-recovered-earlier-attempt goes red, so an older rolled-back attempt of the same migration cannot mask a genuinely failed one
  5. Existing tests unchanged and green: litellm-proxy-extras/tests/test_setup_database_fail_fast.py 22 passed, including the P3009 deadlock, empty-logs, unreadable-ledger, and non-deadlock cases, and test_an_interrupted_migration_without_confirmation_stops passes in the mapped file

fresh-3 pooling e2e on the PR head

  1. Image built from 7e562d9 (later commits only touch tests and Final annotations) with docker build --label org.opencontainers.image.revision=7e562d936df41b6b47c9ed5bbb20fb974c645d64 -t litellm-docker-database:pr -f docker/Dockerfile.database ., same Postgres container
  2. LITELLM_MIGRATION_TESTS=1 LITELLM_MIGRATION_TEST_IMAGE=litellm-docker-database:pr MIGRATION_TEST_ADMIN_URL=postgresql://postgres:postgres@127.0.0.1:55432/postgres MIGRATION_TEST_CONTAINER_ADMIN_URL=postgresql://postgres:postgres@host.docker.internal:55432/postgres MIGRATION_TEST_OUTPUT=<run dir> PYTHONPATH=tests/e2e pytest tests/e2e/migrations/test_pooling.py -k "fresh-3" -vv --tb=short -o addopts= --reruns=0, run 5 times in a row
  3. 5 of 5 passed (1 passed, 3 deselected each, 40.83s, 42.85s, 39.16s, 44.20s, 41.57s)
  4. No replica log in either leg contained P3009 or a deadlock, so the race did not fire locally on main or on the PR; the unit tests above cover the race deterministically

Type

🐛 Bug Fix

Caveats (if any)

Low

  • If P3009 stderr ever lacks the started at line, the deadlock rollback is skipped and startup stops as before
    • Prisma always prints it today, verified on 5.4.2
  • The fresh-3 flake did not reproduce on this box at main, 0 of 5

Final Attestation

  • The tests check the right things, including the edge cases, and regressions in the respective real-world customer use-cases are not possible after this PR

Link to Devin session: https://app.devin.ai/sessions/5d9e27bce61e474497c2316aabb474d5
Open in Devin Desktop: https://app.devin.ai/desktop/session/5d9e27bce61e474497c2316aabb474d5?variant=devin

@devin-ai-integration
devin-ai-integration Bot requested a review from a team October 2, 2026 23:43
@devin-ai-integration

devin-ai-integration Bot commented Oct 2, 2026 •

Copy link
Copy Markdown
Contributor Author

I'll fix CI failures and address comments from users with write access. I'll skip comments containing "(aside)".

  • Disable automatic comment, CI, and merge conflict monitoring

@greptile-apps

greptile-apps Bot commented Oct 2, 2026 •

Copy link
Copy Markdown
Contributor

RetriggerConfidence Score: 5/5

[Medium risk] Refactors migration error handling and adds P3009 retry logic.

The current head appears safe to merge, with the previous annotation requirement satisfied

Summary

The PR retries startup when a peer has already recovered the exact migration attempt named by P3009. Both ledger reads match the migration name and start time

  • The latest commit adds the remaining required Final annotations without changing behavior
  • The earlier annotation finding is fully addressed
  • The regression tests include an older recovered attempt beside the named unresolved attempt and still require startup to stop
  • No new actionable issues or rule violations were found

Reviews (3) · Last reviewed commit: "fix(proxy-extras): annotate the migratio..."

Comment thread litellm-proxy-extras/litellm_proxy_extras/utils.py Outdated
Comment thread tests/unit/litellm_proxy_extras/test_litellm_proxy_extras_utils.py
@codecov

codecov Bot commented Oct 2, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.

📢 Thoughts on this report? Let us know!

@devin-ai-integration

Copy link
Copy Markdown
Contributor Author

@greptileai please review the current head 766573a

@devin-ai-integration

Copy link
Copy Markdown
Contributor Author

@greptileai please review the current head dec1a31

@yuneng-berri
yuneng-berri merged commit 8b11b68 into main Oct 3, 2026
103 of 104 checks passed
@yuneng-berri
yuneng-berri deleted the litellm_fix_f5ccbf branch October 3, 2026 01:39
yuneng-berri added a commit that referenced this pull request Oct 3, 2026
…d migration row (#44283) (#44308)

* fix(proxy-extras): retry P3009 when a peer already recovered the named migration row

* fix(proxy-extras): pin P3009 recovery locals as Final and cover a recovered sibling row

* test(proxy-extras): stop the P3009 ledger fakes shadowing the partition detector cursor

* fix(proxy-extras): annotate the migration ledger reader locals as Final

---------

Co-authored-by: devin-ai-integration[bot] <158243242+devin-ai-integration[bot]@users.noreply.github.com>
yuneng-berri added a commit that referenced this pull request Oct 3, 2026
)

* test: repair stale and polluting tests red on scheduled main CI (#44229)

Partial backport to rc/1.104.0: only the owned Redis port, Presidio stored-content check and event-loop lag logging fixes apply here. The other repairs target tests or behavior this line does not have

* test(proxy): stop the proxy_server app fixture leaking LITELLM_LOG

The session app fixture set LITELLM_LOG=ERROR with os.environ.setdefault and never removed it, so later tests on the same xdist worker inherited it. test_drop_params_env_var spawns a subprocess with os.environ and lost the warning it asserts on. Scope the variable to the import with a MonkeyPatch context

* test(secret-detection): give the hand-built redaction request an ASGI path

Since #43975 _read_request_body checks the route path via request.scope, and a scope without path raised KeyError that was swallowed into an empty body, so chat_completion failed with a missing messages parameter. Real ASGI scopes always carry path

* test(integration): isolate litellm callback lists per sdk test

usage-based-routing-v2 Routers register their selector in litellm.callbacks and nothing removes it, not even Router.reset(). The counter TTL and Redis service metrics tests left their selectors behind, and the next usage routing test ran their pre-call checks against its own rpm=1 deployments, raising "Deployment over defined rpm limit". An autouse fixture now gives each sdk test copies of the callback lists and restores the originals afterwards

* test(integration): keep the owner-lookup fault proxy off the shared read replica

The owned proxy points DATABASE_URL at a scratch database but inherited
DATABASE_URL_READ_REPLICA from the replica job, so auth read the shared
database and rejected the freshly created key with token_not_found_in_db.
Drop the replica variable like the other scratch-database owned proxies

* test(integration): request every seeded key in the team owner breakdown

The aggregated team activity endpoint now caps breakdown.api_keys at the top
100 keys by default (#43398), so the 300 seeded keys came back as 100 rows.
The test guarantees each key is reported with its own owner, so ask for an
api_key_limit that covers all seeded keys

* test(integration): give every owned Redis its own port in the redis-cache container

On CircleCI every owned Redis ran on the fixed port 16379 inside the shared
redis-cache container. When an earlier server still held that port, the new
one failed to bind, readiness pinged the old server, the pidfile read failed
and cleanup then reported "Owned Redis still serves after shutdown"

Reserve an ephemeral port for the docker-exec path the same way the local
binary path already does, and refuse to start when something already serves
the chosen port so the failure names the real cause

* test(e2e): skip the Vertex Mistral partner case the e2e project cannot reach

The e2e Vertex project gets a 404 publisher model not found for vertex_ai/mistral-small-2503, so the case can only fail

* test(e2e): skip the Vertex gpt-oss partner case the e2e project never serves

vertex_ai/openai/gpt-oss-120b-maas has hit a 60s read timeout with no response headers on every run in the e2e Vertex project since the case was ported, and no other Vertex partner chat model passes there to switch to

* test(e2e): check only stored message content for a leaked card number

The Presidio spend-log check ran the card-number pattern over the whole serialized response, so a Luhn-valid usage.cost float (0.0003466000000000001) failed the streaming /v1/messages case although the stored content was <CREDIT_CARD>. The check now reads the content and text strings of the stored response, which is where a raw card would land, and still requires the placeholder there

* test(e2e): assert the proxy decodes token-array embeddings for titan

The port in #44120 carried over a legacy SDK-direct test that expected Bedrock to reject token ids with a 400. Through the proxy, /embeddings decodes token arrays to text for providers that cannot embed tokens, so titan answers 200. The test now sends a token array and its decoded sentence and requires the two vectors to match, which fails if the proxy stops decoding or decodes with the wrong tokenizer

* test(e2e): run the Bedrock extended-thinking round trip on a model that honors enabled thinking

us.anthropic.claude-sonnet-5-5 is adaptive-only, so litellm sends thinking.type=enabled with a 1024 budget as adaptive with low effort, and Bedrock returned no reasoning blocks on 5 of 5 identical Converse calls (boto3 direct agreed). us.anthropic.claude-sonnet-4-6 accepts the legacy shape verbatim and returned reasoning on 5 of 5. The non-thinking Bedrock case stays on sonnet-5-5

* test(proxy): stop unit modules forcing DEBUG logging into the event-loop lag tests

Five tests/unit modules set verbose_proxy_logger to DEBUG at import, so every xdist worker that collected them logged the 2.4MB pass-through response from a worker thread, and secret redaction of that line held the GIL for ~0.8s+ inside the timed window. The lag tests now pin the LiteLLM loggers to WARNING and freeze gc while timing, and the module-level DEBUG overrides are removed

* test(e2e): cite the tokenizer and date behind the titan token-array fixture

* test(e2e): let migration seed replicas finish their request-log indexes before cloning

Since #43948 a serving proxy builds the two LiteLLM_SpendLogs indexes on a background thread after it reports ready. The seed fixtures stopped the replica at readiness, so every cloned legacy database lacked an index no real deployment would be missing, and the v2 baseline diff refused it. Seeds now wait until both indexes exist and are valid in the database's schema

* test(passthrough): give the pass-through MockRequest an httpx URL and ASGI scope

* test(integration): ignore foreign allow_all_keys MCP servers in the access matrix tool list

test_toolset_gateway_url_serves_a_team_granted_toolset_to_a_key_without_its_own_grant (#43908) registers an allow_all_keys server on the shared gateway, and allow_all_keys servers are listed to every key by design, so a matrix case running on another xdist worker at the same time saw its tools. The matrix now drops tools of allow_all_keys servers it did not create, read from LiteLLM_MCPServerTable before and after listing, and still compares everything else exactly

(cherry picked from commit 9b5562f)

* fix(proxy-extras): retry P3009 when a peer already recovered the named migration row (#44283)

* fix(proxy-extras): retry P3009 when a peer already recovered the named migration row

* fix(proxy-extras): pin P3009 recovery locals as Final and cover a recovered sibling row

* test(proxy-extras): stop the P3009 ledger fakes shadowing the partition detector cursor

* fix(proxy-extras): annotate the migration ledger reader locals as Final

---------

Co-authored-by: yuneng <yuneng@berri.ai>
(cherry picked from commit 8b11b68)

---------

Co-authored-by: devin-ai-integration[bot] <158243242+devin-ai-integration[bot]@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant