From 36092f542c55ba7bf5c4fdb51a0151305c49d85a Mon Sep 17 00:00:00 2001 From: Jakub Zych Date: Wed, 28 Oct 2026 19:45:57 +0100 Subject: [PATCH] fix(lagoon): warn on after-commit work registered after lagoon:after_commit; correct the OnDatabase example and pivot read guidance (quick-261028-r16) - flushStatementAfterCommit marks the statement; AfterCommit logs a warning when work is buffered on a flushed statement that no longer holds GORM's transaction. Log-only: the work still never runs, the write succeeds - subtests pin the late callback warning, a callback between commit and flush, and a reused chained statement staying silent - README OnDatabase example registers After(gorm:create).Before(commit), matching docs/database/transactions.md - RegisterJoinTable: pivot-ordered reads join the pivot table explicitly; a Preload cannot be ordered by a pivot column --- docs/database/transactions.md | 2 +- modules/lagoon/README.md | 8 +-- modules/lagoon/relations.go | 9 ++- modules/lagoon/transaction.go | 20 +++++- modules/lagoon/transaction_test.go | 108 +++++++++++++++++++++++++++++ 5 files changed, 139 insertions(+), 8 deletions(-) diff --git a/docs/database/transactions.md b/docs/database/transactions.md index 60413562..1bdac521 100644 --- a/docs/database/transactions.md +++ b/docs/database/transactions.md @@ -84,7 +84,7 @@ return lagoon.OnDatabase(app, func(_ *sql.DB, gdb *gorm.DB) error { ``` > [!WARNING] -> Register such a callback with a `Before("gorm:commit_or_rollback_transaction")` constraint, as above. lagoon runs a single-statement write's after-commit work from its own callback right after that commit step; a callback that GORM sorts after it buffers work that is never run, without an error. +> Register such a callback with a `Before("gorm:commit_or_rollback_transaction")` constraint, as above. lagoon runs a single-statement write's after-commit work from its own callback right after that commit step; a callback that GORM sorts after it buffers work that is never run. The write still succeeds, and lagoon logs a warning when that happens. ## Boot-time work that needs the database diff --git a/modules/lagoon/README.md b/modules/lagoon/README.md index d37855e7..d4f46ba3 100644 --- a/modules/lagoon/README.md +++ b/modules/lagoon/README.md @@ -26,7 +26,7 @@ Use cases: - One shared pool: `lagoon.Open`, `lagoon.Use` and `lagoon.OpenFromApp` return a `*sql.DB` and a `*gorm.DB` built on that same pool; `lagoon.Publish` makes both available on the `backpack.App`. - Database-ready hooks: `lagoon.OnDatabase` runs a callback with the pool and GORM handle as soon as the database is published, immediately when it already is, otherwise when `lagoon.Publish` runs. Plugins register GORM callbacks through it from Boot, which runs before the `serve` command publishes the database. -- After-commit work: `lagoon.Transaction` runs a function in a transaction and then the callbacks registered with `lagoon.AfterCommit`, in order, only after the commit succeeds; a nested `lagoon.Transaction` is a savepoint whose callbacks are dropped with it when it fails. A nested `lagoon.Transaction` must be given the outer transaction's handle: given a root handle it returns an error without running its function, rather than open an independent transaction whose callbacks would wait on the outer one. A single-statement write for which GORM opens its own implicit transaction runs its callbacks from `lagoon:after_commit` once GORM commits, and never when the write fails. A callback registered inside a foreign plain GORM transaction is unsafe because Lagoon cannot observe its commit, so `lagoon.AfterCommit` warns and skips it. Outside a transaction, callbacks run immediately. The handle a supported callback receives always has an empty statement on the connection its work belongs to. A panicking callback is logged and never turns a committed write into an error. +- After-commit work: `lagoon.Transaction` runs a function in a transaction and then the callbacks registered with `lagoon.AfterCommit`, in order, only after the commit succeeds; a nested `lagoon.Transaction` is a savepoint whose callbacks are dropped with it when it fails. A nested `lagoon.Transaction` must be given the outer transaction's handle: given a root handle it returns an error without running its function, rather than open an independent transaction whose callbacks would wait on the outer one. A single-statement write for which GORM opens its own implicit transaction runs its callbacks from `lagoon:after_commit` once GORM commits, and never when the write fails. A GORM callback that runs after `lagoon:after_commit` on the same write registers its work too late: the work never runs, and `lagoon.AfterCommit` logs a warning. A callback registered inside a foreign plain GORM transaction is unsafe because Lagoon cannot observe its commit, so `lagoon.AfterCommit` warns and skips it. Outside a transaction, callbacks run immediately. The handle a supported callback receives always has an empty statement on the connection its work belongs to. A panicking callback is logged and never turns a committed write into an error. - Per-plugin migrations: `lagoon.Migrate` runs the framework's `system_files` set (`attach.Migrations`), backend admin identity set (`lagoon.BackendAdminMigrations`), `deferred_bindings` set (`lagoon.DeferredBindingMigrations`, under the `lagoon.DeferredHistoryID` history) and job-queue set (`lagoon.QueueMigrations`: River's schema pinned at `lagoon.RiverSchemaVersion`, then the `lagoon.JobsTable` record table, under the `lagoon.QueueHistoryID` history), then every `pact.HasMigrations` set in plugin activation order, each in its own `summer_migrations_` history table (`lagoon.HistoryTableName`). `lagoon.RollbackLast` and `lagoon.Status` cover rollback and history. - Mass assignment: `lagoon.Fill` copies only allow-listed keys onto a model by GORM column name and silently drops the rest, logging each dropped key once outside production. A `json.Number` (from a decoder using `UseNumber`) fills integer, unsigned and float fields. A value that does not fit its column (a fraction, an exponent or an overflow for an integer field, or a value of the wrong type) is a `lagoon.FillTypeError` naming the key, so a caller can answer it as a validation failure on that field. `lagoon.HasFillable` and `lagoon.HasHidden` are the Go forms of `$fillable` and `$hidden`. - Validation: `lagoon.Validate` (where `required` fails on a zero date or time) accepts Laravel-style rule strings (`required`, `nullable`, `integer`, `numeric`, `between`, `min`, `max`, `in`, `unique`, `boolean`, `email`, `confirmed`, `different`, `mimes`) and returns a field-to-messages map, translated through phrasebook when a translator is given. Unknown rule tokens are an error. A failed numeric range reports the bound that failed: the `min` message below the lower bound, the `max` message above the upper one, and the numeric `between` message when the bound came from `between`. @@ -81,12 +81,12 @@ func createPost(ctx context.Context, gdb *gorm.DB, tr *phrasebook.Translator, in } ``` -A plugin registers its GORM callbacks from Boot through `lagoon.OnDatabase`, so they are installed whenever the database is published, and defers side effects until the write commits: +A plugin registers its GORM callbacks from Boot through `lagoon.OnDatabase`, so they are installed whenever the database is published, and defers side effects until the write commits. Register the callback before GORM's `gorm:commit_or_rollback_transaction` step: lagoon runs a single-statement write's after-commit work from `lagoon:after_commit` right after that step, so work buffered by a callback GORM sorts later never runs, and `lagoon.AfterCommit` logs a warning for it (see [Callbacks registered at boot](../../docs/database/transactions.md#callbacks-registered-at-boot)): ```go func (p *Plugin) Boot(app *backpack.App) error { return lagoon.OnDatabase(app, func(_ *sql.DB, gdb *gorm.DB) error { - return gdb.Callback().Create().After("gorm:after_create").Register("acme:post_created", func(db *gorm.DB) { + return gdb.Callback().Create().After("gorm:create").Before("gorm:commit_or_rollback_transaction").Register("acme:post_created", func(db *gorm.DB) { if db.Error != nil { return } @@ -191,7 +191,7 @@ func (p *Plugin) Migrations() []*gormigrate.Migration { | `lagoon.OrderOption` | Option type accepted by `lagoon.OrderBy`. | | `lagoon.Paginate` | Builds a `lagoon.Page` with `lagoon.PageMeta`. | | `lagoon.WithSoftDeleteCascade` | Runs a cascade inside the parent delete transaction. | -| `lagoon.RegisterJoinTable` | Registers a custom pivot model for a many-to-many field. | +| `lagoon.RegisterJoinTable` | Registers a custom pivot model for a many-to-many field. Reads in pivot order join the pivot table explicitly, because a Preload of the field cannot be ordered by a pivot column. | | `lagoon.DecryptLaravelPayload` | Decrypts a Laravel AES-256-CBC payload for data imports. | | `attach.File` | The `system_files` row model; `attach.File.URL` is the public URL of the original. | | `attach.PublicURL` | Public URL of a blob key: under `storage.uploads.public_url` when set, else under `storage.uploads.public_path_prefix`. | diff --git a/modules/lagoon/relations.go b/modules/lagoon/relations.go index 9cfee741..9aeb6dd9 100644 --- a/modules/lagoon/relations.go +++ b/modules/lagoon/relations.go @@ -15,8 +15,13 @@ import ( // Association Mode has no documented path to set those columns. Writes go // through an explicit delete-then-bulk-insert (or ON CONFLICT DO UPDATE) // against the join table directly, in the same transaction as the parent -// save. Reads use Preload(field) plus .Order(...) on the pivot's own -// columns once RegisterJoinTable has run. +// save. +// +// Reads in pivot order join the pivot table explicitly: Joins on the join +// table plus Order on its columns. A Preload of the field still loads the +// targets through the pivot model once RegisterJoinTable has run, but GORM +// issues that query without the join table, so ordering it by a pivot +// column fails with a missing FROM-clause entry. func RegisterJoinTable(db *gorm.DB, owner any, field string, joinModel any) error { if db == nil { return fmt.Errorf("lagoon: register join table: db is nil") diff --git a/modules/lagoon/transaction.go b/modules/lagoon/transaction.go index 4f9fb313..558eb336 100644 --- a/modules/lagoon/transaction.go +++ b/modules/lagoon/transaction.go @@ -14,6 +14,9 @@ const AfterCommitCallback = "lagoon:after_commit" const statementBufferKey = "lagoon:after_commit" +// statementFlushedKey marks a statement whose AfterCommitCallback has run. +const statementFlushedKey = "lagoon:after_commit_flushed" + type afterCommitKey struct{} // afterCommitBuffer holds the callbacks registered inside one transaction. @@ -95,6 +98,14 @@ func Transaction(ctx context.Context, gdb *gorm.DB, fn func(ctx context.Context, // run, because Lagoon cannot know whether that transaction will commit. // Anywhere else, fn runs immediately on db's connection. // +// Called from a GORM callback that runs after AfterCommitCallback on the +// same write, fn is registered too late and never runs; AfterCommit logs a +// warning for it. Register such callbacks +// Before("gorm:commit_or_rollback_transaction"). The warning also requires +// that the statement no longer holds GORM's transaction, so a statement +// reused across writes does not warn for a correctly ordered callback in a +// later write. +// // The handle fn receives always has an empty statement on the connection // the work belongs to, whatever handle AfterCommit was called with. Queries // through it never continue from the written model's @@ -115,6 +126,10 @@ func AfterCommit(ctx context.Context, db *gorm.DB, fn func(ctx context.Context, } if db != nil && db.Statement != nil { if _, started := db.InstanceGet("gorm:started_transaction"); started { + if _, flushed := db.InstanceGet(statementFlushedKey); flushed && !transactionalHandle(db) { + moduleLog.Warn("lagoon: after-commit callback registered after lagoon:after_commit ran; it will not run", + "hint", "register the GORM callback before gorm:commit_or_rollback_transaction") + } buf := &afterCommitBuffer{} if existing, ok := db.InstanceGet(statementBufferKey); ok { if b, ok := existing.(*afterCommitBuffer); ok && b != nil { @@ -155,8 +170,11 @@ func bufferFrom(ctx context.Context, db *gorm.DB) *afterCommitBuffer { // flushStatementAfterCommit is the AfterCommitCallback GORM callback: it // runs the statement's buffered callbacks once GORM's own transaction has -// committed, on a fresh session over the pool. +// committed, on a fresh session over the pool. It first marks the +// statement as flushed, on every write that passes through it, so that +// AfterCommit can warn about work registered after this point. func flushStatementAfterCommit(db *gorm.DB) { + db.InstanceSet(statementFlushedKey, true) raw, ok := db.InstanceGet(statementBufferKey) if !ok { return diff --git a/modules/lagoon/transaction_test.go b/modules/lagoon/transaction_test.go index 93cd4dc9..474a607d 100644 --- a/modules/lagoon/transaction_test.go +++ b/modules/lagoon/transaction_test.go @@ -227,6 +227,114 @@ func TestTransactionAfterCommit(t *testing.T) { } }) + // A callback GORM sorts after lagoon:after_commit registers its work too + // late: the write succeeds, the work never runs, and AfterCommit warns. + t.Run("late_callback_warns", func(t *testing.T) { + g, err := Use(ctx, db) + if err != nil { + t.Fatal(err) + } + var logs bytes.Buffer + previous := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&logs, &slog.HandlerOptions{Level: slog.LevelWarn}))) + defer slog.SetDefault(previous) + var r recorder + if err := g.Callback().Create().After(AfterCommitCallback).Register("lagoon_test:late", func(stmt *gorm.DB) { + item, ok := stmt.Statement.Dest.(*acItem) + if !ok { + return + } + name := item.Name + AfterCommit(stmt.Statement.Context, stmt, func(context.Context, *gorm.DB) { r.add(name) }) + }); err != nil { + t.Fatal(err) + } + if err := g.WithContext(ctx).Create(&acItem{Name: "flush-late"}).Error; err != nil { + t.Fatal(err) + } + if n := committedCount(t, db, "flush-late"); n != 1 { + t.Fatalf("committed rows = %d, want 1", n) + } + if got := r.names(); len(got) != 0 { + t.Fatalf("callbacks = %v, want none", got) + } + if !strings.Contains(logs.String(), "registered after lagoon:after_commit ran") { + t.Fatalf("warning = %q", logs.String()) + } + }) + + // A callback between GORM's commit step and lagoon:after_commit is in + // time: its work runs once and nothing is logged. + t.Run("callback_between_commit_and_flush_runs", func(t *testing.T) { + g, err := Use(ctx, db) + if err != nil { + t.Fatal(err) + } + var logs bytes.Buffer + previous := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&logs, &slog.HandlerOptions{Level: slog.LevelWarn}))) + defer slog.SetDefault(previous) + var r recorder + if err := g.Callback().Create().After("gorm:commit_or_rollback_transaction").Before(AfterCommitCallback).Register("lagoon_test:between", func(stmt *gorm.DB) { + item, ok := stmt.Statement.Dest.(*acItem) + if !ok { + return + } + name := item.Name + AfterCommit(stmt.Statement.Context, stmt, func(context.Context, *gorm.DB) { r.add(name) }) + }); err != nil { + t.Fatal(err) + } + if err := g.WithContext(ctx).Create(&acItem{Name: "flush-between"}).Error; err != nil { + t.Fatal(err) + } + if got := r.names(); !reflect.DeepEqual(got, []string{"flush-between"}) { + t.Fatalf("callbacks = %v, want [flush-between]", got) + } + if strings.Contains(logs.String(), "registered after lagoon:after_commit ran") { + t.Fatalf("unexpected warning %q", logs.String()) + } + }) + + // A chained handle reuses one statement across writes, so the flushed + // marker of the first write is still set during the second. A correctly + // ordered callback must stay silent there, because the statement holds + // GORM's transaction again. + t.Run("reused_statement_no_false_warning", func(t *testing.T) { + g, err := Use(ctx, db) + if err != nil { + t.Fatal(err) + } + var logs bytes.Buffer + previous := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&logs, &slog.HandlerOptions{Level: slog.LevelWarn}))) + defer slog.SetDefault(previous) + var r recorder + if err := g.Callback().Create().Before("gorm:create").Register("lagoon_test:reuse", func(stmt *gorm.DB) { + item, ok := stmt.Statement.Dest.(*acItem) + if !ok { + return + } + name := item.Name + AfterCommit(stmt.Statement.Context, stmt, func(context.Context, *gorm.DB) { r.add(name) }) + }); err != nil { + t.Fatal(err) + } + q := g.WithContext(ctx).Table("lagoon_ac_items") + if err := q.Create(&acItem{Name: "flush-reuse-1"}).Error; err != nil { + t.Fatal(err) + } + if err := q.Create(&acItem{Name: "flush-reuse-2"}).Error; err != nil { + t.Fatal(err) + } + if got := r.names(); !reflect.DeepEqual(got, []string{"flush-reuse-1", "flush-reuse-2"}) { + t.Fatalf("callbacks = %v, want [flush-reuse-1 flush-reuse-2]", got) + } + if strings.Contains(logs.String(), "registered after lagoon:after_commit ran") { + t.Fatalf("unexpected warning %q", logs.String()) + } + }) + t.Run("plain_gorm_transaction_is_refused", func(t *testing.T) { var logs bytes.Buffer previous := slog.Default()