diff --git a/internal/database/postgres/migrations/migrate.go b/internal/database/postgres/migrations/migrate.go index 26bc8a42e..59a433bcf 100644 --- a/internal/database/postgres/migrations/migrate.go +++ b/internal/database/postgres/migrations/migrate.go @@ -332,43 +332,48 @@ func maybeForceMigrationVersion(m *migrate.Migrate) error { return nil } -// maybeAutoHealDirty self-recovers a dirty schema_migrations row: when the DB -// is dirty it calls m.Force(currentRecordedVersion) to clear the dirty flag at -// the version golang-migrate last recorded, and the caller's subsequent m.Up() -// re-applies only the still-pending migrations. This runs ONCE per boot, so a -// cold start that finds a dirty DB self-heals instead of staying broken until -// an operator manually forces a version (the multi-hour outage this addresses). +// maybeAutoHealDirty detects a dirty schema_migrations row and, when +// CUDLY_MIGRATION_AUTOHEAL is enabled (the default), returns a loud error with +// recovery instructions rather than silently clearing the dirty flag. // -// DEFAULT-ON (not opt-in). The whole outage was "the app started but stayed -// broken for hours needing a manual force", and TestMigrations_FullStackIdempotent -// proves re-running migrations is safe, so auto-heal runs by default. Set the -// escape hatch CUDLY_MIGRATION_AUTOHEAL=false (any strconv.ParseBool falsey -// value) to disable it in an environment whose migrations are not idempotent. -// When disabled, a dirty DB is left untouched here and surfaces as the usual -// "database is in dirty state" error after Up(); the caller (app.go ensureDB) -// still FAIL-OPENS on that error so the app always starts -- a broken schema -// surfaces via /health + the CloudWatch alarm, never via a crash-loop. +// WHY NOT AUTO-CLEAR: golang-migrate records version=N, dirty=true BEFORE +// running N's SQL. Every migration in this repository is transactional +// (TestMigrationsAreTransactional). When a migration is interrupted (Lambda +// timeout, connection drop, context cancellation), the SQL transaction is +// rolled back completely -- N's effects are ABSENT from the schema -- but the +// dirty flag persists. The previous Force(N)+Up() auto-heal treated such a +// rolled-back migration as fully applied and silently continued at N+1, +// permanently losing N's DDL while schema_migrations reported success (the +// 000074 divergence class: columns reported as present by the version record +// but absent from the actual schema, causing 42703 errors at runtime). // -// CRITICAL -- Force to the CURRENT recorded version, NEVER a lower one. Up() -// then applies only the pending tail. Forcing BELOW already-applied migrations -// would re-run seed/data migrations, and some RAISE on a second run (e.g. -// 000059 errors with "a group named Purchaser already exists with a different -// id" because 000064 already relocated it). Force(current)+Up() is the only -// safe shape; Force(lower) would turn a recoverable dirty state into a hard -// failure. (Proven live during the incident.) +// The "genuine narrow race" (N's SQL committed successfully but the subsequent +// dirty=false update failed, e.g. due to a Lambda timeout between those two +// steps) also results in dirty=true at N, but in that case N's effects ARE +// present. Without per-migration effect probes the two scenarios are +// indistinguishable from schema_migrations alone, so we take the conservative +// path: fail loud so the migration-failed alarm fires and an operator can +// inspect the actual schema before choosing the correct recovery target. // -// IDEMPOTENCY INVARIANT: Force(version) clears the dirty marker WITHOUT rolling -// back the partial effects of the interrupted migration, so when Up() re-runs -// the pending tail those migrations must tolerate already-applied state -// (CREATE ... IF NOT EXISTS, DROP ... IF EXISTS, DO-blocks that no-op when the -// target already exists). The full-stack idempotency test guards this for the -// whole directory as migrations are added. +// RECOVERY (via CUDLY_FORCE_MIGRATION_VERSION -- see maybeForceMigrationVersion): +// - If migration N's SQL effects ARE confirmed present in the schema: set +// CUDLY_FORCE_MIGRATION_VERSION=N. Force(N) clears the dirty flag and +// the subsequent Up() continues at N+1. +// - If migration N's SQL effects are NOT present (rolled back): set +// CUDLY_FORCE_MIGRATION_VERSION=N-1. Force(N-1) resets state to N-1 and +// the subsequent Up() re-applies N then continues. // -// CUDLY_FORCE_MIGRATION_VERSION still takes precedence: it runs earlier and -// leaves the row clean, so this is a no-op when both are set. If auto-heal -// itself fails (e.g. Force errors, or the re-applied Up() still fails), the -// error propagates to ensureDB, which fail-opens AND records the failure so -// the migration-failed alarm fires -- the app still starts. +// FAIL-OPEN: the app still starts on this error. ensureDB (app.go) swallows +// migration failures and the broken schema surfaces via /health + the +// CloudWatch alarm, never via a crash-loop. +// +// Set CUDLY_MIGRATION_AUTOHEAL=false to bypass this check entirely; the dirty +// state then surfaces as the generic "failed to run migrations: migration: N is +// dirty" error from the post-Up() check in RunMigrations, without recovery +// guidance. +// +// CUDLY_FORCE_MIGRATION_VERSION takes precedence: it runs before this function +// and leaves the row clean, so this function is a no-op when both are set. // // The ParseBool gate is duplicated from internal/server.getEnvBool rather than // imported because the migrations package must not depend on internal/server, @@ -390,14 +395,29 @@ func maybeAutoHealDirty(m *migrate.Migrate) error { return nil } - // Force the CURRENT recorded version (never lower -- see the doc comment), - // then let the caller's Up() re-apply only the pending tail. - log.Printf("Database is DIRTY at version %d: auto-heal forcing the current version %d to clear the dirty flag, then re-applying pending migrations (set CUDLY_MIGRATION_AUTOHEAL=false to disable)", version, version) - if err := m.Force(int(version)); err != nil { //nolint:gosec // G115: uint->int for migration version number; migration versions are always small positive integers - return fmt.Errorf("auto-heal: failed to force version %d to clear dirty flag: %w", version, err) - } - log.Printf("Auto-heal cleared dirty flag at version %d; proceeding to re-apply pending migrations", version) - return nil + // Cannot safely determine whether migration N's SQL effects landed: + // - Common case (interrupted/rolled back): effects ABSENT; clearing the + // dirty flag would silently record the never-applied migration as + // complete, hiding the missing DDL from schema_migrations forever. + // - Rare race (N committed, dirty=false update failed): effects PRESENT; + // clearing dirty would be safe -- but we cannot detect this case + // without per-migration effect probes. + // Conservative choice: fail loud so the alarm fires and an operator + // inspects the actual schema before choosing the recovery target. + log.Printf("Database is DIRTY at version %d: auto-heal cannot safely clear the dirty flag without "+ + "knowing whether migration %d's SQL effects were applied. Inspect the schema and redeploy "+ + "with CUDLY_FORCE_MIGRATION_VERSION to recover. Set CUDLY_MIGRATION_AUTOHEAL=false to suppress this check.", + version, version) + return fmt.Errorf( + "auto-heal: migration %d is dirty; cannot verify whether its SQL effects were applied -- "+ + "clearing the dirty flag risks recording a never-applied migration as complete "+ + "(silent schema divergence). Inspect the actual schema, then redeploy with: "+ + "CUDLY_FORCE_MIGRATION_VERSION=%d if migration %d's effects are confirmed present "+ + "(Force clears dirty, Up() continues at %d), or "+ + "CUDLY_FORCE_MIGRATION_VERSION=%d if the migration was NOT applied and must be re-run "+ + "(Force resets to %d, Up() re-applies %d); "+ + "set CUDLY_MIGRATION_AUTOHEAL=false to suppress this check and surface the raw dirty error", + version, version, version, version+1, version-1, version-1, version) } // autoHealEnabled reports whether dirty auto-heal should run. DEFAULT-ON: it diff --git a/internal/database/postgres/migrations/migrate_autoheal_test.go b/internal/database/postgres/migrations/migrate_autoheal_test.go index f3b248a12..11dfdb1d2 100644 --- a/internal/database/postgres/migrations/migrate_autoheal_test.go +++ b/internal/database/postgres/migrations/migrate_autoheal_test.go @@ -27,51 +27,66 @@ func markDirty(ctx context.Context, t *testing.T, container *testhelpers.Postgre // TestMigrations_AutoHealDirty covers the DEFAULT-ON CUDLY_MIGRATION_AUTOHEAL // behavior from migrate.go: // -// - BY DEFAULT (flag unset), a dirty DB is healed: Force(current) clears the -// dirty flag and the subsequent Up() reaches head clean -- a cold start -// self-recovers without operator intervention. -// - With CUDLY_MIGRATION_AUTOHEAL=false, auto-heal is disabled and a dirty DB -// still returns an error with the dirty flag left intact (escape hatch). +// - BY DEFAULT (flag unset), a dirty DB fails loud with a descriptive error +// that includes recovery instructions (CUDLY_FORCE_MIGRATION_VERSION). The +// dirty flag is left intact. The app still starts (fail-open via ensureDB), +// and the CloudWatch alarm fires. Operators inspect the actual schema to +// choose the correct force target. +// - With CUDLY_MIGRATION_AUTOHEAL=false, auto-heal is bypassed and a dirty DB +// surfaces the generic Up() error ("migration: N is dirty") without recovery +// guidance. // -// In both cases the Force target is the CURRENT recorded version (never lower), -// which is the only safe shape -- forcing below already-applied migrations -// would re-run guarded seed migrations that raise on a second run. +// WHY THE BEHAVIOR CHANGED FROM "AUTO-CLEAR" TO "FAIL-LOUD": golang-migrate +// sets dirty=true BEFORE running migration N's SQL. If the migration is +// interrupted (Lambda timeout, etc.) the SQL transaction is rolled back but the +// dirty flag persists -- N's effects are ABSENT. The previous Force(N)+Up() path +// treated the rolled-back migration as applied and skipped its DDL forever +// (000074 divergence class). There is also a narrow race where N commits but +// the dirty=false update fails, leaving dirty=true WITH effects present. These +// two cases are indistinguishable without per-migration effect probes, so the +// conservative choice is to refuse to auto-clear and let an operator confirm +// the schema state before forcing. func TestMigrations_AutoHealDirty(t *testing.T) { ctx := context.Background() migrationsPath := getMigrationsPath() - t.Run("by default a dirty DB self-heals and head is reached", func(t *testing.T) { + t.Run("by default a dirty DB fails loud with recovery instructions", func(t *testing.T) { container, err := testhelpers.SetupPostgresContainer(ctx, t) require.NoError(t, err) defer container.Cleanup(ctx) pool := container.DB.Pool() - // Migrate to head, then simulate an interrupted migration by forcing - // the dirty flag at the head version. + // Migrate to head, then simulate a dirty state by forcing the dirty + // flag at the head version. require.NoError(t, migrations.RunMigrations(ctx, pool, migrationsPath, "", "")) headVersion, _, err := migrations.GetMigrationVersion(ctx, pool, migrationsPath) require.NoError(t, err) require.Greater(t, headVersion, uint(0)) markDirty(ctx, t, container, headVersion) - // Sanity: confirm the DB is genuinely dirty before healing. + // Sanity: confirm the DB is genuinely dirty before the next run. _, dirtyBefore, err := migrations.GetMigrationVersion(ctx, pool, migrationsPath) require.NoError(t, err) - require.True(t, dirtyBefore, "precondition: DB must be dirty before the heal run") + require.True(t, dirtyBefore, "precondition: DB must be dirty before the run") - // Flag explicitly unset: auto-heal is default-on, so the re-run must - // self-recover. t.Setenv auto-restores and forbids t.Parallel(). + // Default-on auto-heal must fail loud (conservative: cannot verify effects). + // t.Setenv auto-restores and forbids t.Parallel(). t.Setenv("CUDLY_MIGRATION_AUTOHEAL", "") - require.NoError(t, migrations.RunMigrations(ctx, pool, migrationsPath, "", ""), - "default-on auto-heal should clear the dirty flag and reach head without error") - - versionAfter, dirtyAfter, err := migrations.GetMigrationVersion(ctx, pool, migrationsPath) - require.NoError(t, err) - assert.False(t, dirtyAfter, "auto-heal must clear the dirty flag") - assert.Equal(t, headVersion, versionAfter, "auto-heal must leave the DB at head") + runErr := migrations.RunMigrations(ctx, pool, migrationsPath, "", "") + require.Error(t, runErr, "default-on auto-heal must fail loud when dirty (cannot verify whether effects were applied)") + assert.ErrorContains(t, runErr, "is dirty", "error must describe the dirty state") + assert.ErrorContains(t, runErr, "CUDLY_FORCE_MIGRATION_VERSION", "error must include recovery instructions") + + // The dirty flag must remain -- conservative auto-heal must not silently + // Force-clear it, which would record the migration as applied without + // verifying its SQL effects. + versionAfter, dirtyAfter, verr := migrations.GetMigrationVersion(ctx, pool, migrationsPath) + require.NoError(t, verr) + assert.True(t, dirtyAfter, "conservative auto-heal must leave the dirty flag intact") + assert.Equal(t, headVersion, versionAfter, "conservative auto-heal must not change the recorded version") }) - t.Run("with CUDLY_MIGRATION_AUTOHEAL=true a dirty DB self-heals", func(t *testing.T) { + t.Run("with CUDLY_MIGRATION_AUTOHEAL=true a dirty DB fails loud with recovery instructions", func(t *testing.T) { container, err := testhelpers.SetupPostgresContainer(ctx, t) require.NoError(t, err) defer container.Cleanup(ctx) @@ -83,16 +98,17 @@ func TestMigrations_AutoHealDirty(t *testing.T) { markDirty(ctx, t, container, headVersion) t.Setenv("CUDLY_MIGRATION_AUTOHEAL", "true") - require.NoError(t, migrations.RunMigrations(ctx, pool, migrationsPath, "", ""), - "explicit true should also clear the dirty flag and reach head") + runErr := migrations.RunMigrations(ctx, pool, migrationsPath, "", "") + require.Error(t, runErr, "explicit true should also fail loud when dirty") + assert.ErrorContains(t, runErr, "CUDLY_FORCE_MIGRATION_VERSION", "error must include recovery instructions") - versionAfter, dirtyAfter, err := migrations.GetMigrationVersion(ctx, pool, migrationsPath) - require.NoError(t, err) - assert.False(t, dirtyAfter, "auto-heal must clear the dirty flag") - assert.Equal(t, headVersion, versionAfter, "auto-heal must leave the DB at head") + versionAfter, dirtyAfter, verr := migrations.GetMigrationVersion(ctx, pool, migrationsPath) + require.NoError(t, verr) + assert.True(t, dirtyAfter, "conservative auto-heal must leave the dirty flag intact") + assert.Equal(t, headVersion, versionAfter, "conservative auto-heal must not change the recorded version") }) - t.Run("CUDLY_MIGRATION_AUTOHEAL=false disables auto-heal and a dirty DB errors", func(t *testing.T) { + t.Run("CUDLY_MIGRATION_AUTOHEAL=false bypasses auto-heal check; dirty DB errors via Up()", func(t *testing.T) { container, err := testhelpers.SetupPostgresContainer(ctx, t) require.NoError(t, err) defer container.Cleanup(ctx) @@ -103,14 +119,82 @@ func TestMigrations_AutoHealDirty(t *testing.T) { require.NoError(t, err) markDirty(ctx, t, container, headVersion) - // Escape hatch: the falsey value disables auto-heal, so the dirty error - // must surface (the caller fail-opens on it; the app still starts). + // Escape hatch: bypasses the descriptive auto-heal error; the dirty state + // surfaces via the generic Up() path ("failed to run migrations: migration: + // N is dirty"). The caller fail-opens on it; the app still starts. t.Setenv("CUDLY_MIGRATION_AUTOHEAL", "false") err = migrations.RunMigrations(ctx, pool, migrationsPath, "", "") - require.Error(t, err, "CUDLY_MIGRATION_AUTOHEAL=false must disable auto-heal so a dirty DB errors") + require.Error(t, err, "CUDLY_MIGRATION_AUTOHEAL=false must bypass auto-heal so a dirty DB still errors") _, dirtyAfter, verr := migrations.GetMigrationVersion(ctx, pool, migrationsPath) require.NoError(t, verr) - assert.True(t, dirtyAfter, "with auto-heal disabled, the dirty flag must be left intact") + assert.True(t, dirtyAfter, "with auto-heal bypassed, the dirty flag must be left intact") + }) + + // TestMigrations_AutoHealDirty_EffectsAbsent is the regression test for the + // 000074 divergence class: when schema_migrations records dirty=true at + // version N but N's SQL was rolled back (effects ABSENT), auto-heal must NOT + // silently Force(N) and mark the never-applied migration as complete. + // + // Setup: run all migrations to head, then roll back the last one (so the + // schema is at head-1 state), then inject dirty=true at head. This exactly + // reproduces the interrupted-migration scenario: schema_migrations says head + // is dirty, but head's SQL effects are not in the schema. + // + // Expected: RunMigrations returns an error AND leaves schema_migrations + // dirty at head -- NOT Force-cleared to clean, which would permanently skip + // the missing DDL. + t.Run("dirty-at-N with N-effects-absent: auto-heal refuses to silently mark it applied", func(t *testing.T) { + container, err := testhelpers.SetupPostgresContainer(ctx, t) + require.NoError(t, err) + defer container.Cleanup(ctx) + pool := container.DB.Pool() + + // Migrate to head so we know the head version number. + require.NoError(t, migrations.RunMigrations(ctx, pool, migrationsPath, "", "")) + headVersion, _, err := migrations.GetMigrationVersion(ctx, pool, migrationsPath) + require.NoError(t, err) + require.Greater(t, headVersion, uint(1), "need at least two migrations for the rollback step") + + // Roll back the last migration so the schema is at head-1 state. + // The effects of headVersion are now absent from the schema. + require.NoError(t, migrations.RollbackMigrations(ctx, pool, migrationsPath, 1), + "rollback of the last migration must succeed") + versionAfterRollback, _, err := migrations.GetMigrationVersion(ctx, pool, migrationsPath) + require.NoError(t, err) + require.Equal(t, headVersion-1, versionAfterRollback, + "rollback must land exactly one version below head") + + // Inject dirty=true at headVersion, simulating a migration that started + // (schema_migrations updated to dirty) but whose SQL was rolled back + // (effects not in the schema). This is the common interrupted-migration + // scenario the original defect was about. + markDirty(ctx, t, container, headVersion) + + // Verify the precondition: schema_migrations reports dirty at headVersion + // but we have not applied headVersion's effects. + recordedVersion, dirtyBefore, err := migrations.GetMigrationVersion(ctx, pool, migrationsPath) + require.NoError(t, err) + require.True(t, dirtyBefore, "precondition: schema_migrations must be dirty") + require.Equal(t, headVersion, recordedVersion, "precondition: dirty version must be head") + + // Run migrations with default auto-heal (conservative: fail loud). + t.Setenv("CUDLY_MIGRATION_AUTOHEAL", "") + runErr := migrations.RunMigrations(ctx, pool, migrationsPath, "", "") + require.Error(t, runErr, + "auto-heal must NOT silently mark the rolled-back migration as applied "+ + "(that would permanently skip its DDL: the 000074 divergence class)") + + // The dirty flag must remain set and the version must be unchanged: + // Force(headVersion) was NOT called, so the record was not falsely cleaned. + // This is the core assertion: a never-applied migration was not recorded + // as complete simply because it appeared dirty in schema_migrations. + versionFinal, dirtyFinal, verr := migrations.GetMigrationVersion(ctx, pool, migrationsPath) + require.NoError(t, verr) + assert.True(t, dirtyFinal, + "auto-heal must leave the dirty flag intact (not Force-cleared), "+ + "preventing the missing DDL from being silently skipped") + assert.Equal(t, headVersion, versionFinal, + "auto-heal must not change the recorded version to avoid falsely marking the migration applied") }) } diff --git a/internal/database/postgres/migrations/migrate_idempotency_test.go b/internal/database/postgres/migrations/migrate_idempotency_test.go index 5626e15aa..00faf644e 100644 --- a/internal/database/postgres/migrations/migrate_idempotency_test.go +++ b/internal/database/postgres/migrations/migrate_idempotency_test.go @@ -13,15 +13,23 @@ import ( "github.com/stretchr/testify/require" ) -// TestMigrations_FullStackIdempotent proves the entire migration stack is -// idempotent: running it to head twice against a fresh DB leaves the second -// run a no-op and the schema_migrations row clean (not dirty). +// TestMigrations_FullStackIdempotent verifies that calling RunMigrations on an +// already-fully-migrated DB is a clean no-op: m.Up() returns ErrNoChange +// (swallowed by RunMigrations), the DB version is unchanged, and the +// schema_migrations row is not set dirty. // -// This is the invariant the opt-in CUDLY_MIGRATION_AUTOHEAL path relies on -// (maybeAutoHealDirty in migrate.go Force()s past a dirty version and lets -// Up() re-apply the pending tail). If a migration were NOT idempotent, a -// re-apply would error or corrupt data, so this test guards the whole -// directory as new migrations are added. +// SCOPE LIMITATION: this test does NOT verify per-migration idempotency (i.e. +// that re-running a single migration on a DB that already has its effects does +// not fail or corrupt data). The second call to RunMigrations hits ErrNoChange +// from golang-migrate and returns without executing any migration SQL -- so +// individual migration bodies are never actually re-run here. +// +// The conservative auto-heal in maybeAutoHealDirty no longer relies on +// per-migration idempotency: instead of silently Force-clearing the dirty flag +// (which risked recording a rolled-back migration as applied), it now fails +// loud and defers to an operator to confirm the schema state via +// CUDLY_FORCE_MIGRATION_VERSION. Per-migration re-run safety is therefore not +// an invariant that auto-heal depends on, and is tracked separately. func TestMigrations_FullStackIdempotent(t *testing.T) { ctx := context.Background() migrationsPath := getMigrationsPath() @@ -40,10 +48,11 @@ func TestMigrations_FullStackIdempotent(t *testing.T) { require.False(t, dirtyAfterFirst, "DB must not be dirty after the first run") require.Greater(t, versionAfterFirst, uint(0), "head version should be > 0") - // Second run: must be a no-op (golang-migrate's m.Up() returns ErrNoChange, - // which RunMigrations swallows) and must not flip the dirty flag. + // Second run: m.Up() returns ErrNoChange (no SQL executed), which + // RunMigrations swallows. The version must be unchanged and the dirty flag + // must not be set. require.NoError(t, migrations.RunMigrations(ctx, pool, migrationsPath, "", ""), - "second migration run must be a clean no-op (ErrNoChange), proving idempotency") + "second migration run on a fully-migrated DB must be a clean no-op (ErrNoChange)") versionAfterSecond, dirtyAfterSecond, err := migrations.GetMigrationVersion(ctx, pool, migrationsPath) require.NoError(t, err)