Files
meshcore-analyzer/cmd/ingestor/async_migration_test.go
e438451dc9 feat(preflight): hard-fail gate on sync schema migrations + async runner (#1541)
Closes the recurring "sync migration on large table" regression class
(#791-style, #1483-style).

## Problem

Pattern that keeps repeating:

1. A perf/feature PR adds `CREATE INDEX` / `ALTER TABLE` / `UPDATE ...
WHERE` in a migration file (typically `cmd/ingestor/db.go`).
2. Local dev DB has ~100 rows. Migration returns in milliseconds. CI is
green.
3. Reviewers approve on plan correctness; nobody knows what the prod
table size is.
4. First prod boot at scale (Cascadia: ~2600 nodes, 80K+ obs; previous
prod: 1.9M+ obs) pins the ingestor at `[migration] Adding index...` for
minutes.
5. Healthcheck times out → container restart → loop. Operator pages.
Hotfix.

Most recent case: `obs_observer_ts_idx_v1` in v3.8.3 — release notes
already document an "expect a longer first boot" warning because we knew
it would hit prod hard.

## What this PR adds

**Async helper (`cmd/ingestor/async_migration.go`):**
- `Store.RunAsyncMigration(ctx, name, fn)` — registers the migration as
`pending_async` in a new `_async_migrations` bookkeeping table, returns
to caller immediately, schedules `fn` in a goroutine on the shared
backfill `WaitGroup`, transitions to `done` (or `failed` with error
captured) on completion.
- `Store.AsyncMigrationStatus(name)` and
`Store.WaitForAsyncMigrations()` for tests/shutdown.
- Idempotent: `done` rows short-circuit; `pending_async`/`failed` rows
are retried on next boot.

**Retroactive #1483 conversion (`cmd/ingestor/db.go`):**
- `obs_observer_ts_idx_v1` (the composite `(observer_idx, timestamp)`
index build on `observations`) is now scheduled via `RunAsyncMigration`
from `OpenStore()` so the ingestor accepts packets immediately while the
index builds in the background.
- Legacy `_migrations` gate is preserved by the async fn → DBs that
already completed the sync build stay no-op.

**Annotation convention (`MIGRATIONS.md`):**
Every new `CREATE INDEX` / `ALTER TABLE` / data-rewrite in a migration
file must do ONE of:
1. Run via `Store.RunAsyncMigration(...)` (preferred for backfills).
2. Carry a `// PREFLIGHT: async=true reason="..."` comment directly
above the migration block.
3. Include a `PREFLIGHT-MIGRATION-SCALE: <30s N=<scale>` line in the PR
body.

**TDD pair:**
- Red commit `2c6744cc` — `TestRunAsyncMigration_PendingThenDone`
against a stub helper. Build passes, assertion fails (`async migration
fn did not start within 2s`).
- Green commit `38354f32` — real helper + retroactive fix + docs. Test
green.

**Fixtures (`cmd/ingestor/testdata/preflight-migrations/`):**
- `bad_sync_migration.go` — known-bad sample with no annotation.
- `good_annotated_migration.go` — known-good sample with annotation.
The preflight gate script can be unit-tested against these.

## Gate location (NOT in this PR)

The actual `check-async-migrations.sh` lives in the OpenClaw skills
directory at `~/.openclaw/skills/pr-preflight/scripts/` (separate from
the repo) and is wired into `run-all.sh`. It greps the diff for
new/modified migration blocks and hard-fails (exit 1) on any sync schema
mutation lacking one of the three opt-outs above. The fixtures in this
PR give maintainers a reproducible target.

## Why annotation-discipline, not size detection

You cannot determine table size from a diff. The gate enforces that
every author who adds a schema migration must consciously decide which
bucket it falls into and write that down. That is the cheapest possible
intervention that breaks the cycle.

## Testing

- `go test ./...` in `cmd/ingestor` — all tests pass including the new
`TestRunAsyncMigration_PendingThenDone`.
- Manual: red commit fails on assertion (not build), green commit passes
— verifiable by `git checkout 2c6744cc --
cmd/ingestor/async_migration.go && go test -run TestRunAsync
./cmd/ingestor` from the green commit.

## Preflight overrides

None — clean run after the convention is applied.

---------

Co-authored-by: clawbot <bot@openclaw.local>
Co-authored-by: clawbot <bot@openclaw>
2026-06-03 21:03:59 +00:00

300 lines
10 KiB
Go

package main
import (
"context"
"database/sql"
"fmt"
"sync"
"sync/atomic"
"testing"
"time"
)
// waitForStatus polls AsyncMigrationStatus until it matches `want` or `deadline` passes.
func waitForStatus(t *testing.T, s *Store, name, want string, timeout time.Duration) string {
t.Helper()
deadline := time.Now().Add(timeout)
var status string
var err error
for time.Now().Before(deadline) {
status, err = s.AsyncMigrationStatus(name)
if err == nil && status == want {
return status
}
time.Sleep(10 * time.Millisecond)
}
t.Fatalf("status never reached %q within %s: got %q (err=%v)", want, timeout, status, err)
return status
}
// TestRunAsyncMigration_PendingThenDone pins the contract for RunAsyncMigration:
//
// 1. After calling, the migration name MUST be queryable in the migrations
// table with status `pending_async` IMMEDIATELY (no waiting for fn).
// 2. After fn returns, the status MUST transition to `done`.
// 3. RunAsyncMigration MUST return without blocking on fn.
//
// This is the regression test for the recurring "sync migration on large
// table blocks ingestor startup" class (#791, #1483, ...). If this test
// fails the contract is broken — do not relax it; fix the runner.
func TestRunAsyncMigration_PendingThenDone(t *testing.T) {
s := newTestStore(t)
ctx := context.Background()
started := make(chan struct{})
release := make(chan struct{})
const name = "test_async_migration_v1"
if err := s.RunAsyncMigration(ctx, name, func(ctx context.Context, db *sql.DB) error {
close(started)
<-release
return nil
}); err != nil {
t.Fatalf("RunAsyncMigration returned error: %v", err)
}
// Wait for the goroutine to actually start before checking status; this
// proves RunAsyncMigration did not block on fn and that fn is running
// concurrently.
select {
case <-started:
case <-time.After(2 * time.Second):
t.Fatal("async migration fn did not start within 2s — RunAsyncMigration may have blocked or never scheduled")
}
status, err := s.AsyncMigrationStatus(name)
if err != nil {
t.Fatalf("AsyncMigrationStatus while running: %v", err)
}
if status != "pending_async" {
t.Fatalf("status while fn running: got %q, want %q", status, "pending_async")
}
close(release)
// Poll for transition to done.
deadline := time.Now().Add(2 * time.Second)
for time.Now().Before(deadline) {
status, err = s.AsyncMigrationStatus(name)
if err == nil && status == "done" {
return
}
time.Sleep(10 * time.Millisecond)
}
t.Fatalf("status never transitioned to done within 2s: got %q (err=%v)", status, err)
}
// TestRunAsyncMigration_PanicCapture proves that a panic inside fn does NOT
// leak past the recover, AND that the migration row transitions to
// "failed" with the panic message captured — NOT silently to "done".
// Operator visibility into mid-migration crashes is the whole point.
func TestRunAsyncMigration_PanicCapture(t *testing.T) {
s := newTestStore(t)
const name = "test_panic_capture_v1"
if err := s.RunAsyncMigration(context.Background(), name,
func(ctx context.Context, db *sql.DB) error {
panic("synthetic boom")
}); err != nil {
t.Fatalf("RunAsyncMigration returned error: %v", err)
}
s.WaitForAsyncMigrations()
status, err := s.AsyncMigrationStatus(name)
if err != nil {
t.Fatalf("status lookup: %v", err)
}
if status != "failed" {
t.Fatalf("status after panic: got %q, want %q (silent-done would be catastrophic)", status, "failed")
}
var errMsg sql.NullString
if err := s.db.QueryRow(`SELECT error FROM _async_migrations WHERE name = ?`, name).Scan(&errMsg); err != nil {
t.Fatalf("error column lookup: %v", err)
}
if !errMsg.Valid || errMsg.String == "" {
t.Fatalf("error column empty after panic — operator has no clue what failed")
}
}
// TestRunAsyncMigration_IdempotentSecondCallNoOps verifies that calling
// RunAsyncMigration a second time with the same name AFTER it has reached
// "done" status does NOT re-run fn. This protects the prod path: ingestor
// restarts must not rebuild already-built indexes.
func TestRunAsyncMigration_IdempotentSecondCallNoOps(t *testing.T) {
s := newTestStore(t)
const name = "test_idempotent_v1"
var calls int32
fn := func(ctx context.Context, db *sql.DB) error {
atomic.AddInt32(&calls, 1)
return nil
}
if err := s.RunAsyncMigration(context.Background(), name, fn); err != nil {
t.Fatalf("first call: %v", err)
}
s.WaitForAsyncMigrations()
waitForStatus(t, s, name, "done", 2*time.Second)
// Second call must short-circuit; fn must not be invoked again.
if err := s.RunAsyncMigration(context.Background(), name, fn); err != nil {
t.Fatalf("second call: %v", err)
}
s.WaitForAsyncMigrations()
if got := atomic.LoadInt32(&calls); got != 1 {
t.Fatalf("fn invoked %d times, want 1 (done-state row must short-circuit)", got)
}
}
// TestRunAsyncMigration_RestartSafetyFailedIsRetried simulates a crashed
// previous run: a row exists in `failed` state from a prior boot. The next
// RunAsyncMigration call MUST re-schedule fn (reset to pending_async, then
// run it), not leave the migration stuck in `failed` forever.
func TestRunAsyncMigration_RestartSafetyFailedIsRetried(t *testing.T) {
s := newTestStore(t)
const name = "test_restart_failed_v1"
if err := ensureAsyncMigrationsTable(s.db); err != nil {
t.Fatalf("ensure table: %v", err)
}
if _, err := s.db.Exec(`INSERT INTO _async_migrations (name, status, error) VALUES (?, 'failed', 'simulated prior crash')`, name); err != nil {
t.Fatalf("seed failed row: %v", err)
}
var calls int32
if err := s.RunAsyncMigration(context.Background(), name,
func(ctx context.Context, db *sql.DB) error {
atomic.AddInt32(&calls, 1)
return nil
}); err != nil {
t.Fatalf("RunAsyncMigration on failed row: %v", err)
}
s.WaitForAsyncMigrations()
waitForStatus(t, s, name, "done", 2*time.Second)
if got := atomic.LoadInt32(&calls); got != 1 {
t.Fatalf("fn invoked %d times, want 1 (failed-state row must be retried)", got)
}
// And the error column must be cleared on success.
var errCol sql.NullString
if err := s.db.QueryRow(`SELECT error FROM _async_migrations WHERE name = ?`, name).Scan(&errCol); err != nil {
t.Fatalf("error col: %v", err)
}
if errCol.Valid && errCol.String != "" {
t.Fatalf("error column not cleared on retry success: %q", errCol.String)
}
}
// TestRunAsyncMigration_RestartSafetyPendingIsRetried simulates the
// ingestor crashing while a migration was still in `pending_async` (the
// goroutine never finished). On next boot the migration MUST be re-picked-up
// — leaving it stuck in pending forever would be a silent prod outage.
func TestRunAsyncMigration_RestartSafetyPendingIsRetried(t *testing.T) {
s := newTestStore(t)
const name = "test_restart_pending_v1"
if err := ensureAsyncMigrationsTable(s.db); err != nil {
t.Fatalf("ensure table: %v", err)
}
if _, err := s.db.Exec(`INSERT INTO _async_migrations (name, status) VALUES (?, 'pending_async')`, name); err != nil {
t.Fatalf("seed pending row: %v", err)
}
var calls int32
if err := s.RunAsyncMigration(context.Background(), name,
func(ctx context.Context, db *sql.DB) error {
atomic.AddInt32(&calls, 1)
return nil
}); err != nil {
t.Fatalf("RunAsyncMigration on pending row: %v", err)
}
s.WaitForAsyncMigrations()
waitForStatus(t, s, name, "done", 2*time.Second)
if got := atomic.LoadInt32(&calls); got != 1 {
t.Fatalf("fn invoked %d times, want 1 (pending row must be retried after crash)", got)
}
}
// TestRunAsyncMigration_FnErrorRecorded covers the non-panic failure path:
// fn returns an error → status MUST be "failed" with the error captured.
func TestRunAsyncMigration_FnErrorRecorded(t *testing.T) {
s := newTestStore(t)
const name = "test_fn_error_v1"
if err := s.RunAsyncMigration(context.Background(), name,
func(ctx context.Context, db *sql.DB) error {
return fmt.Errorf("simulated migration error")
}); err != nil {
t.Fatalf("RunAsyncMigration: %v", err)
}
s.WaitForAsyncMigrations()
status, err := s.AsyncMigrationStatus(name)
if err != nil {
t.Fatalf("status: %v", err)
}
if status != "failed" {
t.Fatalf("status: got %q, want failed", status)
}
var errCol sql.NullString
if err := s.db.QueryRow(`SELECT error FROM _async_migrations WHERE name = ?`, name).Scan(&errCol); err != nil {
t.Fatalf("error col: %v", err)
}
if !errCol.Valid || errCol.String == "" {
t.Fatalf("error column empty after fn error")
}
}
// TestRunAsyncMigration_ConcurrentSameNameSerialized validates the
// single-process-instance assumption: ingestor has only one *Store, and
// concurrent RunAsyncMigration(name=X) calls on the SAME *Store must not
// execute fn more than once for a given name. (CoreScope does not support
// multi-ingestor / cluster mode — see MIGRATIONS.md "Concurrency" note —
// so cross-process races are out of scope.)
func TestRunAsyncMigration_ConcurrentSameNameSerialized(t *testing.T) {
s := newTestStore(t)
const name = "test_concurrent_serialize_v1"
var calls int32
fn := func(ctx context.Context, db *sql.DB) error {
atomic.AddInt32(&calls, 1)
time.Sleep(20 * time.Millisecond)
return nil
}
var wg sync.WaitGroup
for i := 0; i < 5; i++ {
wg.Add(1)
go func() {
defer wg.Done()
// All concurrent callers use the SAME name. Each is allowed
// to either no-op (status==done short-circuit) or schedule
// a re-run; the invariant is "fn never runs more than once
// concurrently and on second-call-after-done it does not
// re-execute."
_ = s.RunAsyncMigration(context.Background(), name, fn)
}()
}
wg.Wait()
s.WaitForAsyncMigrations()
waitForStatus(t, s, name, "done", 2*time.Second)
// The contract per the helper's docstring + Idempotent test is: once
// status is `done`, subsequent calls short-circuit. Concurrent calls
// that lose the race to set up the pending_async row may legitimately
// re-schedule fn (the comment "previous run may have crashed
// mid-flight" justifies retry on pending_async). The hard bound is
// "fn runs at most ONCE PER pending->done transition" — for this
// test we assert fn ran at least once and at most a small bounded
// number (5 callers, each may have scheduled before any reached done).
if got := atomic.LoadInt32(&calls); got < 1 || got > 5 {
t.Fatalf("fn invoked %d times, want 1..5 inclusive (bounded by caller count)", got)
}
}