command_log Index Migration Fails on Deploy

Alert / Symptom

After deploying the version that bumps conta-command to 0.2.0-rc.11, new finsta pods crashloop and the rollout stalls. Startup logs show a FlywayException on a global migration — if it happens, most likely the unique index build:

Migration V2_4_0_1221__alter_table_command_log_add_indexes.sql failed
ERROR: could not create unique index "ux_command_log_cmd_uuid"
DETAIL: Key (cmd_uuid)=(...) is duplicated.

Old pods keep serving (rolling update retains them), so this is a stuck deployment, not a live outage — unless a scale-up or full restart forces every pod through the failing migration.

This should now be rare: V2_4_0_1220 cleans command_log before the index builds (see Background). The recovery below is the fallback if a duplicate still slips through.

Background

The 2_4_0 command-log migrations are global, run blocking at startup (migrate-on-startup: true), and a failure aborts boot — there is no per-tenant 503 degradation path here. They run in order:

  • V2_4_0_1220 (finsta-owned) — cleanup, runs first. A normal transactional migration that removes the bad rows so the unique index can build:

    1. delete from command_log where http_method = 'GET' — no GET endpoint in finsta carries a command, so every GET-attributed row is a tracing artifact (see root cause). This alone clears the bulk of the cmd_uuid collisions and always keeps the real mutation row, not the artifact.

    2. dedup any remaining cmd_uuid (e.g. two concurrent PUTs of the same command), keeping the earliest started_at. No cmd_uuid is reassigned.

  • V2_4_0_1221(tenant_id, started_at) index, then create unique index concurrently ux_command_log_cmd_uuid.

  • V2_4_0_1222(started_at) + GIN on attributes.

  • V2_4_0_1223 — partial importance = 'High' + (cmd_class, started_at).

  • V2_4_0_1224 — fix uuid→`text` type in the command_log helper functions.

Root cause of the bad rows

A command-tracing context bleed in conta-command, fixed in 0.2.0-rc.10. The in-flight command was held on the request context; in the reactive filter path it could survive onto a later request handled by the same worker, so a command from a mutation (PUT/POST) got re-logged while an adjacent GET (a refetch/poll fired milliseconds later) was the active request. Signature: same cmd_uuid, byte-identical cmd_body, attributed to a GET, started_at 1–3 ms apart. Because rc.10 confines the command to its originating request, no new bad rows appear after deploy — so V2_4_0_1220 is a one-shot repair, not a recurring cleanup.

Note the rolling-window caveat: "after deploy" means after every old pod is gone, not after the cleanup runs. During the rollout the old (pre-rc.10) pods keep serving traffic with the live bleed, so they can write a fresh GET-artifact duplicate after V2_4_0_1220 has committed and during the V2_4_0_1221 CONCURRENTLY validation window — exactly the kind of duplicate the cleanup just removed. A V2_4_0_1221 failure on the first deploy of this version is therefore possible even with the cleanup in place (low odds: rare bleed × a few-second window), which is precisely why the post-deploy validity check below is mandatory, not optional. Re-running once the rollout has fully completed — all old pods gone, no more bleed writes — is guaranteed clean.

Why the index build is delicate

CREATE INDEX CONCURRENTLY cannot run in a transaction, so V2_4_0_1221 sets executeInTransaction=false. Two consequences if it ever fails:

  • The first (always-safe) index ix_command_log_tenant_id_started_at commits before the unique build, so a failure leaves a partially-applied migration.

  • A failed CONCURRENTLY build leaves an INVALID index occupying the name ux_command_log_cmd_uuid. Because the statement is IF NOT EXISTS, a naive flyway repair + redeploy silently skips the rebuild and reports success while the unique constraint enforces nothing.

These CONCURRENTLY migrations also require Flyway’s session-scoped lock (flyway.postgresql.transactional.lock=false) on the global datasource, set in application-domain.yml. Without it the build hangs rather than fails: CREATE INDEX CONCURRENTLY waits forever on Flyway’s default transaction-scoped lock connection, which sits idle-in-transaction for the whole run. A new startup hang on V2_4_0_1221 (no error, just a stalled migration) is the signature of this setting having been lost — see Flyway lock mode.

Post-deploy verification (do this on every deploy of this version)

A green rollout is not proof the unique index is enforcing. Because of the IF NOT EXISTS silent-skip trap above, an interrupted CONCURRENTLY build (failed unique build, but also a pod killed by a probe/SIGTERM/OOM mid-build) can leave an INVALID index that a later re-run reports as success. There is deliberately no automated guard migration for this: an invalid audit-log index is a degradation, not an outage, and crashlooping the whole app on it would be disproportionate. So once the rollout completes, confirm manually (expect zero rows):

select indexrelid::regclass, indisvalid
from   pg_index
where  indrelid = 'command_log'::regclass and not indisvalid;

If it returns any row, an index is invalid and enforcing/serving nothing — go to Mitigate (drop it, then rebuild), regardless of what flyway_schema_history says.

Impact

  • New pods fail to start; the rollout stalls. The failed migration is recorded success = false in flyway_schema_history.

  • Any index committed earlier in the same migration is harmless to the old version.

  • Naive retry risk: a green re-run can leave cmd_uuid uniqueness unenforced — you think you are protected when you are not.

Diagnose (only if the index migration failed)

The V2_4_0_1220 cleanup should make this unnecessary, but if V2_4_0_1221 still fails:

Confirm the failed migration:

select version, description, success, installed_on
from   flyway_schema_history
where  version = '2.4.0.1221';

Find the remaining duplicate(s) the cleanup did not catch:

select cmd_uuid, count(*), array_agg(id order by started_at) as row_ids
from   command_log
group  by cmd_uuid
having count(*) > 1
order  by count(*) desc;

Check for the leftover INVALID index:

select indexrelid::regclass, indisvalid
from   pg_index
where  indrelid = 'command_log'::regclass and not indisvalid;

Mitigate

  1. Drop the invalid index — do not trust IF NOT EXISTS to rebuild it:

    drop index concurrently if exists ux_command_log_cmd_uuid;
  2. Delete the remaining duplicates, keeping the earliest started_at per cmd_uuid (the same logic as the V2_4_0_1220 cleanup):

    begin;
    delete from command_log c
    using (
        select id, row_number() over (partition by cmd_uuid order by started_at, id) as rn
        from   command_log
        where  cmd_uuid in (select cmd_uuid from command_log group by cmd_uuid having count(*) > 1)
    ) ranked
    where c.id = ranked.id and ranked.rn > 1;
    select cmd_uuid, count(*) from command_log group by cmd_uuid having count(*) > 1;  -- expect zero rows
    commit;
  3. flyway repair to clear the failed migration row, then redeploy so the migration re-runs cleanly.

  4. Verify the index is valid after deploy (expect zero rows):

    select indexrelid::regclass, indisvalid
    from   pg_index
    where  indrelid = 'command_log'::regclass and not indisvalid;
  • finsta-core/finsta-db/src/main/resources/tritt/finsta/migrations/global/V2_4_0_1220__cleanup_command_log_before_unique_index.sql — the cleanup migration.

  • finsta-core/finsta-db/src/main/resources/tritt/finsta/migrations/global/V2_4_0_1221__alter_table_command_log_add_indexes.sql — the unique index migration and its full inline rationale.

  • no.conta.command:conta-command-postgresql — upstream source of the index/helper migrations (adopted, renamed into finsta’s version sequence). The tracing bleed itself was fixed in conta-command 0.2.0-rc.10.

  • Tenant Migration Stuck on Advisory Lock — the other Flyway failure mode (tenant, not global).