From 257d88f090915d2a4c071b453d5fe7ae0fce42bc Mon Sep 17 00:00:00 2001 From: FrameAutomata Date: Mon, 7 Sep 2026 12:50:56 -0500 Subject: [PATCH] middleware: buffer the response until Commit succeeds; isolate commit hooks Transactional decided whether to commit only after the handler had already flushed its response, so a failed Commit() (SQLite "database is locked", a full disk, a dropped Postgres connection) still delivered the handler's 2xx for rows that were never persisted; /api/register handed the browser a JWT for a user that did not exist. The recover path had the same flaw for a handler that panicked after writing. The middleware now swaps c.Writer for a responseBuffer that records the status and body in memory and releases them only after Commit() succeeds. A failed commit discards the buffer, restores the headers as they were before the handler ran, and answers 500 with an empty body through c.AbortWithError so the failure is logged and reported. Commit hooks now run one at a time under their own recover: the transaction is already committed, so a panicking hook is recorded on c.Errors and the remaining hooks and the response still go out. Closes #364 Co-Authored-By: Claude Fable 5.1 --- CLAUDE.md | 15 +- backend/app/middleware/buffer_response.go | 103 +++++ .../middleware/transactional.middleware.go | 36 +- backend/app/middleware/transactional_test.go | 353 ++++++++++++++++++ 4 files changed, 498 insertions(+), 9 deletions(-) create mode 100644 backend/app/middleware/buffer_response.go create mode 100644 backend/app/middleware/transactional_test.go diff --git a/CLAUDE.md b/CLAUDE.md index 7d2ae351..9a6e9185 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -123,14 +123,16 @@ func (c *AuthController) Register(ctx *gin.Context) { return // Transaction auto-rolls back on non-success status } - ctx.JSON(201, user) // Transaction auto-commits on 200/201/303 + ctx.JSON(201, user) // Transaction auto-commits on any 2xx/3xx status } ``` **Auto-commit/rollback behavior:** -- Commits on status codes: 200, 201, 303 +- Commits on any 2xx or 3xx status (`200 <= status < 400`) - Rolls back on all other status codes or panics +**Response buffering:** `Transactional` holds the handler's response in memory (`responseBuffer` in `buffer_response.go`) and only releases it after `Commit()` succeeds; a failed commit answers 500 with an empty body instead of the 2xx the handler rendered, and commit hooks run before the release (each hook is isolated by `runCommitHook`, so a panicking hook is recorded on `c.Errors` without cancelling the others or the response). Handlers on transactional routes therefore must not stream, flush or hijack. + **Body buffering:** `Transactional` reads the request body into memory (cap `maxTransactionalBodyBytes`, 8MB) before it calls `db.DB.Begin()`, answering 413/408/400 without a transaction when that fails; the handler's later bind is served from memory. This is what keeps a slow-drip body from holding the single SQLite main-DB connection, and it covers every transactional route without each one remembering a special middleware. Routes that want a tighter cap put `middleware.BufferAuthBody` (64KB) in front of `Transactional`, which then skips the body it finds already buffered; the anonymous auth endpoints do this. The self-transacting OAuth routes (`/auth/device/*`, `/auth/token`, `/auth/logout`) use `BufferAuthBody` on its own for the same cap. `UseAppAuth` caps every dashboard route's body at the same 8MB with `MaxBytesReader`, so the non-transactional telemetry reads are bounded too. Every plain JSON bind site in the controllers answers through `middleware.RejectBindError(c, err, fallback)`, which maps `MaxBytesError` to 413 and the body guard's timeout to 408 with fixed messages and otherwise returns 400 with the fallback (the ingest routes use `middleware.RejectIngestBindError`, the same mapping except that the timeout becomes 503 + `Retry-After`, because OTLP exporters retry 503 but treat 408 as permanent; the Traceway SDKs re-queue a failed batch whatever the status); the guard itself swaps the raw deadline error (a `*net.OpError` naming the listener address) for `middleware.ErrBodyTimedOut` before it leaves `Read`, so no handler can echo the address. **Preference:** For CRUD controller methods, always prefer using `middleware.Transactional` in the route + `db.GetTx(ctx)` in the controller over `pgdb.ExecuteTransaction`. The middleware approach keeps controllers flat, avoids nested closures, and follows the established pattern. (The tx getter lives in the `db` package: `db.GetTx(ctx)`, not `middleware.GetTx`.) @@ -1245,19 +1247,26 @@ if err != nil { traceway.CaptureException(fmt.Errorf("failed to read session recording (key=%s): %w", key, err)) } +// ALSO CORRECT - inside a handler or middleware, before the response is sent +if err != nil { + _ = c.Error(fmt.Errorf("failed to warm the project cache: %w", err)) +} + // WRONG - Do not use log.Printf for errors if err != nil { log.Printf("Failed to read session recording (key=%s): %v", key, err) } ``` +Inside a handler or middleware with the response not yet sent, `c.Error(err)` is an equivalent channel: tracewaygin reports every `c.Errors` entry with the request's trace, and gin's Logger prints it even when monitoring is off, whereas `CaptureException` is a no-op until the SDK is initialised. `runCommitHook` uses it for a panicking commit hook. + **Validation error conventions:** - `400 Bad Request`: Malformed requests, missing required params, type errors - `422 Unprocessable Entity`: Business validation in form dialogs (name too long, duplicate name, required field empty). Return `c.JSON(422, gin.H{"error": "descriptive message"})`. The frontend `api.ts` extracts 422 error messages — dialogs catch and display them inline. **Summary:** - **Stopping errors** (abort the request): `c.AbortWithError(status, traceway.NewStackTraceErrorf("reason: %w", err))` -- **Non-stopping errors** (continue serving): `traceway.CaptureException(fmt.Errorf("reason: %w", err))` +- **Non-stopping errors** (continue serving): `traceway.CaptureException(fmt.Errorf("reason: %w", err))`, or `c.Error(err)` when a `*gin.Context` is in hand and the response has not been sent - **Validation errors** (user-facing): `c.JSON(422, gin.H{"error": "message"})` for form validation - **Always** wrap errors with `traceway.NewStackTraceErrorf` or `fmt.Errorf` using `%w` — never discard the original error diff --git a/backend/app/middleware/buffer_response.go b/backend/app/middleware/buffer_response.go new file mode 100644 index 00000000..552b0894 --- /dev/null +++ b/backend/app/middleware/buffer_response.go @@ -0,0 +1,103 @@ +package middleware + +import ( + "bufio" + "bytes" + "fmt" + "maps" + "net" + "net/http" + + "github.com/gin-gonic/gin" +) + +var errHijackUnderTransaction = fmt.Errorf("hijack is not supported on a transactional route: %w", http.ErrNotSupported) + +// responseBuffer holds a handler's status and body until Transactional knows +// whether the transaction committed. +type responseBuffer struct { + gin.ResponseWriter + ctx *gin.Context + body bytes.Buffer + status int + written bool + headers http.Header +} + +func bufferResponse(c *gin.Context) *responseBuffer { + buf := &responseBuffer{ + ResponseWriter: c.Writer, + ctx: c, + status: c.Writer.Status(), + headers: c.Writer.Header().Clone(), + } + c.Writer = buf + return buf +} + +func (b *responseBuffer) WriteHeader(code int) { + if code <= 0 || b.written { + return + } + b.status = code +} + +// WriteHeaderNow locks the status the way gin's writer does; nothing reaches +// the wire until release. +func (b *responseBuffer) WriteHeaderNow() { + b.written = true +} + +func (b *responseBuffer) Flush() { + b.WriteHeaderNow() +} + +func (b *responseBuffer) Write(data []byte) (int, error) { + b.WriteHeaderNow() + return b.body.Write(data) +} + +func (b *responseBuffer) WriteString(s string) (int, error) { + b.WriteHeaderNow() + return b.body.WriteString(s) +} + +func (b *responseBuffer) Status() int { + return b.status +} + +func (b *responseBuffer) Size() int { + if !b.written { + return -1 + } + return b.body.Len() +} + +func (b *responseBuffer) Written() bool { + return b.written +} + +func (b *responseBuffer) Hijack() (net.Conn, *bufio.ReadWriter, error) { + return nil, nil, errHijackUnderTransaction +} + +// Unwrap keeps http.ResponseController reaching the connection from inside a +// handler (SetWriteDeadline and friends), as it does through gin's own writer. +func (b *responseBuffer) Unwrap() http.ResponseWriter { + return b.ResponseWriter +} + +// discard drops the buffered response and restores the headers as they were +// before the handler ran, so a Content-Type, Location or Set-Cookie meant for +// the discarded response does not ride out on the 500 that replaces it. +func (b *responseBuffer) discard() { + clear(b.Header()) + maps.Copy(b.Header(), b.headers) + b.ctx.Writer = b.ResponseWriter +} + +func (b *responseBuffer) release() { + b.ctx.Writer = b.ResponseWriter + b.ResponseWriter.WriteHeader(b.status) + b.ResponseWriter.Write(b.body.Bytes()) +} diff --git a/backend/app/middleware/transactional.middleware.go b/backend/app/middleware/transactional.middleware.go index dd40a849..e5db96ac 100644 --- a/backend/app/middleware/transactional.middleware.go +++ b/backend/app/middleware/transactional.middleware.go @@ -7,23 +7,32 @@ import ( "github.com/tracewayapp/traceway/backend/app/db" "github.com/gin-gonic/gin" + traceway "go.tracewayapp.com" ) +// Transactional opens a main-DB transaction for the request and commits it +// when the handler answers 2xx/3xx, rolling back otherwise. The handler's +// response is buffered and only released once Commit() has succeeded; a +// failed commit answers 500 with an empty body instead of the 2xx the +// handler rendered for rows that never persisted. Handlers under it must not +// stream, flush or hijack. func Transactional(c *gin.Context) { if !bufferRequestBody(c, maxTransactionalBodyBytes) { return } txHandle, err := db.DB.Begin() - if err != nil { - c.AbortWithStatus(http.StatusInternalServerError) - panic(err) + c.AbortWithError(http.StatusInternalServerError, traceway.NewStackTraceErrorf("begin transaction: %w", err)) + return } + buf := bufferResponse(c) + defer func() { if r := recover(); r != nil { txHandle.Rollback() + buf.discard() c.AbortWithStatus(http.StatusInternalServerError) panic(r) } @@ -37,13 +46,17 @@ func Transactional(c *gin.Context) { if status := c.Writer.Status(); status >= 200 && status < 400 { if err := txHandle.Commit(); err != nil { - c.AbortWithStatus(http.StatusInternalServerError) - panic(err) + buf.discard() + c.AbortWithError(http.StatusInternalServerError, traceway.NewStackTraceErrorf("commit transaction: %w", err)) + return } + // Hooks run before the response leaves: the project cache must hold + // the row before the client can send its next request. runCommitHooks(c) } else { txHandle.Rollback() } + buf.release() } const commitHooksContextKey = "txCommitHooks" @@ -63,6 +76,17 @@ func runCommitHooks(c *gin.Context) { hooks, _ := c.Get(commitHooksContextKey) fns, _ := hooks.([]func()) for _, fn := range fns { - fn() + runCommitHook(c, fn) } } + +// The transaction is already committed, so a hook failure must neither cancel +// the remaining hooks nor turn a persisted request into a 500. +func runCommitHook(c *gin.Context, fn func()) { + defer func() { + if r := recover(); r != nil { + _ = c.Error(traceway.NewStackTraceErrorf("commit hook panicked: %v", r)) + } + }() + fn() +} diff --git a/backend/app/middleware/transactional_test.go b/backend/app/middleware/transactional_test.go new file mode 100644 index 00000000..7ea44074 --- /dev/null +++ b/backend/app/middleware/transactional_test.go @@ -0,0 +1,353 @@ +//go:build !transactional_pg + +package middleware + +import ( + "context" + "database/sql" + "database/sql/driver" + "errors" + "io" + "net/http" + "net/http/httptest" + "slices" + "testing" + "time" + + "github.com/gin-gonic/gin" + "github.com/tracewayapp/traceway/backend/app/db" + _ "modernc.org/sqlite" +) + +var errSimulatedCommit = errors.New("simulated commit failure") + +// failCommitConnector hands out one real in-memory sqlite connection whose +// transactions fail to commit when failCommit is set. A failed commit rolls +// back for real so the connection stays clean; returning driver.ErrBadConn +// instead would make database/sql discard the connection and, with it, the +// in-memory database, so a "0 rows" assertion would pass vacuously. +type failCommitConnector struct { + drv driver.Driver + failCommit bool +} + +func (c *failCommitConnector) Connect(context.Context) (driver.Conn, error) { + conn, err := c.drv.Open(":memory:") + if err != nil { + return nil, err + } + return &failCommitConn{Conn: conn, failCommit: c.failCommit}, nil +} + +func (c *failCommitConnector) Driver() driver.Driver { return c.drv } + +type failCommitConn struct { + driver.Conn + failCommit bool +} + +func (c *failCommitConn) BeginTx(ctx context.Context, opts driver.TxOptions) (driver.Tx, error) { + tx, err := c.Conn.(driver.ConnBeginTx).BeginTx(ctx, opts) + if err != nil { + return nil, err + } + return &failCommitTx{Tx: tx, failCommit: c.failCommit}, nil +} + +type failCommitTx struct { + driver.Tx + failCommit bool +} + +func (t *failCommitTx) Commit() error { + if t.failCommit { + _ = t.Tx.Rollback() + return errSimulatedCommit + } + return t.Tx.Commit() +} + +func setupTransactionalDB(t *testing.T, failCommit bool) { + t.Helper() + + base, err := sql.Open("sqlite", ":memory:") + if err != nil { + t.Fatalf("open sqlite: %v", err) + } + connector := &failCommitConnector{drv: base.Driver(), failCommit: failCommit} + base.Close() + + mainDB := sql.OpenDB(connector) + mainDB.SetMaxOpenConns(1) + + prev := db.DB + db.DB = mainDB + t.Cleanup(func() { + mainDB.Close() + db.DB = prev + }) + + if _, err := mainDB.Exec(`CREATE TABLE things (id INTEGER PRIMARY KEY AUTOINCREMENT, name TEXT NOT NULL)`); err != nil { + t.Fatalf("create table: %v", err) + } +} + +func insertThing(t *testing.T, c *gin.Context, name string) { + t.Helper() + if _, err := db.GetTx(c).Exec(`INSERT INTO things (name) VALUES (?)`, name); err != nil { + t.Fatalf("insert %q: %v", name, err) + } +} + +// assertRows queries the table the setup created: a replaced in-memory +// database would have no such table and fail here instead of counting zero. +func assertRows(t *testing.T, name string, present bool) { + t.Helper() + var n int + if err := db.DB.QueryRow(`SELECT count(*) FROM things WHERE name = ?`, name).Scan(&n); err != nil { + t.Fatalf("count %q: %v", name, err) + } + want := 0 + if present { + want = 1 + } + if n != want { + t.Fatalf("%q rows = %d, want %d", name, n, want) + } +} + +const outerHeader = "X-Outer-Middleware" + +type transactionalObservations struct { + recovered any + errors []*gin.Error +} + +// newTransactionalRouter mirrors the production chain: recovery outermost, a +// middleware that sets a header before the handler and reads c.Errors after +// it, then Transactional and the handler. +func newTransactionalRouter(handler gin.HandlerFunc) (*gin.Engine, *transactionalObservations) { + gin.SetMode(gin.TestMode) + obs := &transactionalObservations{} + r := gin.New() + r.Use(gin.CustomRecoveryWithWriter(io.Discard, func(c *gin.Context, err any) { + obs.recovered = err + c.AbortWithStatus(http.StatusInternalServerError) + })) + r.Use(func(c *gin.Context) { + c.Header(outerHeader, "set") + c.Next() + obs.errors = append([]*gin.Error(nil), c.Errors...) + }) + r.Any("/tx", Transactional, handler) + return r, obs +} + +// headerWriteObserver reports the moment the first status line reaches the +// underlying writer, so ordering against commit hooks is observable. +type headerWriteObserver struct { + *httptest.ResponseRecorder + onFirstWriteHeader func() +} + +func (w *headerWriteObserver) WriteHeader(code int) { + if w.onFirstWriteHeader != nil { + w.onFirstWriteHeader() + w.onFirstWriteHeader = nil + } + w.ResponseRecorder.WriteHeader(code) +} + +func serve(r *gin.Engine, method string) *httptest.ResponseRecorder { + rec := httptest.NewRecorder() + r.ServeHTTP(rec, httptest.NewRequest(method, "/tx", nil)) + return rec +} + +func TestTransactionalFailedCommitAnswers500WithoutHandlerResponse(t *testing.T) { + setupTransactionalDB(t, true) + hookRan := false + r, obs := newTransactionalRouter(func(c *gin.Context) { + insertThing(t, c, "row") + OnCommit(c, func() { hookRan = true }) + c.Header("Location", "/somewhere") + c.JSON(http.StatusCreated, gin.H{"ok": true}) + }) + + rec := serve(r, http.MethodPost) + + if rec.Code != http.StatusInternalServerError { + t.Fatalf("status = %d, want 500", rec.Code) + } + if rec.Body.Len() != 0 { + t.Fatalf("body = %q, want empty", rec.Body.String()) + } + for _, h := range []string{"Content-Type", "Location"} { + if v := rec.Header().Get(h); v != "" { + t.Fatalf("%s = %q, want unset", h, v) + } + } + if v := rec.Header().Get(outerHeader); v != "set" { + t.Fatalf("%s = %q, want the outer middleware's value", outerHeader, v) + } + assertRows(t, "row", false) + if hookRan { + t.Fatal("commit hook ran after a failed commit") + } + if obs.recovered != nil { + t.Fatalf("panic reached recovery: %v", obs.recovered) + } + if len(obs.errors) != 1 || !errors.Is(obs.errors[0].Err, errSimulatedCommit) { + t.Fatalf("c.Errors = %v, want one entry wrapping the commit error", obs.errors) + } +} + +func TestTransactionalReleasesResponseAfterCommit(t *testing.T) { + cases := []struct { + name string + method string + render func(c *gin.Context) + wantStatus int + wantBody string + wantHeaders map[string]string + }{ + { + name: "json", + method: http.MethodPost, + render: func(c *gin.Context) { c.JSON(http.StatusCreated, gin.H{"ok": true}) }, + wantStatus: http.StatusCreated, + wantBody: `{"ok":true}`, + wantHeaders: map[string]string{ + "Content-Type": "application/json; charset=utf-8", + }, + }, + { + name: "redirect", + method: http.MethodGet, + render: func(c *gin.Context) { c.Redirect(http.StatusSeeOther, "/next") }, + wantStatus: http.StatusSeeOther, + wantBody: "See Other.\n\n", + wantHeaders: map[string]string{"Location": "/next"}, + }, + { + name: "bare status", + method: http.MethodDelete, + render: func(c *gin.Context) { c.Status(http.StatusNoContent) }, + wantStatus: http.StatusNoContent, + }, + { + name: "json no content", + method: http.MethodDelete, + render: func(c *gin.Context) { c.JSON(http.StatusNoContent, nil) }, + wantStatus: http.StatusNoContent, + }, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + setupTransactionalDB(t, false) + var events []string + r, obs := newTransactionalRouter(func(c *gin.Context) { + insertThing(t, c, "row") + OnCommit(c, func() { events = append(events, "hook") }) + tc.render(c) + }) + + rec := &headerWriteObserver{ResponseRecorder: httptest.NewRecorder()} + rec.onFirstWriteHeader = func() { events = append(events, "header") } + r.ServeHTTP(rec, httptest.NewRequest(tc.method, "/tx", nil)) + + if rec.Code != tc.wantStatus { + t.Fatalf("status = %d, want %d", rec.Code, tc.wantStatus) + } + if got := rec.Body.String(); got != tc.wantBody { + t.Fatalf("body = %q, want %q", got, tc.wantBody) + } + for h, want := range tc.wantHeaders { + if got := rec.Header().Get(h); got != want { + t.Fatalf("%s = %q, want %q", h, got, want) + } + } + if v := rec.Header().Get(outerHeader); v != "set" { + t.Fatalf("%s = %q, want the outer middleware's value", outerHeader, v) + } + assertRows(t, "row", true) + if !slices.Equal(events, []string{"hook", "header"}) { + t.Fatalf("events = %v, want the hook to run before the first header write", events) + } + if obs.recovered != nil || len(obs.errors) != 0 { + t.Fatalf("recovered = %v, c.Errors = %v, want neither", obs.recovered, obs.errors) + } + }) + } +} + +func TestTransactionalPanicAfterWriteAnswers500(t *testing.T) { + setupTransactionalDB(t, false) + r, obs := newTransactionalRouter(func(c *gin.Context) { + insertThing(t, c, "row") + c.JSON(http.StatusCreated, gin.H{"ok": true}) + panic("boom") + }) + + rec := serve(r, http.MethodPost) + + if rec.Code != http.StatusInternalServerError { + t.Fatalf("status = %d, want 500", rec.Code) + } + if rec.Body.Len() != 0 { + t.Fatalf("body = %q, want empty", rec.Body.String()) + } + if v := rec.Header().Get("Content-Type"); v != "" { + t.Fatalf("Content-Type = %q, want unset", v) + } + assertRows(t, "row", false) + if obs.recovered != "boom" { + t.Fatalf("recovered = %v, want the handler's panic", obs.recovered) + } +} + +func TestTransactionalPanickingCommitHookDoesNotStopOthers(t *testing.T) { + setupTransactionalDB(t, false) + secondRan := false + r, obs := newTransactionalRouter(func(c *gin.Context) { + insertThing(t, c, "row") + OnCommit(c, func() { panic("hook boom") }) + OnCommit(c, func() { secondRan = true }) + c.JSON(http.StatusCreated, gin.H{"ok": true}) + }) + + rec := serve(r, http.MethodPost) + + if rec.Code != http.StatusCreated { + t.Fatalf("status = %d, want 201", rec.Code) + } + if got := rec.Body.String(); got != `{"ok":true}` { + t.Fatalf("body = %q, want the handler's JSON", got) + } + assertRows(t, "row", true) + if !secondRan { + t.Fatal("second commit hook did not run after the first panicked") + } + if obs.recovered != nil { + t.Fatalf("hook panic reached recovery: %v", obs.recovered) + } + if len(obs.errors) != 1 { + t.Fatalf("c.Errors = %v, want exactly one entry for the panicking hook", obs.errors) + } +} + +type deadlineWriter struct{ http.ResponseWriter } + +func (deadlineWriter) SetReadDeadline(time.Time) error { return nil } + +// httptest.ResponseRecorder has no SetReadDeadline, so the controller only +// succeeds if it unwraps through the buffer down to deadlineWriter. +func TestResponseBufferUnwrapKeepsResponseControllerWorking(t *testing.T) { + gin.SetMode(gin.TestMode) + c, _ := gin.CreateTestContext(deadlineWriter{httptest.NewRecorder()}) + bufferResponse(c) + + if err := http.NewResponseController(c.Writer).SetReadDeadline(time.Time{}); err != nil { + t.Fatalf("SetReadDeadline through the buffer: %v", err) + } +}