diff --git a/cmd/migrate/exit_test.go b/cmd/migrate/exit_test.go new file mode 100644 index 00000000..22680912 --- /dev/null +++ b/cmd/migrate/exit_test.go @@ -0,0 +1,45 @@ +package migrate + +import ( + "bytes" + "errors" + "strings" + "testing" +) + +// A deployment decides whether to start the new version on this command's +// exit code. Before this batch the only failure that produced one was a +// failing migration function, and it produced it by ending the process from +// inside the migration engine; moving that out would have taken the last +// reported failure with it. +func TestExitOnErrorEndsTheCommandNonZero(t *testing.T) { + var codes []int + osExit = func(c int) { codes = append(codes, c) } + t.Cleanup(func() { osExit = origExit }) + + var out bytes.Buffer + exitOnError(&out, errors.New("the tenant database is unreachable")) + + if len(codes) != 1 || codes[0] != 1 { + t.Errorf("exit codes = %v, want [1]", codes) + } + if !strings.Contains(out.String(), "the tenant database is unreachable") { + t.Errorf("the reason was not reported: %q", out.String()) + } +} + +func TestExitOnErrorLetsSuccessThrough(t *testing.T) { + var codes []int + osExit = func(c int) { codes = append(codes, c) } + t.Cleanup(func() { osExit = origExit }) + + var out bytes.Buffer + exitOnError(&out, nil) + + if len(codes) != 0 { + t.Errorf("a successful migration exited with %v", codes) + } + if out.Len() != 0 { + t.Errorf("a successful migration wrote %q", out.String()) + } +} diff --git a/cmd/migrate/migration/init.go b/cmd/migrate/migration/init.go index 309d41c2..8f5070ab 100644 --- a/cmd/migrate/migration/init.go +++ b/cmd/migrate/migration/init.go @@ -284,12 +284,33 @@ func (e *Migration) Status() ([]StatusEntry, error) { } // Migrate applies every registered migration that has not been applied yet, -// across all apps. Existing callers are unaffected. -func (e *Migration) Migrate() { e.run(allApps) } +// across all apps. +func (e *Migration) Migrate() error { return e.run(allApps) } // MigrateApp applies only the migrations registered under appCode. Pass // FrameworkAppCode for the framework's own migrations. -func (e *Migration) MigrateApp(appCode string) { e.run(AppFilter(appCode)) } +func (e *Migration) MigrateApp(appCode string) error { return e.run(AppFilter(appCode)) } + +// VersionFailure names the migration that failed. +// +// The caller that needs this is an installer recording which version an +// install got stuck on. That is a diagnostic snapshot and nothing more: the +// authoritative answer to "where does a retry resume" is always recomputed +// by subtracting sys_migration's applied rows from what is registered, never +// read back from anywhere it was stored. Which is exactly why this carries +// the version rather than leaving the caller to infer it - inferring it +// would produce "what is pending now", a different question that happens to +// have the same answer most of the time. +type VersionFailure struct { + Version string + Err error +} + +func (e *VersionFailure) Error() string { + return fmt.Sprintf("migration %s failed: %v", e.Version, e.Err) +} + +func (e *VersionFailure) Unwrap() error { return e.Err } // NormalizeAppCode applies the same rule ForApp does, so a code typed on the // command line matches one written in an init(). @@ -332,7 +353,15 @@ func (e *Migration) AppCodes() []string { return out } -func (e *Migration) run(appCode string) { +// run applies the pending migrations selected by appCode. +// +// It reports failure instead of ending the process. It used to call +// log.Fatalf, which took the whole process down at the first failing +// migration - so a caller had nowhere to record what happened, and a test +// could not exercise a failing migration at all without killing the test +// binary. The exit now lives at the command layer, where the exit code is +// the command's business (see initDB in cmd/migrate/server.go). +func (e *Migration) run(appCode string) error { all := e.mergedEntries() versions := make([]string, 0, len(all)) entries := make(map[string]versionEntry, len(all)) @@ -347,10 +376,14 @@ func (e *Migration) run(appCode string) { // A mistyped --app would otherwise select nothing and report "no // migrations to apply", which reads exactly like "already up to date". + // + // The command layer rejects an unregistered code before any database + // work (exitUnlessAppRegistered), so on that path this is unreachable. + // It is reachable from an installer, which asks for one app by name and + // must not be told that installing an app nothing registered succeeded. if appCode != allApps && len(versions) == 0 { - log.Printf("no migrations are registered for app %q; registered: %s", + return fmt.Errorf("no migrations are registered for app %q; registered: %s", DisplayAppCode(appCode), strings.Join(e.AppCodes(), ", ")) - return } var err error @@ -359,7 +392,7 @@ func (e *Migration) run(appCode string) { for _, v := range versions { err = e.db.Table("sys_migration").Where("version = ?", v).Count(&count).Error if err != nil { - log.Fatalln(err) + return fmt.Errorf("checking whether migration %s was applied: %w", v, err) } if count > 0 { // Already applied. This used to print the bare count, so a mature @@ -369,7 +402,7 @@ func (e *Migration) run(appCode string) { } log.Printf("applying migration %s", v) if err = entries[v].fn(e.db.Debug(), v); err != nil { - log.Fatalf("migration %s failed: %v", v, err) + return &VersionFailure{Version: v, Err: err} } applied++ } @@ -378,6 +411,7 @@ func (e *Migration) run(appCode string) { } else { log.Printf("applied %d migration(s)", applied) } + return nil } // allApps is the sentinel run() takes to mean "do not filter". It is distinct diff --git a/cmd/migrate/migration/init_test.go b/cmd/migrate/migration/init_test.go index 13d8c6a6..e1287f8d 100644 --- a/cmd/migrate/migration/init_test.go +++ b/cmd/migrate/migration/init_test.go @@ -1,9 +1,7 @@ package migration import ( - "bytes" - "log" - "os" + "errors" "strings" "testing" "time" @@ -81,7 +79,9 @@ func TestForAppRecordsItsAppCode(t *testing.T) { m.ForApp("x").SetVersion("1786800001000", func(db *gorm.DB, version, appCode string) error { return recordFor(db, version, appCode) }) - m.Migrate() + if err := m.Migrate(); err != nil { + t.Fatalf("m.Migrate(): %v", err) + } rows := rowsByVersion(t, db) row, ok := rows["x-1786800001000"] @@ -104,7 +104,9 @@ func TestSetVersionStillRecordsTheFrameworkAsEmpty(t *testing.T) { m.SetVersion("1786700009000", func(db *gorm.DB, version string) error { return db.Create(&common.Migration{Version: version}).Error }) - m.Migrate() + if err := m.Migrate(); err != nil { + t.Fatalf("m.Migrate(): %v", err) + } rows := rowsByVersion(t, db) row, ok := rows["1786700009000"] @@ -136,7 +138,9 @@ func TestMigrateAppRunsOnlyThatApp(t *testing.T) { return recordFor(db, version, appCode) }) - m.MigrateApp("x") + if err := m.MigrateApp("x"); err != nil { + t.Fatalf("m.MigrateApp(\"x\"): %v", err) + } if !ran["x"] { t.Error("x did not run") @@ -167,7 +171,9 @@ func TestMigrateAppCoreSelectsTheFramework(t *testing.T) { return recordFor(db, version, appCode) }) - m.MigrateApp(FrameworkAppCode) + if err := m.MigrateApp(FrameworkAppCode); err != nil { + t.Fatalf("m.MigrateApp(FrameworkAppCode): %v", err) + } if !ran["core"] { t.Error("framework migration did not run") @@ -198,7 +204,9 @@ func TestMigrateRunsEveryApp(t *testing.T) { return recordFor(db, version, appCode) }) - m.Migrate() + if err := m.Migrate(); err != nil { + t.Fatalf("m.Migrate(): %v", err) + } // Namespacing puts every framework migration - bare digits - ahead of every // app migration, and orders apps by code rather than by whose timestamp @@ -232,7 +240,9 @@ func TestNamespacingKeepsTwoAppsWithTheSameTimestampApart(t *testing.T) { return recordFor(db, version, appCode) }) } - m.Migrate() + if err := m.Migrate(); err != nil { + t.Fatalf("m.Migrate(): %v", err) + } if ran != 2 { t.Errorf("ran %d migrations, want 2", ran) @@ -357,11 +367,11 @@ func TestFailedMigrationLeavesNoRecord(t *testing.T) { }) }) - // run() calls log.Fatal on failure, which would take the test binary with - // it, so drive the registered function directly - the point here is the - // transaction boundary, not the scheduler. - entry := m.version["crm-1786800001000"] - if err := entry.fn(db, "crm-1786800001000"); err == nil { + // Driven through the scheduler, not by calling the registered function + // directly. That workaround was here because run() called log.Fatal and + // would have taken the test binary with it, which also meant nothing + // covered what the scheduler does with a failure. + if err := m.MigrateApp("crm"); err == nil { t.Fatal("migration reported success") } if rows := rowsByVersion(t, db); len(rows) != 0 { @@ -369,6 +379,49 @@ func TestFailedMigrationLeavesNoRecord(t *testing.T) { } } +// An installer records which version an attempt got stuck on. It gets that +// from the error rather than by asking the database what is still pending, +// which is a different question - see VersionFailure. +func TestRunReportsWhichVersionFailed(t *testing.T) { + db := newTestDB(t) + m := newMigration() + m.SetDb(db) + + // Two versions, and the first one succeeds: the failure has to name the + // one that actually failed, which a report that just names the app, or + // the first version it looked at, would get wrong. + m.ForApp("crm").SetVersion("1786800001000", func(db *gorm.DB, version, appCode string) error { + return recordFor(db, version, appCode) + }) + m.ForApp("crm").SetVersion("1786800002000", func(db *gorm.DB, version, appCode string) error { + return errTestMigrationFailed + }) + + err := m.MigrateApp("crm") + if err == nil { + t.Fatal("MigrateApp reported success") + } + var vf *VersionFailure + if !errors.As(err, &vf) { + t.Fatalf("error is %T, want *VersionFailure: %v", err, err) + } + if vf.Version != "crm-1786800002000" { + t.Errorf("failed version = %q, want crm-1786800002000", vf.Version) + } + if !errors.Is(err, errTestMigrationFailed) { + t.Errorf("the cause is not reachable through the wrapper: %v", err) + } + // The one that succeeded before it stays recorded: a retry must not run + // it again. + rows := rowsByVersion(t, db) + if _, ok := rows["crm-1786800001000"]; !ok { + t.Errorf("the migration that succeeded was not recorded: %v", rows) + } + if _, ok := rows["crm-1786800002000"]; ok { + t.Errorf("the migration that failed was recorded: %v", rows) + } +} + var errTestMigrationFailed = &testError{"boom"} type testError struct{ s string } @@ -389,17 +442,18 @@ func TestMigrateAppOnAnUnknownCodeSaysSo(t *testing.T) { return recordFor(db, version, appCode) }) - var buf bytes.Buffer - log.SetOutput(&buf) - t.Cleanup(func() { log.SetOutput(os.Stderr) }) - - m.MigrateApp("crmm") - - if !strings.Contains(buf.String(), `no migrations are registered for app "crmm"`) { - t.Errorf("output = %q", buf.String()) + // Reported as an error rather than a log line, so an installer asking + // for one app by name cannot be told that installing an app nothing + // registered succeeded. + err := m.MigrateApp("crmm") + if err == nil { + t.Fatal("a typo reported success") } - if !strings.Contains(buf.String(), "registered: core, crm") { - t.Errorf("the message must list what is registered; got %q", buf.String()) + if !strings.Contains(err.Error(), `no migrations are registered for app "crmm"`) { + t.Errorf("error = %q", err) + } + if !strings.Contains(err.Error(), "registered: core, crm") { + t.Errorf("the message must list what is registered; got %q", err) } if rows := rowsByVersion(t, db); len(rows) != 0 { t.Errorf("a typo ran %v", rows) @@ -425,7 +479,9 @@ func TestMergedEntriesRunsAContractRegisteredAppMigration(t *testing.T) { return recordFor(db, version, appCode) }) - m.Migrate() + if err := m.Migrate(); err != nil { + t.Fatalf("m.Migrate(): %v", err) + } if !ran { t.Fatal("contract-registered migration did not run") @@ -466,7 +522,9 @@ func TestMergedEntriesStatusIncludesContractRegisteredMigrations(t *testing.T) { t.Fatalf("pending contract entry = %+v (ok=%v)", e, ok) } - m.Migrate() + if err := m.Migrate(); err != nil { + t.Fatalf("m.Migrate(): %v", err) + } entries, err = m.Status() if err != nil { @@ -522,7 +580,9 @@ func TestMergedEntriesMigrateAppRunsOnlyThatContractApp(t *testing.T) { return recordFor(db, version, appCode) }) - m.MigrateApp("order") + if err := m.MigrateApp("order"); err != nil { + t.Fatalf("m.MigrateApp(\"order\"): %v", err) + } if !ran["order"] { t.Error("order did not run") @@ -552,7 +612,9 @@ func TestMergedEntriesHostRegistrationWinsOnKeyCollision(t *testing.T) { return recordFor(db, version, appCode) }) - m.Migrate() + if err := m.Migrate(); err != nil { + t.Fatalf("m.Migrate(): %v", err) + } if !hostRan { t.Error("host registration did not run") diff --git a/cmd/migrate/server.go b/cmd/migrate/server.go index 951fedee..d845b0c7 100644 --- a/cmd/migrate/server.go +++ b/cmd/migrate/server.go @@ -3,6 +3,7 @@ package migrate import ( "bytes" "fmt" + "io" "os" "strconv" "strings" @@ -162,11 +163,9 @@ func migrateModel() error { } migration.Migrate.SetDb(db.Debug()) if appCode != "" { - migration.Migrate.MigrateApp(appCode) - return nil + return migration.Migrate.MigrateApp(appCode) } - migration.Migrate.Migrate() - return nil + return migration.Migrate.Migrate() } func initDB() { @@ -197,13 +196,40 @@ func initDB() { //4. 数据库迁移 fmt.Println("数据库迁移开始") - if err := migrateModel(); err != nil { - fmt.Println(err) - return - } + exitOnError(os.Stderr, migrateModel()) fmt.Println(`数据库基础数据初始化成功`) } +// exitOnError ends the command non-zero when the migration did not go through. +// +// A caller that migrates before starting a server decides whether to go ahead +// on the exit code alone - the deploy workflow does exactly that. Every path +// out of migrateModel used to return without one: an unreachable tenant +// database or a failed AutoMigrate printed a line and exited 0, so a +// deployment carried on onto a schema that had not been brought forward. A +// failing migration function was the only one reported, and only because it +// ended the process from inside the migration engine - which is the call this +// batch moved out here, so without this the last reported failure would have +// stopped being reported too. +// +// Split from the exit itself, the way appRegistrationError is split from +// exitUnlessAppRegistered, so what it decides can be tested without a +// subprocess. osExit is a variable for the same reason. +func exitOnError(w io.Writer, err error) { + if err == nil { + return + } + fmt.Fprintln(w, err) + osExit(1) +} + +// osExit is a variable so a test can watch the decision without ending the +// test binary; origExit is what it is put back to. +var ( + osExit = os.Exit + origExit = os.Exit +) + func runStatus() { config.Setup( file.NewSource(file.WithPath(configYml)),