From 9c68bc25a5312e36383026e096dd03e476969dbb Mon Sep 17 00:00:00 2001 From: zhangwenjian Date: Wed, 9 Sep 2026 12:14:12 +0800 Subject: [PATCH] =?UTF-8?q?refactor=E2=99=BB=EF=B8=8F:=20report=20a=20fail?= =?UTF-8?q?ed=20migration=20instead=20of=20ending=20the=20process?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit run() called log.Fatalf on the first migration that failed, which ended the process from inside the migration engine. Nothing above it could record what happened - an installer needs to write down which version an attempt stopped on - and no test could exercise a failing migration at all without taking the test binary with it, which is why the one test that covers a failed migration drove the registered function directly and left the scheduler uncovered. run(), Migrate() and MigrateApp() now return an error, and the exit moved to the command layer where the exit code is the command's business. Two of those errors say more than "it failed". A migration that fails comes back as a *VersionFailure naming the version, because an installer records that as a diagnostic snapshot - the authoritative answer to where a retry resumes is always recomputed from sys_migration, never read back, and asking the database what is still pending answers a different question that merely has the same answer most of the time. An app code nothing registered under is now an error rather than a log line, so an installer asking for one app by name cannot be told that installing an app that does not exist succeeded; the command layer still rejects a typo before any database work. exitOnError is what makes the command exit non-zero, and it covers more than it replaces. Every path out of migrateModel used to return without an exit code: an unreachable tenant database or a failed AutoMigrate printed a line and exited 0, so a caller that migrates before starting a server - the deploy workflow does exactly that - carried on onto a schema that had not been brought forward. A failing migration function was the only failure reported, and only as a side effect of the log.Fatalf this commit removes. Each of these was checked by degrading it and watching the named assertion go red: returning nil instead of the failure, naming the first version rather than the one that failed, accepting an unregistered app code, and not exiting. One gap is left open deliberately. Go allows a call whose only result is an error to stand as a statement, so `migration.Migrate.Migrate()` still compiles while dropping what it returns - `go build` passed while migrateModel was doing exactly that during this change. Both call sites now return the value, which the compiler does check, but nothing guards against the statement form coming back. A checksilent rule was considered and dropped: that tool parses without type information, so it could only match the method name, and a guard that fires on any type with a Migrate method is noise. --- cmd/migrate/exit_test.go | 45 +++++++++++ cmd/migrate/migration/init.go | 50 ++++++++++-- cmd/migrate/migration/init_test.go | 118 ++++++++++++++++++++++------- cmd/migrate/server.go | 42 ++++++++-- 4 files changed, 211 insertions(+), 44 deletions(-) create mode 100644 cmd/migrate/exit_test.go 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)),