From ca0e13be80bb8f261022be37c0206b422ca0f49e Mon Sep 17 00:00:00 2001 From: Remylus Losius Date: Thu, 24 Sep 2026 17:34:36 -0400 Subject: [PATCH 1/6] fix(auth): bound the per-user lock wait and make closure evidence attributable Follow-up to the first integrated closure run for OW-069 and OW-073 on a22c8b29, authorized 2026-09-24. Stacked on the I10 change. Lock-wait bound. Nothing bounded the wait for the per-user lock: the http.Server WriteTimeout does not cancel a handler, so a request blocked on the lock waited until its client disconnected. LockUser now sets a transaction-local lock_timeout of 5 s (identity.LockWaitBound), so every path that takes the lock inherits it, the administrative account mutations included. A timeout is a determinate failure reported as 503 server.error, retryable, and is distinct from a logout that failed and rolled back (500 auth.logout_incomplete) and from an unknown commit (503, not retryable). Logout still clears both cookies on a timeout, because the web client treats every logout response as signed out. SSO audit reasons. A refused federated sign-in now records sso_account_disabled or sso_account_deleted, on both refusal paths. The sign-in page stays /login?sso_error=signin. Audit contract. auth.login.failure declared five reasons, of which the code recorded one; it records 36. The event now declares the full vocabulary and the username, remote_addr and user_agent keys the emitters send, which the key check had been logging as violations on every binder refusal. A source scan (AC-80) keeps the two in step. Evidence. The three assertions that read the newest audit row in the database now read only the row their own request produced, by correlation id (bugs/OW-075). The scratch closure cases are promoted to committed tests that attribute writes by row ID, with the coordinating mutation's own changes asserted separately. The OpenAPI document now declares the error responses login, both refresh paths, logout and the admin account mutations already returned. Specs: system-auth-identity 1.9.0 (C-11 amended, C-43 added, AC-73 to AC-80), system-sso 1.2.0 (C-05 amended, AC-12, AC-13). Refs: bugs/OW-069, bugs/doing/OW-073, bugs/OW-075, bugs/doing/OW-062 sections 14.7 and 14.8 --- .secrets.baseline | 4 +- api/openapi.yaml | 80 ++ audit/events.yaml | 38 +- frontend/src/api/schema.d.ts | 81 ++ internal/audit/events.gen.go | 6 +- internal/identity/account_state_test.go | 21 +- internal/identity/revoke.go | 35 + internal/server/auth_handlers.go | 20 + internal/server/closure_regressions_test.go | 790 ++++++++++++++++++ .../server/login_failure_vocabulary_test.go | 191 +++++ internal/server/session_binding_gaps_test.go | 10 +- internal/server/session_binding_test.go | 79 +- internal/server/sso_account_state_test.go | 14 +- internal/server/sso_closure_test.go | 153 ++++ internal/server/sso_handlers.go | 30 +- internal/server/users_admin_handlers.go | 5 + internal/sso/flow.go | 2 +- internal/sso/types.go | 16 + specs/system/auth-identity.spec.yaml | 175 +++- specs/system/sso.spec.yaml | 50 +- 20 files changed, 1754 insertions(+), 46 deletions(-) create mode 100644 internal/server/closure_regressions_test.go create mode 100644 internal/server/login_failure_vocabulary_test.go create mode 100644 internal/server/sso_closure_test.go diff --git a/.secrets.baseline b/.secrets.baseline index 34559470..5db56cb2 100644 --- a/.secrets.baseline +++ b/.secrets.baseline @@ -149,7 +149,7 @@ "filename": "api/openapi.yaml", "hashed_secret": "6b1fe243c0b63c8e43d2545520492f2f5bc19869", "is_verified": false, - "line_number": 195 + "line_number": 251 } ], "cmd/openwatch/setup.go": [ @@ -809,5 +809,5 @@ } ] }, - "generated_at": "2026-09-24T11:31:29Z" + "generated_at": "2026-09-24T21:34:13Z" } diff --git a/api/openapi.yaml b/api/openapi.yaml index 0595de02..0aaefa4b 100644 --- a/api/openapi.yaml +++ b/api/openapi.yaml @@ -118,6 +118,16 @@ paths: content: application/json: schema: {$ref: '#/components/schemas/ErrorEnvelope'} + '503': + description: >- + server.error. retryable true: sign-in did not complete and nothing was + issued, including when the per-user lock was not acquired in time. + retryable false: the outcome is unknown; sign in again rather than + assuming either result. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' /api/v1/auth/logout: post: @@ -126,6 +136,34 @@ paths: responses: '204': description: Session revoked + '403': + description: >- + authz.csrf_invalid. A credential cookie selects what to revoke and the + double-submit token is missing or does not match. Nothing was revoked and + no cookie was changed. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' + '500': + description: >- + auth.logout_incomplete, retryable. The revocation failed and rolled back, + so nothing was revoked. Both cookies are cleared; the session may stay + valid until it expires. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' + '503': + description: >- + server.error. Two outcomes, told apart by retryable. Both cookies are + cleared in both. retryable true: the per-user lock was not acquired in + time and nothing was revoked; a retry is safe. retryable false: the + revocation outcome is unknown and neither outcome is asserted. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' /api/v1/auth/refresh: post: @@ -148,6 +186,15 @@ paths: content: application/json: schema: {$ref: '#/components/schemas/ErrorEnvelope'} + '503': + description: >- + server.error. retryable true: nothing was rotated, including when the + per-user lock was not acquired in time. retryable false: the rotation + outcome is unknown; sign in again rather than presenting the same token. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' /api/v1/auth/refresh-cookie: post: @@ -171,6 +218,15 @@ paths: content: application/json: schema: {$ref: '#/components/schemas/ErrorEnvelope'} + '503': + description: >- + server.error. retryable true: nothing was rotated and no cookie was + set, including when the per-user lock was not acquired in time. + retryable false: the rotation outcome is unknown. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' /api/v1/auth/me: get: @@ -821,6 +877,14 @@ paths: content: application/json: schema: {$ref: '#/components/schemas/ErrorEnvelope'} + '503': + description: >- + server.error, retryable. The per-user lock was not acquired in time and + the change was not applied. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' /api/v1/users/{id}:disable: post: @@ -856,6 +920,14 @@ paths: content: application/json: schema: {$ref: '#/components/schemas/ErrorEnvelope'} + '503': + description: >- + server.error, retryable. The per-user lock was not acquired in time and + the change was not applied. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' /api/v1/users/{id}:enable: post: @@ -885,6 +957,14 @@ paths: content: application/json: schema: {$ref: '#/components/schemas/ErrorEnvelope'} + '503': + description: >- + server.error, retryable. The per-user lock was not acquired in time and + the change was not applied. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' /api/v1/roles:create: post: diff --git a/audit/events.yaml b/audit/events.yaml index d861039a..6e49043f 100644 --- a/audit/events.yaml +++ b/audit/events.yaml @@ -65,13 +65,47 @@ events: - code: auth.login.failure severity: warning - description: Authentication attempt failed + description: >- + Authentication attempt failed, or a presented credential was refused. + reason names why. Password login records wrong_password, + unknown_user, account_disabled, mfa_required, mfa_invalid, + mfa_required_during_login or password_changed_during_login. The + binders record the session, access-token and account-state reasons. + SSO records the sso_ reasons, and sso_account_disabled or + sso_account_deleted when the local account may not sign in; the + sign-in page stays generic. account_state_unavailable and + session_lookup_failed mean the server could not tell, and the + request answered 503, not 401. invalid_credentials, account_locked, + mfa_failed and sso_failed are legacy values that nothing records + now; older rows may carry them. username is the submitted name, + clipped. remote_addr and user_agent are recorded by the binders, + the user agent clipped. actor_types: [user] detail_schema: type: object properties: - reason: {type: string, enum: [invalid_credentials, account_locked, mfa_required, mfa_failed, sso_failed]} + reason: + type: string + enum: [ + wrong_password, unknown_user, account_disabled, account_deleted, + account_missing, account_state_unknown, account_state_unavailable, + mfa_required, mfa_invalid, mfa_required_during_login, + password_changed_during_login, + invalid_session_token, session_expired, session_revoked, + session_lookup_failed, session_user_lookup_failed, + invalid_api_token, invalid_jwt, jwt_expired, jwt_verify_failed, + invalid_jwt_subject, invalid_jwt_session, + sid_absent, session_absent, session_owner_mismatch, + session_absolute_expired, session_binding_unknown, + sso_login_init_failed, sso_idp_error, sso_state_expired, + sso_state_invalid, sso_token_invalid, sso_discovery_failed, + sso_account_disabled, sso_account_deleted, sso_account_not_active, + sso_signin_failed, + invalid_credentials, account_locked, mfa_failed, sso_failed] auth_method: {type: string} + username: {type: string} + remote_addr: {type: string} + user_agent: {type: string} - code: auth.logout severity: info diff --git a/frontend/src/api/schema.d.ts b/frontend/src/api/schema.d.ts index 356b32c2..ae2285d2 100644 --- a/frontend/src/api/schema.d.ts +++ b/frontend/src/api/schema.d.ts @@ -5036,6 +5036,15 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; + /** @description server.error. retryable true: sign-in did not complete and nothing was issued, including when the per-user lock was not acquired in time. retryable false: the outcome is unknown; sign in again rather than assuming either result. */ + 503: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; }; }; postAuthLogout: { @@ -5054,6 +5063,33 @@ export interface operations { }; content?: never; }; + /** @description authz.csrf_invalid. A credential cookie selects what to revoke and the double-submit token is missing or does not match. Nothing was revoked and no cookie was changed. */ + 403: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; + /** @description auth.logout_incomplete, retryable. The revocation failed and rolled back, so nothing was revoked. Both cookies are cleared; the session may stay valid until it expires. */ + 500: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; + /** @description server.error. Two outcomes, told apart by retryable. Both cookies are cleared in both. retryable true: the per-user lock was not acquired in time and nothing was revoked; a retry is safe. retryable false: the revocation outcome is unknown and neither outcome is asserted. */ + 503: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; }; }; postAuthRefresh: { @@ -5087,6 +5123,15 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; + /** @description server.error. retryable true: nothing was rotated, including when the per-user lock was not acquired in time. retryable false: the rotation outcome is unknown; sign in again rather than presenting the same token. */ + 503: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; }; }; postAuthRefreshCookie: { @@ -5116,6 +5161,15 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; + /** @description server.error. retryable true: nothing was rotated and no cookie was set, including when the per-user lock was not acquired in time. retryable false: the rotation outcome is unknown. */ + 503: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; }; }; getAuthMe: { @@ -6064,6 +6118,15 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; + /** @description server.error, retryable. The per-user lock was not acquired in time and the change was not applied. */ + 503: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; }; }; postUserDisable: { @@ -6113,6 +6176,15 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; + /** @description server.error, retryable. The per-user lock was not acquired in time and the change was not applied. */ + 503: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; }; }; postUserEnable: { @@ -6153,6 +6225,15 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; + /** @description server.error, retryable. The per-user lock was not acquired in time and the change was not applied. */ + 503: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; }; }; postRolesCreate: { diff --git a/internal/audit/events.gen.go b/internal/audit/events.gen.go index 251cdde5..645ab286 100644 --- a/internal/audit/events.gen.go +++ b/internal/audit/events.gen.go @@ -25,7 +25,7 @@ const ( const ( // User authenticated successfully AuthLoginSuccess Code = "auth.login.success" - // Authentication attempt failed + // Authentication attempt failed, or a presented credential was refused. reason names why. Password login records wrong_password, unknown_user, account_disabled, mfa_required, mfa_invalid, mfa_required_during_login or password_changed_during_login. The binders record the session, access-token and account-state reasons. SSO records the sso_ reasons, and sso_account_disabled or sso_account_deleted when the local account may not sign in; the sign-in page stays generic. account_state_unavailable and session_lookup_failed mean the server could not tell, and the request answered 503, not 401. invalid_credentials, account_locked, mfa_failed and sso_failed are legacy values that nothing records now; older rows may carry them. username is the submitted name, clipped. remote_addr and user_agent are recorded by the binders, the user agent clipped. AuthLoginFailure Code = "auth.login.failure" // User explicitly logged out. One login family is ended, located by the request's cookies. anchor names which cookie selected it. target_conflict is true when both cookies resolved to different families; only the session cookie's family was revoked. No credential values are recorded. AuthLogout Code = "auth.logout" @@ -350,9 +350,9 @@ var Metadata = map[Code]EventMeta{ Code: AuthLoginFailure, Category: "auth", Severity: SeverityWarning, - Description: `Authentication attempt failed`, + Description: `Authentication attempt failed, or a presented credential was refused. reason names why. Password login records wrong_password, unknown_user, account_disabled, mfa_required, mfa_invalid, mfa_required_during_login or password_changed_during_login. The binders record the session, access-token and account-state reasons. SSO records the sso_ reasons, and sso_account_disabled or sso_account_deleted when the local account may not sign in; the sign-in page stays generic. account_state_unavailable and session_lookup_failed mean the server could not tell, and the request answered 503, not 401. invalid_credentials, account_locked, mfa_failed and sso_failed are legacy values that nothing records now; older rows may carry them. username is the submitted name, clipped. remote_addr and user_agent are recorded by the binders, the user agent clipped.`, ActorTypes: []string{"user"}, - DetailKeys: []string{"auth_method", "reason"}, + DetailKeys: []string{"auth_method", "reason", "remote_addr", "user_agent", "username"}, }, AuthLogout: { Code: AuthLogout, diff --git a/internal/identity/account_state_test.go b/internal/identity/account_state_test.go index b63dfc02..9741f0ba 100644 --- a/internal/identity/account_state_test.go +++ b/internal/identity/account_state_test.go @@ -236,8 +236,11 @@ type fakeTx struct { } func (f *fakeTx) QueryRow(context.Context, string, ...any) pgx.Row { return fakeRow{err: f.lockErr} } -func (f *fakeTx) Commit(context.Context) error { return f.commitErr } -func (f *fakeTx) Rollback(context.Context) error { return nil } +func (f *fakeTx) Exec(context.Context, string, ...any) (pgconn.CommandTag, error) { + return pgconn.CommandTag{}, nil +} +func (f *fakeTx) Commit(context.Context) error { return f.commitErr } +func (f *fakeTx) Rollback(context.Context) error { return nil } type fakeRow struct{ err error } @@ -287,6 +290,20 @@ func TestRunSerialized_BoundedRetryAndUnknownCommit(t *testing.T) { } }) + t.Run("lock wait exceeded is determinate and not retried", func(t *testing.T) { + b := &countingBeginner{failWith: []error{pgErr("55P03")}} + err := RunSerialized(context.Background(), b, uid, noop) + if !errors.Is(err, ErrLockWaitExceeded) { + t.Fatalf("want ErrLockWaitExceeded, got %v", err) + } + if errors.Is(err, ErrCommitUnknown) { + t.Error("a lock timeout was classified as an unknown commit") + } + if b.attempts != 1 { + t.Errorf("attempts = %d, want 1: a lock timeout is not retried", b.attempts) + } + }) + t.Run("retryable, exhausts three attempts", func(t *testing.T) { b := &countingBeginner{failWith: []error{pgErr("40001"), pgErr("40001"), pgErr("40001"), pgErr("40001")}} err := RunSerialized(context.Background(), b, uid, noop) diff --git a/internal/identity/revoke.go b/internal/identity/revoke.go index 517b8ae3..93d1710e 100644 --- a/internal/identity/revoke.go +++ b/internal/identity/revoke.go @@ -2,7 +2,9 @@ package identity import ( "context" + "errors" "fmt" + "time" "github.com/google/uuid" "github.com/jackc/pgx/v5" @@ -61,11 +63,44 @@ func RevokeUserCredentialsPool(ctx context.Context, pool *pgxpool.Pool, userID u // // A missing user row is reported as pgx.ErrNoRows so the caller can // treat it as a determinate refusal. Spec C-34. +// +// The wait is bounded by LockWaitBound. Without a bound nothing ends it: +// the http.Server WriteTimeout does not cancel a handler, so a request +// blocked here waited until its client disconnected. A wait that exceeds +// the bound returns ErrLockWaitExceeded, a determinate failure: the +// transaction made no change. Spec C-43. func LockUser(ctx context.Context, tx pgx.Tx, userID uuid.UUID) error { + // set_config with is_local=true is SET LOCAL: it lasts until the + // transaction ends and cannot leak to the pooled connection. + if _, err := tx.Exec(ctx, `SELECT set_config('lock_timeout', $1, true)`, + fmt.Sprintf("%dms", LockWaitBound.Milliseconds())); err != nil { + return fmt.Errorf("identity: set lock wait bound: %w", err) + } var one int if err := tx.QueryRow(ctx, `SELECT 1 FROM users WHERE id = $1 FOR NO KEY UPDATE`, userID).Scan(&one); err != nil { + var pgErr *pgconn.PgError + if errors.As(err, &pgErr) && pgErr.Code == sqlStateLockNotAvailable { + return fmt.Errorf("%w: %w", ErrLockWaitExceeded, err) + } return err } return nil } + +// LockWaitBound caps how long a credential transaction waits for the +// per-user lock. The lock is held only across short database statements: +// password hashing and every network call run outside it by design +// (C-39), so a wait this long means a stuck holder rather than ordinary +// contention. It leaves most of the 60 s http.Server WriteTimeout for the +// response that reports the failure. Spec C-43. +const LockWaitBound = 5 * time.Second + +// ErrLockWaitExceeded reports that the per-user lock was not acquired +// within LockWaitBound. Nothing was read or changed under the lock, so +// the caller may say that nothing happened and that a retry is safe. +var ErrLockWaitExceeded = errors.New("identity: per-user lock wait exceeded") + +// sqlStateLockNotAvailable is what PostgreSQL raises when lock_timeout +// expires. +const sqlStateLockNotAvailable = "55P03" diff --git a/internal/server/auth_handlers.go b/internal/server/auth_handlers.go index 6cc5f20d..dd0ff0de 100644 --- a/internal/server/auth_handlers.go +++ b/internal/server/auth_handlers.go @@ -286,6 +286,9 @@ func (h *handlers) PostAuthLogout(w http.ResponseWriter, r *http.Request) { // is indeterminate. It is NOT a failure: the family may already be // revoked. Spec C-37, C-40. revokeUnknown := false + // lockWaitExceeded is set when the per-user lock was not acquired + // within identity.LockWaitBound. Nothing was revoked. + lockWaitExceeded := false // Logout ends ONE login family, located by the cookies the request // carries. The session cookie is consulted first: that is the @@ -350,6 +353,13 @@ func (h *handlers) PostAuthLogout(w http.ResponseWriter, r *http.Request) { return identity.RevokeLogoutFamily(ctx, tx, t) }) switch { + case errors.Is(txErr, identity.ErrLockWaitExceeded): + // The lock was never acquired, so nothing was read or + // revoked. Distinct from a revocation that failed: this one + // never started, and a retry is safe. Spec C-43. + lockWaitExceeded = true + slog.WarnContext(r.Context(), "logout: per-user lock not acquired in time; nothing was revoked", + slog.String("user_id", owner.String())) case errors.Is(txErr, identity.ErrCommitUnknown): // The commit may have applied. Neither success nor rollback // is asserted, here or in the response. @@ -398,6 +408,16 @@ func (h *handlers) PostAuthLogout(w http.ResponseWriter, r *http.Request) { // rather than reporting a clean logout: the client needs to know the // credential may still be live so a human can revoke the session // explicitly or rotate. + if lockWaitExceeded { + // Nothing was revoked, and the response says so. The cookies are + // still cleared above: the web client treats every logout + // response as signed out, so keeping them would leave a working + // session in a browser the user believes is signed out. A retry + // is safe for a client that still holds the values. Spec C-43. + writeError(w, http.StatusServiceUnavailable, "server.error", "server", + "signed out on this device, but sign-out did not reach the server in time and nothing was revoked. The session may remain valid until it expires. Revoke it from Settings.", true) + return + } if revokeUnknown { // Not retryable, and no claim either way. Spec C-40. writeError(w, http.StatusServiceUnavailable, "server.error", "server", diff --git a/internal/server/closure_regressions_test.go b/internal/server/closure_regressions_test.go new file mode 100644 index 00000000..963cafbc --- /dev/null +++ b/internal/server/closure_regressions_test.go @@ -0,0 +1,790 @@ +// @spec system-auth-identity +// +// Regressions promoted from the first integrated closure run for +// bugs/OW-069 and bugs/doing/OW-073 (bugs/doing/OW-062 section 14.8). +// +// Attribution. A before-and-after count cannot say who wrote a row. These +// tests snapshot the user's credential row IDs before the coordinating +// mutation, again right after it, and once more after the attempt. The +// coordinator's own changes are asserted separately, and any ID that +// appears after the coordinator ran belongs to the attempt. + +package server + +import ( + "bytes" + "context" + "encoding/json" + "io" + "net/http" + "strings" + "sync" + "testing" + "time" + + "github.com/Hanalyx/openwatch/internal/auth" + "github.com/Hanalyx/openwatch/internal/identity" + "github.com/Hanalyx/openwatch/internal/users" + "github.com/google/uuid" + "github.com/jackc/pgx/v5" + pgerr "github.com/jackc/pgx/v5/pgconn" + "github.com/jackc/pgx/v5/pgxpool" +) + +// hookedBeginner runs a hook before each transaction begins and, when set, +// replaces Commit. attempt counts from 1 across RunSerialized's retries. +type hookedBeginner struct { + inner identity.TxBeginner + mu sync.Mutex + n int + beforeBegin func(attempt int) + atCommit func(attempt int, tx pgx.Tx) error +} + +type hookedTx struct { + pgx.Tx + commit func(pgx.Tx) error +} + +func (h *hookedTx) Commit(context.Context) error { return h.commit(h.Tx) } + +func (b *hookedBeginner) Begin(ctx context.Context) (pgx.Tx, error) { + b.mu.Lock() + b.n++ + attempt := b.n + b.mu.Unlock() + if b.beforeBegin != nil { + b.beforeBegin(attempt) + } + tx, err := b.inner.Begin(ctx) + if err != nil || b.atCommit == nil { + return tx, err + } + return &hookedTx{Tx: tx, commit: func(inner pgx.Tx) error { return b.atCommit(attempt, inner) }}, nil +} + +func (b *hookedBeginner) attempts() int { + b.mu.Lock() + defer b.mu.Unlock() + return b.n +} + +// credentialRows maps each of a user's session and refresh rows, by ID, +// to whether it is revoked. +type credentialRows struct { + sessions map[uuid.UUID]bool + refresh map[uuid.UUID]bool +} + +func snapshotCredentials(t *testing.T, pool *pgxpool.Pool, uid uuid.UUID) credentialRows { + t.Helper() + read := func(table string) map[uuid.UUID]bool { + rows, err := pool.Query(context.Background(), + `SELECT id, revoked_at IS NOT NULL FROM `+table+` WHERE user_id = $1`, uid) + if err != nil { + t.Fatalf("snapshot %s: %v", table, err) + } + defer rows.Close() + out := map[uuid.UUID]bool{} + for rows.Next() { + var id uuid.UUID + var revoked bool + if err := rows.Scan(&id, &revoked); err != nil { + t.Fatalf("scan %s: %v", table, err) + } + out[id] = revoked + } + return out + } + return credentialRows{sessions: read("sessions"), refresh: read("refresh_tokens")} +} + +// added returns the IDs present in c and absent from earlier. +func (c credentialRows) added(earlier credentialRows) (sessions, refresh []uuid.UUID) { + for id := range c.sessions { + if _, ok := earlier.sessions[id]; !ok { + sessions = append(sessions, id) + } + } + for id := range c.refresh { + if _, ok := earlier.refresh[id]; !ok { + refresh = append(refresh, id) + } + } + return sessions, refresh +} + +func (c credentialRows) live() (sessions, refresh int) { + for _, revoked := range c.sessions { + if !revoked { + sessions++ + } + } + for _, revoked := range c.refresh { + if !revoked { + refresh++ + } + } + return sessions, refresh +} + +func (c credentialRows) equal(o credentialRows) bool { + same := func(a, b map[uuid.UUID]bool) bool { + if len(a) != len(b) { + return false + } + for k, v := range a { + if w, ok := b[k]; !ok || w != v { + return false + } + } + return true + } + return same(c.sessions, o.sessions) && same(c.refresh, o.refresh) +} + +// apiResult is a response read in full: status, the error envelope's +// code and retryable flag, the JSON body, and every Set-Cookie. +type apiResult struct { + status int + code string + retryable bool + body map[string]any + cookies []*http.Cookie +} + +func doAPI(t *testing.T, req *http.Request) apiResult { + t.Helper() + resp := doReq(t, req) + defer resp.Body.Close() + raw, _ := io.ReadAll(resp.Body) + var body map[string]any + _ = json.Unmarshal(raw, &body) + res := apiResult{status: resp.StatusCode, body: body, cookies: resp.Cookies()} + if e, ok := body["error"].(map[string]any); ok { + res.code, _ = e["code"].(string) + res.retryable, _ = e["retryable"].(bool) + } + return res +} + +// setsCredential reports a non-empty session or refresh cookie. +func (r apiResult) setsCredential() bool { + for _, c := range r.cookies { + if (c.Name == identity.SessionCookieName || c.Name == identity.RefreshCookieName) && c.Value != "" { + return true + } + } + return false +} + +// clearsCredential reports a session or refresh cookie being cleared. +func (r apiResult) clearsCredential() bool { + for _, c := range r.cookies { + if (c.Name == identity.SessionCookieName || c.Name == identity.RefreshCookieName) && c.Value == "" { + return true + } + } + return false +} + +// carriesToken reports an access or refresh token in the response body. +func (r apiResult) carriesToken() bool { + for _, k := range []string{"access_token", "refresh_token"} { + if v, _ := r.body[k].(string); v != "" { + return true + } + } + return false +} + +func loginRequest(url, username, password string, otp *string) *http.Request { + m := map[string]string{"username": username, "password": password} + if otp != nil { + m["otp"] = *otp + } + bs, _ := json.Marshal(m) + req, _ := http.NewRequest("POST", url+"/api/v1/auth/login", bytes.NewReader(bs)) + req.Header.Set("Content-Type", "application/json") + return req +} + +func bodyRefreshRequest(url, token string) *http.Request { + bs, _ := json.Marshal(map[string]string{"refresh_token": token}) + req, _ := http.NewRequest("POST", url+"/api/v1/auth/refresh", bytes.NewReader(bs)) + req.Header.Set("Content-Type", "application/json") + return req +} + +func cookieRefreshRequest(url string, rc *http.Cookie) *http.Request { + req, _ := http.NewRequest("POST", url+"/api/v1/auth/refresh-cookie", nil) + req.AddCookie(rc) + req.AddCookie(&http.Cookie{Name: "XSRF-TOKEN", Value: "closure-csrf"}) + req.Header.Set("X-CSRF-Token", "closure-csrf") + return req +} + +func logoutRequest(url string, session, refresh *http.Cookie) *http.Request { + req, _ := http.NewRequest("POST", url+"/api/v1/auth/logout", nil) + req.AddCookie(session) + req.AddCookie(refresh) + req.AddCookie(&http.Cookie{Name: "XSRF-TOKEN", Value: "closure-csrf"}) + req.Header.Set("X-CSRF-Token", "closure-csrf") + return req +} + +// holdUserLock takes the per-user lock on a second connection. The +// returned release is idempotent, and a safety timer releases the lock +// after max so a missing bound fails the test instead of hanging it. +func holdUserLock(t *testing.T, pool *pgxpool.Pool, uid uuid.UUID, max time.Duration) (release func()) { + t.Helper() + ctx := context.Background() + holder, err := pool.Begin(ctx) + if err != nil { + t.Fatalf("begin holder: %v", err) + } + if err := identity.LockUser(ctx, holder, uid); err != nil { + t.Fatalf("hold the lock: %v", err) + } + var once sync.Once + release = func() { once.Do(func() { _ = holder.Rollback(ctx) }) } + timer := time.AfterFunc(max, release) + t.Cleanup(func() { timer.Stop(); release() }) + return release +} + +// @ac AC-73 +// AC-73: the per-user lock wait is bounded in the production +// configuration. A request that cannot take the lock answers a retryable +// 503 once the bound expires and decides nothing. +func TestLockWait_BoundedInProductionConfiguration(t *testing.T) { + t.Run("system-auth-identity/AC-73", func(t *testing.T) { + url, pool := freshAPIServer(t) + for _, path := range []string{"login", "body refresh", "cookie refresh", "logout", "admin disable"} { + path := path + t.Run(path, func(t *testing.T) { + t.Parallel() + li := loginFresh(t, url, pool, "ac73"+strings.ReplaceAll(path, " ", "")) + var req *http.Request + switch path { + case "login": + req = loginRequest(url, li.u.Username, li.u.Password, nil) + case "body refresh": + req = bodyRefreshRequest(url, li.bodyRefresh) + case "cookie refresh": + req = cookieRefreshRequest(url, li.refreshCookie) + case "logout": + req = logoutRequest(url, li.sessionCookie, li.refreshCookie) + case "admin disable": + req = asRole(t, "POST", url+"/api/v1/users/"+li.u.ID.String()+":disable", auth.RoleAdmin, nil) + } + before := snapshotCredentials(t, pool, li.u.ID) + release := holdUserLock(t, pool, li.u.ID, identity.LockWaitBound+15*time.Second) + start := time.Now() + got := doAPI(t, req) + elapsed := time.Since(start) + release() + + if got.status != http.StatusServiceUnavailable || got.code != "server.error" || !got.retryable { + t.Errorf("response = %d %q retryable=%v, want 503 server.error retryable", got.status, got.code, got.retryable) + } + if elapsed < identity.LockWaitBound-250*time.Millisecond || elapsed > identity.LockWaitBound+10*time.Second { + t.Errorf("answered after %v; the bound is %v", elapsed, identity.LockWaitBound) + } + if after := snapshotCredentials(t, pool, li.u.ID); !after.equal(before) { + t.Error("credential rows changed although the lock was never acquired") + } + if got.setsCredential() || got.carriesToken() { + t.Error("the response issued a credential") + } + // Logout clears the cookies on every outcome (C-43); no + // other path may. + if cleared := got.clearsCredential(); cleared != (path == "logout") { + t.Errorf("credential cookies cleared = %v", cleared) + } + if path == "admin disable" && isDisabled(t, pool, li.u.ID) { + t.Error("the account was disabled although the change reported not applied") + } + if code := authMe(t, url, li.sessionCookie); code != http.StatusOK { + t.Errorf("the presented session no longer works: %d", code) + } + }) + } + }) +} + +// @ac AC-74 +// AC-74: a refresh racing Disable leaves nothing usable once Disable +// returns, in both orders and on both refresh paths. +func TestRefreshRacingDisable_LeavesNothingUsable(t *testing.T) { + t.Run("system-auth-identity/AC-74", func(t *testing.T) { + url, pool, srv := freshAPIServerWithHandles(t) + ctx := context.Background() + svc := users.NewService(pool, nil) + for _, path := range []string{"body", "cookie"} { + path := path + request := func(li loggedInUser) *http.Request { + if path == "body" { + return bodyRefreshRequest(url, li.bodyRefresh) + } + return cookieRefreshRequest(url, li.refreshCookie) + } + + t.Run(path+": disable commits before the refresh takes the lock", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac74first"+path) + var afterCoordinator credentialRows + hb := &hookedBeginner{inner: pool, beforeBegin: func(attempt int) { + if attempt == 1 { + if err := svc.Disable(ctx, li.u.ID); err != nil { + t.Errorf("disable: %v", err) + } + afterCoordinator = snapshotCredentials(t, pool, li.u.ID) + } + }} + srv.handlers.serializer = hb + got := doAPI(t, request(li)) + srv.handlers.serializer = nil + + if got.status == http.StatusOK || got.setsCredential() || got.carriesToken() { + t.Errorf("refresh after a committed disable answered %d and issued a credential", got.status) + } + if s, r := snapshotCredentials(t, pool, li.u.ID).added(afterCoordinator); len(s)+len(r) != 0 { + t.Errorf("the refresh wrote %d sessions and %d refresh rows after the disable", len(s), len(r)) + } + if s, r := snapshotCredentials(t, pool, li.u.ID).live(); s+r != 0 { + t.Errorf("live credentials after disable: %d/%d", s, r) + } + }) + + t.Run(path+": refresh holds the lock while disable waits", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac74second"+path) + before := snapshotCredentials(t, pool, li.u.ID) + disabled := make(chan error, 1) + hb := &hookedBeginner{inner: pool, atCommit: func(attempt int, inner pgx.Tx) error { + go func() { disabled <- svc.Disable(ctx, li.u.ID) }() + if !waitForUserLockWaiter(t, pool) { + t.Error("disable never queued behind the refresh") + } + return inner.Commit(ctx) + }} + srv.handlers.serializer = hb + got := doAPI(t, request(li)) + srv.handlers.serializer = nil + if err := <-disabled; err != nil { + t.Fatalf("disable: %v", err) + } + if got.status != http.StatusOK { + t.Fatalf("precondition: the refresh holding the lock should commit, got %d", got.status) + } + after := snapshotCredentials(t, pool, li.u.ID) + // Attributed: the rows the refresh wrote, by ID. + s, r := after.added(before) + if len(s)+len(r) == 0 { + t.Fatal("precondition: the committed refresh wrote no successor") + } + for _, id := range s { + if !after.sessions[id] { + t.Errorf("the refresh's session %s is live after disable returned", id) + } + } + for _, id := range r { + if !after.refresh[id] { + t.Errorf("the refresh's successor token %s is live after disable returned", id) + } + } + if access, _ := got.body["access_token"].(string); access != "" && authMeBearer(t, url, access) != http.StatusUnauthorized { + t.Error("the successor access token authenticates after disable returned") + } + if authMeBearer(t, url, li.accessToken) != http.StatusUnauthorized { + t.Error("the predecessor access token authenticates after disable returned") + } + }) + } + }) +} + +// @ac AC-75 +// AC-75: credentials revoked by Disable stay dead after Enable, and only a +// fresh sign-in works. +func TestEnable_DoesNotReviveWhatDisableRevoked(t *testing.T) { + t.Run("system-auth-identity/AC-75", func(t *testing.T) { + url, pool := freshAPIServer(t) + ctx := context.Background() + svc := users.NewService(pool, nil) + li := loginFresh(t, url, pool, "ac75revived") + if err := svc.Disable(ctx, li.u.ID); err != nil { + t.Fatalf("disable: %v", err) + } + if err := svc.Enable(ctx, li.u.ID); err != nil { + t.Fatalf("enable: %v", err) + } + if code := authMe(t, url, li.sessionCookie); code != http.StatusUnauthorized { + t.Errorf("session cookie after disable and enable = %d, want 401", code) + } + if code := authMeBearer(t, url, li.accessToken); code != http.StatusUnauthorized { + t.Errorf("access token after disable and enable = %d, want 401", code) + } + if code, _ := refreshBody(t, url, li.bodyRefresh); code == http.StatusOK { + t.Error("body refresh token rotated after disable and enable") + } + if code, sess := refreshCookie(t, url, li.refreshCookie); code == http.StatusOK || sess != nil { + t.Error("refresh cookie minted a session after disable and enable") + } + if !freshLoginWorks(t, url, li.u) { + t.Error("a fresh sign-in after enable did not work") + } + }) +} + +// waitForLockWaiters waits until n requests are queued on a row lock. +func waitForLockWaiters(t *testing.T, pool *pgxpool.Pool, n int) bool { + t.Helper() + deadline := time.Now().Add(20 * time.Second) + for time.Now().Before(deadline) { + var c int + if err := pool.QueryRow(context.Background(), ` + SELECT count(*) FROM pg_stat_activity + WHERE wait_event_type = 'Lock' AND query ILIKE '%FOR NO KEY UPDATE%' + AND pid <> pg_backend_pid()`).Scan(&c); err == nil && c >= n { + return true + } + time.Sleep(20 * time.Millisecond) + } + return false +} + +// @ac AC-76 +// AC-76: MFA is decided under the lock. Two logins presenting one code +// issue once; a secret rotated before the lock refuses the old code; an +// enrollment removed before the lock lets the login issue without +// consuming anything (C-39). +func TestMFA_DecidedUnderTheLock(t *testing.T) { + t.Run("system-auth-identity/AC-76", func(t *testing.T) { + url, pool, srv := freshAPIServerWithHandles(t) + ctx := context.Background() + + t.Run("same code, two logins serialized", func(t *testing.T) { + f := enrolledUser(t, url, pool, "ac76twice") + code := f.otp(t) + before := snapshotCredentials(t, pool, f.li.u.ID) + otpBefore := otpUseCount(t, pool, f.li.u.ID) + release := holdUserLock(t, pool, f.li.u.ID, 30*time.Second) + results := make(chan loginOutcome, 2) + for i := 0; i < 2; i++ { + go func() { results <- loginFor(t, url, f.li.u.Username, f.li.u.Password, &code) }() + } + if !waitForLockWaiters(t, pool, 2) { + t.Fatal("both logins did not queue on the lock") + } + release() + a, b := <-results, <-results + ok := 0 + for _, r := range []loginOutcome{a, b} { + if r.status == http.StatusOK { + ok++ + } else if r.code != "auth.mfa_invalid" { + t.Errorf("refused login answered %q, want auth.mfa_invalid", r.code) + } + } + if ok != 1 { + t.Errorf("successful logins = %d, want 1", ok) + } + s, r := snapshotCredentials(t, pool, f.li.u.ID).added(before) + if len(s) != 1 || len(r) != 1 { + t.Errorf("rows written = %d sessions, %d refresh; want 1 and 1", len(s), len(r)) + } + if got := otpUseCount(t, pool, f.li.u.ID) - otpBefore; got != 1 { + t.Errorf("otp uses recorded = %d, want 1", got) + } + }) + + t.Run("secret rotated before the lock", func(t *testing.T) { + f := enrolledUser(t, url, pool, "ac76rotated") + code := f.otp(t) + before := snapshotCredentials(t, pool, f.li.u.ID) + otpBefore := otpUseCount(t, pool, f.li.u.ID) + srv.handlers.serializer = &hookedBeginner{inner: pool, beforeBegin: func(attempt int) { + if attempt != 1 { + return + } + if _, err := identity.EnrollMFA(ctx, pool, f.li.u.ID, f.li.u.Username); err != nil { + t.Errorf("rotate: %v", err) + } + if _, err := pool.Exec(ctx, `UPDATE auth_mfa_secrets SET last_verified_at = now() WHERE user_id = $1`, f.li.u.ID); err != nil { + t.Errorf("confirm rotation: %v", err) + } + }} + got := loginFor(t, url, f.li.u.Username, f.li.u.Password, &code) + srv.handlers.serializer = nil + if got.status == http.StatusOK || got.code != "auth.mfa_invalid" { + t.Errorf("old-secret code after rotation = %d %q, want 401 auth.mfa_invalid", got.status, got.code) + } + if s, r := snapshotCredentials(t, pool, f.li.u.ID).added(before); len(s)+len(r) != 0 { + t.Errorf("rows written = %d sessions, %d refresh; want none", len(s), len(r)) + } + if got := otpUseCount(t, pool, f.li.u.ID) - otpBefore; got != 0 { + t.Errorf("otp uses recorded = %d, want 0", got) + } + }) + + t.Run("enrollment removed before the lock", func(t *testing.T) { + f := enrolledUser(t, url, pool, "ac76removed") + code := f.otp(t) + before := snapshotCredentials(t, pool, f.li.u.ID) + otpBefore := otpUseCount(t, pool, f.li.u.ID) + srv.handlers.serializer = &hookedBeginner{inner: pool, beforeBegin: func(attempt int) { + if attempt == 1 { + if _, err := pool.Exec(ctx, `DELETE FROM auth_mfa_secrets WHERE user_id = $1`, f.li.u.ID); err != nil { + t.Errorf("remove enrollment: %v", err) + } + } + }} + got := loginFor(t, url, f.li.u.Username, f.li.u.Password, &code) + srv.handlers.serializer = nil + if got.status != http.StatusOK { + t.Errorf("login after the enrollment was removed = %d %q, want 200 (C-39)", got.status, got.code) + } + if s, r := snapshotCredentials(t, pool, f.li.u.ID).added(before); len(s) != 1 || len(r) != 1 { + t.Errorf("rows written = %d sessions, %d refresh; want 1 and 1", len(s), len(r)) + } + if got := otpUseCount(t, pool, f.li.u.ID) - otpBefore; got != 0 { + t.Errorf("otp uses recorded = %d, want 0: no secret, nothing to consume", got) + } + }) + }) +} + +// @ac AC-77 +// AC-77: a retried transaction acts on the state it reads on the retry, +// not on what the lost attempt read. +func TestSerializedRetry_ActsOnTheNewState(t *testing.T) { + t.Run("system-auth-identity/AC-77", func(t *testing.T) { + url, pool, srv := freshAPIServerWithHandles(t) + ctx := context.Background() + svc := users.NewService(pool, nil) + for _, state := range []string{"40P01", "40001"} { + state := state + t.Run(state, func(t *testing.T) { + u := seedAuthUser(t, svc, "ac77"+strings.ToLower(state), false) + _ = svc.AssignRole(ctx, u.ID, "viewer", nil) + before := snapshotCredentials(t, pool, u.ID) + hb := &hookedBeginner{inner: pool, atCommit: func(attempt int, inner pgx.Tx) error { + if attempt == 1 { + _ = inner.Rollback(ctx) + if err := svc.Disable(ctx, u.ID); err != nil { + t.Errorf("disable between attempts: %v", err) + } + return &pgerr.PgError{Code: state} + } + return inner.Commit(ctx) + }} + srv.handlers.serializer = hb + got := doAPI(t, loginRequest(url, u.Username, u.Password, nil)) + srv.handlers.serializer = nil + if hb.attempts() != 2 { + t.Errorf("transactions begun = %d, want 2", hb.attempts()) + } + if got.status != http.StatusUnauthorized || got.setsCredential() || got.carriesToken() { + t.Errorf("login retried after the account was disabled = %d, want 401 with nothing issued", got.status) + } + if s, r := snapshotCredentials(t, pool, u.ID).added(before); len(s)+len(r) != 0 { + t.Errorf("rows written = %d sessions, %d refresh; want none", len(s), len(r)) + } + }) + } + }) +} + +// @ac AC-78 +// AC-78: every password and refresh issuance path, paused after its +// pre-lock reads and released after an invalidating mutation commits, +// issues nothing. +func TestProtocolOrder_NothingIssuedFromInvalidatedState(t *testing.T) { + t.Run("system-auth-identity/AC-78", func(t *testing.T) { + url, pool, srv := freshAPIServerWithHandles(t) + ctx := context.Background() + svc := users.NewService(pool, nil) + coordinators := map[string]func(uuid.UUID) error{ + "disable": func(id uuid.UUID) error { return svc.Disable(ctx, id) }, + "password reset": func(id uuid.UUID) error { return svc.AdminResetPassword(ctx, id, "ac78-reset-Passphrase-4410") }, // pragma: allowlist secret + } + for _, path := range []string{"login", "login with mfa", "body refresh", "cookie refresh"} { + for _, coordinator := range []string{"disable", "password reset"} { + path, coordinator := path, coordinator + t.Run(path+" against "+coordinator, func(t *testing.T) { + name := "ac78" + strings.NewReplacer(" ", "").Replace(path+coordinator) + var li loggedInUser + var otp *string + if path == "login with mfa" { + f := enrolledUser(t, url, pool, name) + li = f.li + c := f.otp(t) + otp = &c + } else { + li = loginFresh(t, url, pool, name) + } + var req *http.Request + switch path { + case "login", "login with mfa": + req = loginRequest(url, li.u.Username, li.u.Password, otp) + case "body refresh": + req = bodyRefreshRequest(url, li.bodyRefresh) + case "cookie refresh": + req = cookieRefreshRequest(url, li.refreshCookie) + } + before := snapshotCredentials(t, pool, li.u.ID) + otpBefore := otpUseCount(t, pool, li.u.ID) + var afterCoordinator credentialRows + var coordErr error + srv.handlers.serializer = &hookedBeginner{inner: pool, beforeBegin: func(attempt int) { + if attempt == 1 { + coordErr = coordinators[coordinator](li.u.ID) + afterCoordinator = snapshotCredentials(t, pool, li.u.ID) + } + }} + got := doAPI(t, req) + srv.handlers.serializer = nil + if coordErr != nil { + t.Fatalf("%s: %v", coordinator, coordErr) + } + // The coordinator's changes, enumerated: it inserts nothing + // and revokes every row that was live. + if s, r := afterCoordinator.added(before); len(s)+len(r) != 0 { + t.Errorf("%s inserted %d sessions and %d refresh rows", coordinator, len(s), len(r)) + } + if s, r := afterCoordinator.live(); s+r != 0 { + t.Errorf("%s left %d/%d live", coordinator, s, r) + } + // The attempt's own rows: anything after the coordinator. + if s, r := snapshotCredentials(t, pool, li.u.ID).added(afterCoordinator); len(s)+len(r) != 0 { + t.Errorf("the %s wrote %d sessions and %d refresh rows", path, len(s), len(r)) + } + if got.status == http.StatusOK || got.setsCredential() || got.carriesToken() { + t.Errorf("the %s answered %d and issued a credential", path, got.status) + } + if n := otpUseCount(t, pool, li.u.ID) - otpBefore; n != 0 { + t.Errorf("the attempt consumed %d one-time codes", n) + } + }) + } + } + }) +} + +// @ac AC-79 +// AC-79: a rotation whose commit fails reports no credential, sets no +// cookie, and leaves the presented token usable. +func TestRefresh_NothingReportedBeforeCommit(t *testing.T) { + t.Run("system-auth-identity/AC-79", func(t *testing.T) { + url, pool, srv := freshAPIServerWithHandles(t) + ctx := context.Background() + for _, path := range []string{"body", "cookie"} { + path := path + t.Run(path, func(t *testing.T) { + li := loginFresh(t, url, pool, "ac79"+path) + req := func() *http.Request { + if path == "body" { + return bodyRefreshRequest(url, li.bodyRefresh) + } + return cookieRefreshRequest(url, li.refreshCookie) + } + before := snapshotCredentials(t, pool, li.u.ID) + srv.handlers.serializer = &hookedBeginner{inner: pool, atCommit: func(_ int, inner pgx.Tx) error { + _ = inner.Rollback(ctx) + return &pgerr.PgError{Code: "23505"} // a known rollback + }} + got := doAPI(t, req()) + srv.handlers.serializer = nil + if got.status != http.StatusServiceUnavailable || got.code != "server.error" { + t.Errorf("response = %d %q, want 503 server.error", got.status, got.code) + } + if got.carriesToken() || got.setsCredential() { + t.Error("a credential was reported although its transaction did not commit") + } + if !snapshotCredentials(t, pool, li.u.ID).equal(before) { + t.Error("credential rows changed although the transaction rolled back") + } + if again := doAPI(t, req()); again.status != http.StatusOK { + t.Errorf("the presented token no longer rotates after the rollback: %d", again.status) + } + }) + } + }) +} + +// @ac AC-34 +// AC-34, end to end: a live, unrevoked session cookie is refused by the +// account-state check, each state recording its own reason on the +// request's own audit row. +func TestCookieBinder_AccountStateEndToEnd(t *testing.T) { + t.Run("system-auth-identity/AC-34", func(t *testing.T) { + url, pool := freshAPIServer(t) + ctx := context.Background() + for _, tc := range []struct { + name, stmt, reason string + status int + }{ + {"disabled", `UPDATE users SET disabled_at = now() WHERE id = $1`, "account_disabled", 401}, + {"soft deleted", `UPDATE users SET deleted_at = now() WHERE id = $1`, "account_deleted", 401}, + {"active without roles", `DELETE FROM user_roles WHERE user_id = $1`, "session_user_lookup_failed", 401}, + {"active control", ``, "", 200}, + } { + tc := tc + t.Run(tc.name, func(t *testing.T) { + li := loginFresh(t, url, pool, "ac34e2e"+strings.ReplaceAll(tc.name, " ", "")) + if tc.stmt != "" { + if _, err := pool.Exec(ctx, tc.stmt, li.u.ID); err != nil { + t.Fatalf("set account state: %v", err) + } + } + code, cid := authMeCookieCorrelated(t, url, li.sessionCookie) + if code != tc.status { + t.Errorf("status = %d, want %d", code, tc.status) + } + if tc.reason != "" { + if got := loginFailureReasonFor(t, pool, cid); got != tc.reason { + t.Errorf("audit reason = %q, want %q", got, tc.reason) + } + } + }) + } + }) +} + +// @ac AC-36 +// AC-36, Bearer arm: when the binding lookup itself fails, the answer is +// 503, not 401, and the token works again once the lookup recovers. +func TestBearer_LookupFailureIs503(t *testing.T) { + t.Run("system-auth-identity/AC-36", func(t *testing.T) { + url, pool := freshAPIServer(t) + ctx := context.Background() + li := loginFresh(t, url, pool, "ac36bearer") + if code := authMeBearer(t, url, li.accessToken); code != http.StatusOK { + t.Fatalf("precondition: token = %d, want 200", code) + } + if _, err := pool.Exec(ctx, `ALTER TABLE sessions RENAME TO sessions_ac36`); err != nil { + t.Fatalf("break the binding lookup: %v", err) + } + restored := false + restore := func() { + if !restored { + if _, err := pool.Exec(ctx, `ALTER TABLE sessions_ac36 RENAME TO sessions`); err != nil { + t.Fatalf("restore sessions: %v", err) + } + restored = true + } + } + t.Cleanup(restore) + code, cid := authMeBearerCorrelated(t, url, li.accessToken) + restore() + if code != http.StatusServiceUnavailable { + t.Errorf("Bearer request with the lookup failing = %d, want 503", code) + } + if got := loginFailureReasonFor(t, pool, cid); got != "session_lookup_failed" { + t.Errorf("audit reason = %q, want session_lookup_failed", got) + } + if code := authMeBearer(t, url, li.accessToken); code != http.StatusOK { + t.Errorf("token after the lookup recovered = %d, want 200", code) + } + }) +} diff --git a/internal/server/login_failure_vocabulary_test.go b/internal/server/login_failure_vocabulary_test.go new file mode 100644 index 00000000..e596f983 --- /dev/null +++ b/internal/server/login_failure_vocabulary_test.go @@ -0,0 +1,191 @@ +// @spec system-auth-identity + +package server + +import ( + "go/ast" + "go/parser" + "go/token" + "os" + "sort" + "strconv" + "strings" + "testing" + + "gopkg.in/yaml.v3" +) + +// loginFailureReasonSources are the files that produce the reason recorded +// on auth.login.failure. A reason produced anywhere else is invisible to +// this scan, which is the scan's known limit. +var loginFailureReasonSources = []string{ + "../identity/binder.go", + "../identity/account_state.go", + "auth_handlers.go", + "sso_handlers.go", +} + +// reasonReturningFuncs name functions whose string returns ARE reasons. +var reasonReturningFuncs = map[string]bool{ + "Reason": true, + "ssoFailureReason": true, + "ssoRefusalReason": true, + "unavailableReason": false, +} + +// reasonVariables name the variables and fields a reason is assigned to +// before it is emitted. +var reasonVariables = map[string]bool{"reason": true, "loginRefused": true, "refused": true} + +func stringLit(e ast.Expr) (string, bool) { + lit, ok := e.(*ast.BasicLit) + if !ok || lit.Kind != token.STRING { + return "", false + } + v, err := strconv.Unquote(lit.Value) + return v, err == nil +} + +// emittedLoginFailureReasons collects every string literal that reaches +// detail.reason through the shapes the four source files use. +func emittedLoginFailureReasons(t *testing.T) map[string]string { + t.Helper() + found := map[string]string{} + fset := token.NewFileSet() + for _, path := range loginFailureReasonSources { + f, err := parser.ParseFile(fset, path, nil, 0) + if err != nil { + t.Fatalf("parse %s: %v", path, err) + } + add := func(e ast.Expr) { + if v, ok := stringLit(e); ok && v != "" { + found[v] = fset.Position(e.Pos()).String() + } + } + for _, decl := range f.Decls { + switch d := decl.(type) { + case *ast.GenDecl: + // const reasonX = "..." + for _, spec := range d.Specs { + vs, ok := spec.(*ast.ValueSpec) + if !ok || d.Tok != token.CONST { + continue + } + for i, name := range vs.Names { + if strings.HasPrefix(name.Name, "reason") && i < len(vs.Values) { + add(vs.Values[i]) + } + } + } + case *ast.FuncDecl: + inReasonFunc := reasonReturningFuncs[d.Name.Name] + ast.Inspect(d, func(n ast.Node) bool { + switch x := n.(type) { + case *ast.ReturnStmt: + // return "..." inside a reason function + if inReasonFunc && len(x.Results) == 1 { + add(x.Results[0]) + } + // return anon(), "..." + if len(x.Results) == 2 { + if call, ok := x.Results[0].(*ast.CallExpr); ok { + if id, ok := call.Fun.(*ast.Ident); ok && id.Name == "anon" { + add(x.Results[1]) + } + } + } + case *ast.CallExpr: + // emitLoginFailure(r, "...", ...) + if id, ok := x.Fun.(*ast.Ident); ok && id.Name == "emitLoginFailure" && len(x.Args) >= 2 { + add(x.Args[1]) + } + case *ast.AssignStmt: + // reason = "...", loginRefused = "...", res.refused = "..." + for i, lhs := range x.Lhs { + name := "" + switch l := lhs.(type) { + case *ast.Ident: + name = l.Name + case *ast.SelectorExpr: + name = l.Sel.Name + } + if reasonVariables[name] && i < len(x.Rhs) { + add(x.Rhs[i]) + } + } + } + return true + }) + } + } + } + return found +} + +func declaredLoginFailureReasons(t *testing.T) map[string]bool { + t.Helper() + raw, err := os.ReadFile("../../audit/events.yaml") + if err != nil { + t.Fatalf("read events.yaml: %v", err) + } + var doc struct { + Events []struct { + Code string `yaml:"code"` + DetailSchema struct { + Properties map[string]struct { + Enum []string `yaml:"enum"` + } `yaml:"properties"` + } `yaml:"detail_schema"` + } `yaml:"events"` + } + if err := yaml.Unmarshal(raw, &doc); err != nil { + t.Fatalf("parse events.yaml: %v", err) + } + for _, e := range doc.Events { + if e.Code == "auth.login.failure" { + out := map[string]bool{} + for _, v := range e.DetailSchema.Properties["reason"].Enum { + out[v] = true + } + return out + } + } + t.Fatal("auth.login.failure is not declared in events.yaml") + return nil +} + +// @ac AC-80 +// AC-80: every reason the code can record on auth.login.failure is +// declared in the audit contract. The emitter checks key names only, so +// without this an undeclared reason passes silently. +func TestLoginFailureReasons_AreDeclared(t *testing.T) { + t.Run("system-auth-identity/AC-80", func(t *testing.T) { + emitted := emittedLoginFailureReasons(t) + declared := declaredLoginFailureReasons(t) + // The scan must see the shapes it claims to. These are reasons + // known to be emitted, one per shape. + for _, must := range []string{ + "account_state_unavailable", // const reason* + "invalid_jwt", // return anon(), "..." + "session_owner_mismatch", // Reason() method + "wrong_password", // assignment to reason + "mfa_required", // emitLoginFailure literal + "sso_account_disabled", // ssoFailureReason + } { + if _, ok := emitted[must]; !ok { + t.Errorf("the scan did not see %q; it no longer reads that shape", must) + } + } + var missing []string + for v, pos := range emitted { + if !declared[v] { + missing = append(missing, v+" ("+pos+")") + } + } + sort.Strings(missing) + if len(missing) > 0 { + t.Errorf("reasons recorded on auth.login.failure but not declared in audit/events.yaml:\n %s", + strings.Join(missing, "\n ")) + } + }) +} diff --git a/internal/server/session_binding_gaps_test.go b/internal/server/session_binding_gaps_test.go index e300e7b0..3bd212e7 100644 --- a/internal/server/session_binding_gaps_test.go +++ b/internal/server/session_binding_gaps_test.go @@ -63,10 +63,11 @@ func TestBearer_RefusesASessionOwnedByAnotherUser(t *testing.T) { if _, verr := identity.VerifyJWT(crossed); verr != nil { t.Fatalf("the crossed token must be cryptographically valid, got %v", verr) } - if code := authMeBearer(t, url, crossed); code != http.StatusUnauthorized { + code, cid := authMeBearerCorrelated(t, url, crossed) + if code != http.StatusUnauthorized { t.Errorf("crossed token = %d, want 401: a token must not bind a session it does not own", code) } - if reason := lastLoginFailureReason(t, pool); reason != "session_owner_mismatch" { + if reason := loginFailureReasonFor(t, pool, cid); reason != "session_owner_mismatch" { t.Errorf("audit reason = %q, want session_owner_mismatch", reason) } }) @@ -240,10 +241,11 @@ func TestBearer_ExemptFromIdleBoundedByAbsolute(t *testing.T) { WHERE user_id = $1`, li.u.ID); err != nil { t.Fatalf("age the absolute deadline: %v", err) } - if code := authMeBearer(t, url, li.accessToken); code != http.StatusUnauthorized { + code, cid := authMeBearerCorrelated(t, url, li.accessToken) + if code != http.StatusUnauthorized { t.Errorf("status = %d, want 401 past the absolute deadline", code) } - if reason := lastLoginFailureReason(t, pool); reason != "session_absolute_expired" { + if reason := loginFailureReasonFor(t, pool, cid); reason != "session_absolute_expired" { t.Errorf("audit reason = %q, want session_absolute_expired", reason) } }) diff --git a/internal/server/session_binding_test.go b/internal/server/session_binding_test.go index 15b15eca..818b9616 100644 --- a/internal/server/session_binding_test.go +++ b/internal/server/session_binding_test.go @@ -8,8 +8,8 @@ package server import ( "context" - "errors" "net/http" + "strings" "testing" "time" @@ -17,7 +17,6 @@ import ( "github.com/Hanalyx/openwatch/internal/identity" "github.com/Hanalyx/openwatch/internal/users" "github.com/google/uuid" - "github.com/jackc/pgx/v5" "github.com/jackc/pgx/v5/pgxpool" ) @@ -113,7 +112,8 @@ func TestAccessToken_BindingIsRequiredAndAlwaysIssued(t *testing.T) { if _, err := identity.VerifyJWT(unbound); err != nil { t.Fatalf("the unbound token must be otherwise valid, got %v", err) } - if code := authMeBearer(t, url, unbound); code != http.StatusUnauthorized { + code, cid := authMeBearerCorrelated(t, url, unbound) + if code != http.StatusUnauthorized { t.Errorf("unbound access token = %d, want 401", code) } // The REASON matters. An empty sid also fails UUID parsing, so a @@ -122,7 +122,7 @@ func TestAccessToken_BindingIsRequiredAndAlwaysIssued(t *testing.T) { // look for a malformed token; "sid_absent" says a client is // minting tokens with no binding at all. The vocabulary is the // recorded one (OW-062 section 4). - if reason := lastLoginFailureReason(t, pool); reason != "sid_absent" { + if reason := loginFailureReasonFor(t, pool, cid); reason != "sid_absent" { t.Errorf("audit reason for an unbound token = %q, want sid_absent", reason) } @@ -144,34 +144,65 @@ func TestAccessToken_BindingIsRequiredAndAlwaysIssued(t *testing.T) { }) } -// lastLoginFailureReason reads the most recent auth.login.failure -// reason. The audit writer batches, so it polls until the reading stops -// changing rather than returning on the first row. -func lastLoginFailureReason(t *testing.T, pool *pgxpool.Pool) string { +// authMeBearerCorrelated presents a Bearer token on GET /auth/me with a +// unique X-Correlation-Id and returns the status and that id. The id is +// what ties an audit row to THIS request (bugs/OW-075). +func authMeBearerCorrelated(t *testing.T, url, token string) (int, string) { t.Helper() - deadline := time.Now().Add(5 * time.Second) - last := "" - stable := 0 + cid := "ac-" + strings.ReplaceAll(uuid.NewString(), "-", "") + req, _ := http.NewRequest("GET", url+"/api/v1/auth/me", nil) + req.Header.Set("Authorization", "Bearer "+token) + req.Header.Set("X-Correlation-Id", cid) + resp := doReq(t, req) + defer resp.Body.Close() + return resp.StatusCode, cid +} + +// authMeCookieCorrelated is the cookie-path equivalent. +func authMeCookieCorrelated(t *testing.T, url string, c *http.Cookie) (int, string) { + t.Helper() + cid := "ac-" + strings.ReplaceAll(uuid.NewString(), "-", "") + req, _ := http.NewRequest("GET", url+"/api/v1/auth/me", nil) + req.AddCookie(c) + req.Header.Set("X-Correlation-Id", cid) + resp := doReq(t, req) + defer resp.Body.Close() + return resp.StatusCode, cid +} + +// loginFailureReasonFor returns the reason on the ONE auth.login.failure +// row the request with this correlation id produced. It waits, bounded, +// for that row to land, because the audit writer batches, and fails the +// test when the row never appears or when the request produced more than +// one. It never falls back to another request's row. bugs/OW-075. +func loginFailureReasonFor(t *testing.T, pool *pgxpool.Pool, correlationID string) string { + t.Helper() + deadline := time.Now().Add(10 * time.Second) for { - var reason string - err := pool.QueryRow(context.Background(), ` + rows, err := pool.Query(context.Background(), ` SELECT COALESCE(detail->>'reason','') FROM audit_events - WHERE action = 'auth.login.failure' - ORDER BY occurred_at DESC, id DESC LIMIT 1`).Scan(&reason) - if err != nil && !errors.Is(err, pgx.ErrNoRows) { + WHERE action = 'auth.login.failure' AND correlation_id = $1`, correlationID) + if err != nil { t.Fatalf("read audit: %v", err) } - if reason == last && reason != "" { - stable++ - if stable >= 2 { - return reason + var reasons []string + for rows.Next() { + var r string + if err := rows.Scan(&r); err != nil { + t.Fatalf("scan audit: %v", err) } - } else { - stable = 0 - last = reason + reasons = append(reasons, r) + } + rows.Close() + if len(reasons) > 1 { + t.Fatalf("request %s recorded %d login failures, want 1: %v", correlationID, len(reasons), reasons) + } + if len(reasons) == 1 { + return reasons[0] } if time.Now().After(deadline) { - return last + t.Fatalf("request %s recorded no auth.login.failure within 10s", correlationID) } + time.Sleep(50 * time.Millisecond) } } diff --git a/internal/server/sso_account_state_test.go b/internal/server/sso_account_state_test.go index 0801d820..00b27ff3 100644 --- a/internal/server/sso_account_state_test.go +++ b/internal/server/sso_account_state_test.go @@ -26,6 +26,7 @@ import ( "net/http" "net/http/httptest" "net/url" + "strings" "testing" "time" @@ -164,6 +165,9 @@ type ssoCallbackResult struct { // all is every Set-Cookie on the callback response, including any // with an empty value, so a test can see a cookie being CLEARED. all []*http.Cookie + // correlationID was sent on the callback, so its audit rows can be + // read without mistaking another request's (bugs/OW-075). + correlationID string } // ssoSignIn drives the real login redirect and the real callback. @@ -191,13 +195,17 @@ func ssoSignIn(t *testing.T, base string, pool *pgxpool.Pool, d *ssoTestIDP, p s `SELECT nonce FROM sso_auth_states WHERE state = $1`, state).Scan(&d.nonce); err != nil { t.Fatalf("read persisted nonce: %v", err) } - cbResp, err := cl.Get(fmt.Sprintf("%s/api/v1/auth/sso/%s/callback?code=%s&state=%s", - base, p.ID.String(), "test-code", url.QueryEscape(state))) + // A unique correlation id ties this callback's audit rows to it. + cid := "sso-" + strings.ReplaceAll(uuid.NewString(), "-", "") + cbReq, _ := http.NewRequest("GET", fmt.Sprintf("%s/api/v1/auth/sso/%s/callback?code=%s&state=%s", + base, p.ID.String(), "test-code", url.QueryEscape(state)), nil) + cbReq.Header.Set("X-Correlation-Id", cid) + cbResp, err := cl.Do(cbReq) if err != nil { t.Fatalf("callback: %v", err) } cbResp.Body.Close() - res := ssoCallbackResult{status: cbResp.StatusCode, location: cbResp.Header.Get("Location")} + res := ssoCallbackResult{status: cbResp.StatusCode, location: cbResp.Header.Get("Location"), correlationID: cid} res.all = cbResp.Cookies() for _, c := range cbResp.Cookies() { switch c.Name { diff --git a/internal/server/sso_closure_test.go b/internal/server/sso_closure_test.go new file mode 100644 index 00000000..f380e722 --- /dev/null +++ b/internal/server/sso_closure_test.go @@ -0,0 +1,153 @@ +// @spec system-sso +// +// SSO regressions promoted from the first integrated closure run for +// bugs/doing/OW-073 (bugs/doing/OW-062 criteria AC-78 and AC-90). + +package server + +import ( + "context" + "net/http" + "testing" + + "github.com/Hanalyx/openwatch/internal/auth" + "github.com/Hanalyx/openwatch/internal/users" + "github.com/google/uuid" +) + +// @ac AC-12 +// AC-12: a refused federated sign-in records WHICH account state refused +// it, on the callback's own audit row, while the sign-in page stays +// generic. +func TestSSO_RefusalAuditNamesTheAccountState(t *testing.T) { + t.Run("system-sso/AC-12", func(t *testing.T) { + for _, tc := range []struct { + name, subject, reason string + transform func(*users.Service, uuid.UUID) error + }{ + {"disabled", "sub-ac12-disabled", "sso_account_disabled", + func(svc *users.Service, id uuid.UUID) error { return svc.Disable(context.Background(), id) }}, + {"soft-deleted", "sub-ac12-deleted", "sso_account_deleted", + func(svc *users.Service, id uuid.UUID) error { return svc.SoftDelete(context.Background(), id) }}, + } { + tc := tc + t.Run(tc.name, func(t *testing.T) { + base, pool, d, p := ssoFixture(t) + ctx := context.Background() + svc := users.NewService(pool, nil) + d.sub, d.email = tc.subject, tc.subject+"@example.test" + if first := ssoSignIn(t, base, pool, d, p); first.sessionCookie == nil { + t.Fatalf("precondition: the first sign-in must succeed, got %q", first.location) + } + var uid uuid.UUID + if err := pool.QueryRow(ctx, `SELECT user_id FROM sso_identities WHERE subject = $1`, tc.subject).Scan(&uid); err != nil { + t.Fatalf("no federation link: %v", err) + } + if err := tc.transform(svc, uid); err != nil { + t.Fatalf("%s: %v", tc.name, err) + } + res := ssoSignIn(t, base, pool, d, p) + if res.location != "/login?sso_error=signin" || res.sessionCookie != nil || res.refreshCookie != nil { + t.Errorf("refused sign-in = %q (session %v); want /login?sso_error=signin and no cookies", + res.location, res.sessionCookie != nil) + } + if got := loginFailureReasonFor(t, pool, res.correlationID); got != tc.reason { + t.Errorf("audit reason = %q, want %q", got, tc.reason) + } + }) + } + }) +} + +// @ac AC-13 +// AC-13: an account disabled between the provisioning commit and the +// issuance lock gets nothing, keeps its provisioned row, and a later +// callback reuses that row. A password reset in the same window does not +// block issuance, because a federated sign-in does not use the password. +func TestSSO_ProvisioningRace(t *testing.T) { + t.Run("system-sso/AC-13", func(t *testing.T) { + base, pool, d, p, srv := ssoFixtureWithServer(t) + ctx := context.Background() + svc := users.NewService(pool, nil) + linkedUser := func(subject string) uuid.UUID { + var uid uuid.UUID + if err := pool.QueryRow(ctx, `SELECT user_id FROM sso_identities WHERE subject = $1`, subject).Scan(&uid); err != nil { + t.Fatalf("no federation link for %s: %v", subject, err) + } + return uid + } + + t.Run("disabled before the issuance lock", func(t *testing.T) { + d.sub, d.email = "sub-ac13-disabled", "ac13-disabled@example.test" + srv.handlers.serializer = &hookedBeginner{inner: pool, beforeBegin: func(attempt int) { + if attempt == 1 { + if err := svc.Disable(ctx, linkedUser(d.sub)); err != nil { + t.Errorf("disable: %v", err) + } + } + }} + res := ssoSignIn(t, base, pool, d, p) + srv.handlers.serializer = nil + uid := linkedUser(d.sub) + + if res.location != "/login?sso_error=signin" || res.sessionCookie != nil || res.refreshCookie != nil { + t.Errorf("callback = %q (session %v); want /login?sso_error=signin and no cookies", res.location, res.sessionCookie != nil) + } + // The user did not exist before this callback, so every + // credential row for it would be the attempt's. + if rows := snapshotCredentials(t, pool, uid); len(rows.sessions)+len(rows.refresh) != 0 { + t.Errorf("rows written for the provisioned user: %d sessions, %d refresh", len(rows.sessions), len(rows.refresh)) + } + var deleted bool + if err := pool.QueryRow(ctx, `SELECT deleted_at IS NOT NULL FROM users WHERE id = $1`, uid).Scan(&deleted); err != nil || deleted { + t.Errorf("the provisioned user row is not intact (deleted=%v, err=%v)", deleted, err) + } + if got := loginFailureReasonFor(t, pool, res.correlationID); got != "sso_account_disabled" { + t.Errorf("audit reason = %q, want sso_account_disabled", got) + } + + // Re-enabled, a later callback finds the same user. + if err := svc.Enable(ctx, uid); err != nil { + t.Fatalf("enable: %v", err) + } + _ = svc.AssignRole(ctx, uid, auth.RoleID("viewer"), nil) + later := ssoSignIn(t, base, pool, d, p) + if later.sessionCookie == nil { + t.Errorf("later callback = %q, want a session", later.location) + } + var usersWithEmail, links int + _ = pool.QueryRow(ctx, `SELECT count(*) FROM users WHERE email = $1`, d.email).Scan(&usersWithEmail) + _ = pool.QueryRow(ctx, `SELECT count(*) FROM sso_identities WHERE subject = $1`, d.sub).Scan(&links) + if usersWithEmail != 1 || links != 1 { + t.Errorf("later callback re-provisioned: %d users, %d links", usersWithEmail, links) + } + }) + + t.Run("password reset before the issuance lock", func(t *testing.T) { + d.sub, d.email = "sub-ac13-reset", "ac13-reset@example.test" + if first := ssoSignIn(t, base, pool, d, p); first.sessionCookie == nil { + t.Fatalf("precondition: provisioning sign-in must succeed, got %q", first.location) + } + uid := linkedUser(d.sub) + before := snapshotCredentials(t, pool, uid) + srv.handlers.serializer = &hookedBeginner{inner: pool, beforeBegin: func(attempt int) { + if attempt == 1 { + if err := svc.AdminResetPassword(ctx, uid, "ac13-reset-Passphrase-7781"); err != nil { // pragma: allowlist secret + t.Errorf("reset: %v", err) + } + } + }} + res := ssoSignIn(t, base, pool, d, p) + srv.handlers.serializer = nil + if res.sessionCookie == nil { + t.Errorf("callback after a password reset = %q, want a session", res.location) + } + if s, _ := snapshotCredentials(t, pool, uid).added(before); len(s) != 1 { + t.Errorf("sessions written by the callback = %d, want 1", len(s)) + } + if res.sessionCookie != nil && authMe(t, base, res.sessionCookie) != http.StatusOK { + t.Error("the session issued after the reset does not authenticate") + } + }) + }) +} diff --git a/internal/server/sso_handlers.go b/internal/server/sso_handlers.go index 278c73fd..82e52c6f 100644 --- a/internal/server/sso_handlers.go +++ b/internal/server/sso_handlers.go @@ -257,10 +257,14 @@ func (h *handlers) GetAuthSSOCallback(w http.ResponseWriter, r *http.Request, id refresh string ssoSess identity.Session ssoRefused bool + // refusedStatus is the state that refused issuance, for the + // audit reason only. + refusedStatus identity.AccountStatus ) txErr := identity.RunSerialized(r.Context(), h.serialized(), result.UserID, func(ctx context.Context, tx pgx.Tx) error { // Reset per attempt: RunSerialized may restart the transaction. sessionToken, refresh, ssoRefused = "", "", false + refusedStatus = identity.AccountUnknown ssoSess = identity.Session{} status, err := identity.ReadAccountStatus(ctx, tx, result.UserID) @@ -269,6 +273,7 @@ func (h *handlers) GetAuthSSOCallback(w http.ResponseWriter, r *http.Request, id } if !status.MayAuthenticate() { ssoRefused = true + refusedStatus = status return nil } var err2 error @@ -310,7 +315,7 @@ func (h *handlers) GetAuthSSOCallback(w http.ResponseWriter, r *http.Request, id if ssoRefused { // The account was disabled or deleted between resolution and // issuance. Nothing was written. - emitLoginFailure(r, "sso_account_not_active", "") + emitLoginFailure(r, ssoRefusalReason(refusedStatus), "") http.Redirect(w, r, "/login?sso_error=signin", http.StatusFound) return } @@ -388,12 +393,35 @@ func ssoFailureReason(err error) string { case errors.Is(err, sso.ErrDiscovery): return "sso_discovery_failed" case errors.Is(err, sso.ErrAccountNotActive): + // The audit record names the state; the sign-in page does not. + var notActive *sso.AccountNotActiveError + if errors.As(err, ¬Active) { + switch notActive.State { + case sso.AccountStateDisabled: + return "sso_account_disabled" + case sso.AccountStateDeleted: + return "sso_account_deleted" + } + } return "sso_account_not_active" default: return "sso_signin_failed" } } +// ssoRefusalReason names the account state that refused issuance under +// the lock, in the same vocabulary as ssoFailureReason. +func ssoRefusalReason(s identity.AccountStatus) string { + switch s { + case identity.AccountDisabled: + return "sso_account_disabled" + case identity.AccountDeleted: + return "sso_account_deleted" + default: + return "sso_account_not_active" + } +} + func deref(p *string) string { if p == nil { return "" diff --git a/internal/server/users_admin_handlers.go b/internal/server/users_admin_handlers.go index edd4ddcc..86f40dee 100644 --- a/internal/server/users_admin_handlers.go +++ b/internal/server/users_admin_handlers.go @@ -31,6 +31,11 @@ func mapUserAdminErr(w http.ResponseWriter, err error) bool { return false case errors.Is(err, users.ErrUserNotFound): writeError(w, http.StatusNotFound, "users.not_found", "client", "user not found", false) + case errors.Is(err, identity.ErrLockWaitExceeded): + // The per-user lock was not acquired in time, so the change was + // not applied. Retrying is safe. Spec system-auth-identity C-43. + writeError(w, http.StatusServiceUnavailable, "server.error", "server", + "the change was not applied because the account could not be locked in time. Try again.", true) case errors.Is(err, identity.ErrPasswordTooShort), errors.Is(err, identity.ErrPasswordTooLong), errors.Is(err, identity.ErrPasswordBreached): diff --git a/internal/sso/flow.go b/internal/sso/flow.go index 9f721607..10859df8 100644 --- a/internal/sso/flow.go +++ b/internal/sso/flow.go @@ -55,7 +55,7 @@ func (s *Service) HandleCallback(ctx context.Context, state, redirectURI, code s if uid, found, state, err := s.linkedUserState(ctx, st.ProviderID, claims.Subject); err != nil { return CallbackResult{}, err } else if found && !state.MaySignIn() { - return CallbackResult{}, fmt.Errorf("%w: %s", ErrAccountNotActive, state) + return CallbackResult{}, &AccountNotActiveError{State: state} } else if found { return CallbackResult{UserID: uid, RedirectTo: st.RedirectTo}, nil } diff --git a/internal/sso/types.go b/internal/sso/types.go index 7feed3b8..8fc33517 100644 --- a/internal/sso/types.go +++ b/internal/sso/types.go @@ -25,6 +25,7 @@ package sso import ( "errors" + "fmt" "time" "github.com/google/uuid" @@ -138,6 +139,21 @@ const ( AccountStateDeleted ) +// AccountNotActiveError is the refusal for a federated identity whose +// local account may not sign in. It unwraps to ErrAccountNotActive and +// carries the state, so the audit record can name disabled or deleted +// while the sign-in page stays generic. bugs/OW-073, OW-062 AC-90. +type AccountNotActiveError struct { + State AccountState +} + +func (e *AccountNotActiveError) Error() string { + return fmt.Sprintf("%s: %s", ErrAccountNotActive, e.State) +} + +// Unwrap lets errors.Is match ErrAccountNotActive. +func (e *AccountNotActiveError) Unwrap() error { return ErrAccountNotActive } + // MaySignIn reports whether this state permits a federated sign-in. func (a AccountState) MaySignIn() bool { return a == AccountStateActive } diff --git a/specs/system/auth-identity.spec.yaml b/specs/system/auth-identity.spec.yaml index ae9d4bf9..080d882b 100644 --- a/specs/system/auth-identity.spec.yaml +++ b/specs/system/auth-identity.spec.yaml @@ -1,7 +1,7 @@ spec: id: system-auth-identity title: Auth identity primitives (password, session, JWT, MFA) - version: "1.8.0" + version: "1.9.0" status: approved tier: 1 @@ -91,7 +91,13 @@ spec: type: security enforcement: error - id: C-11 - description: Identity binder MUST emit auth.login.failure with detail.reason populated on every rejected authentication attempt + description: > + Identity binder MUST emit auth.login.failure with detail.reason + populated on every rejected authentication attempt. Every reason any + path records on that event MUST be declared in the event's + detail_schema in audit/events.yaml. The emitter checks key names + only, so an undeclared reason would pass silently; AC-80 checks the + vocabulary against the source. type: security enforcement: error - id: C-12 @@ -380,6 +386,30 @@ spec: refresh is provided for it. type: security enforcement: error + - id: C-43 + description: > + The wait for the per-user lock MUST be bounded in the production + configuration, not only under test. Nothing else bounds it: the + http.Server WriteTimeout does not cancel a handler, so a request + blocked on the lock waited until its client disconnected. The bound + is identity.LockWaitBound, 5 seconds, applied as a transaction-local + lock_timeout by the lock helper itself, so every path that takes the + lock inherits it, the administrative account mutations included. + The lock is held only across short database statements (C-39 keeps + password hashing and network calls outside it), so a wait that long + means a stuck holder, and the bound leaves most of the 60 second + WriteTimeout for the response. A wait that exceeds the bound is a + determinate failure: nothing was read under the lock and nothing + changed. It MUST be reported as 503 server.error with retryable + true, distinct from a revocation that failed and rolled back (logout + 500 auth.logout_incomplete) and from an unknown commit outcome (503 + with retryable false). Logout still clears both credential cookies + in that case, as it does for every outcome: the web client treats + any logout response as signed out, so a kept cookie would leave a + working session in a browser the user believes is signed out. The + message says nothing was revoked. + type: security + enforcement: error acceptance_criteria: - id: AC-01 @@ -1673,3 +1703,144 @@ spec: revoked_by_enable: false Permanently revoked: authenticates_after_enable: false + + - id: AC-73 + description: > + The per-user lock wait is bounded in the production configuration. + A request that cannot take the lock answers 503 server.error with + retryable true once the bound expires, and decides nothing. + priority: critical + references_constraints: [C-34, C-43] + inputs: + initial_state: "A second connection holds the per-user lock for longer than the bound" + operation: "Login, body refresh, cookie refresh, logout, and administrative disable" + method: > + Each path runs against the unmodified server, with no test + override of the lock timeout. A safety timer releases the held + lock well after the bound, so a missing bound fails the test + instead of hanging it. + expected_output: + response: {status: 503, code: server.error, retryable: true} + answered_after: "The bound, not before it" + durable_changes: [] + logout_cookies: "Cleared, as for every logout outcome" + prohibited_changes: + - "A credential issued or revoked" + - "A credential cookie set, or cleared by any path other than logout" + - "The account disabled although the change was reported not applied" + subsequent: ["The presented session still authenticates"] + + - id: AC-74 + description: > + A refresh racing Disable leaves nothing usable once Disable returns, + in both orders and on both refresh paths. + priority: critical + references_constraints: [C-34, C-36] + inputs: + variants: + - "Disable commits after the refresh's pre-lock reads and before it takes the lock" + - "The refresh holds the lock, Disable queues behind it, the refresh commits" + attribution: "Credential rows by ID: before, after the coordinator, after the attempt" + expected_output: + first_order: "The refresh is refused and writes no row" + second_order: "Every row the refresh wrote is revoked once Disable returns" + prohibited_changes: ["Any predecessor or successor credential authenticating after Disable returns"] + + - id: AC-75 + description: > + Credentials revoked by Disable stay revoked after Enable. Only a fresh + sign-in works. + priority: critical + references_constraints: [C-36] + inputs: + initial_state: "A signed-in user" + operation: "Disable, then Enable, then present the pre-disable session cookie, access token and both refresh tokens" + expected_output: + credentials_authenticating: 0 + subsequent: ["A fresh sign-in succeeds"] + + - id: AC-76 + description: > + MFA is decided under the lock. Two logins presenting one code issue + once. A secret rotated after the pre-lock reads refuses the old + code. An enrollment removed after the pre-lock reads lets the login + issue without consuming anything, as C-39 requires. + priority: critical + references_constraints: [C-35, C-39] + inputs: + variants: + - "Same code, two logins serialized behind the lock" + - "Secret rotated and confirmed before the login takes the lock" + - "Enrollment removed before the login takes the lock" + expected_output: + same_code: {successful_logins: 1, refused_code: auth.mfa_invalid, otp_uses_added: 1, sessions_added: 1} + secret_rotated: {code: auth.mfa_invalid, rows_added: 0, otp_uses_added: 0} + enrollment_removed: {status: 200, sessions_added: 1, otp_uses_added: 0} + + - id: AC-77 + description: > + A retried transaction acts on the state it reads on the retry, not on + what the lost attempt read. + priority: critical + references_constraints: [C-37] + inputs: + variants: ["40P01 on the first attempt", "40001 on the first attempt"] + between_attempts: "The account is disabled through the real users service" + expected_output: + transactions_begun: 2 + response: {status: 401} + rows_added: 0 + + - id: AC-78 + description: > + Every password and refresh issuance path, paused after its pre-lock + reads and released after an invalidating mutation commits, issues + nothing. + priority: critical + references_constraints: [C-34, C-39] + inputs: + paths: ["Login", "Login with MFA", "Body refresh", "Cookie refresh"] + coordinators: ["Disable", "Administrative password reset"] + attribution: > + Credential row IDs are read before the coordinator, right after + it, and after the attempt. The coordinator's own changes are + asserted separately: it inserts nothing and revokes every live + row. Any ID that appears after it belongs to the attempt. + expected_output: + attempt_rows_added: 0 + otp_uses_added: 0 + prohibited_changes: ["A 200 response", "A credential cookie", "A token in the response body"] + structural_review: > + Reported separately and by hand: every reachable write to sessions + or refresh_tokens sits inside the locked protocol, except the idle + slide in VerifySession. + + - id: AC-79 + description: > + A rotation whose commit fails reports no credential, sets no cookie, + and leaves the presented token usable. + priority: critical + references_constraints: [C-34, C-37] + inputs: + variants: ["Body refresh", "Cookie refresh"] + controlled_failure: "The commit is a known rollback" + expected_output: + response: {status: 503, code: server.error} + credential_rows_changed: false + subsequent: ["The same token rotates on the next request"] + + - id: AC-80 + description: > + Every reason the code can record on auth.login.failure is declared + in the event's detail_schema in audit/events.yaml. + priority: high + references_constraints: [C-11] + inputs: + method: > + A source scan collects the literals that reach detail.reason + through the shapes the binder, the account-state verdicts and the + login, refresh and SSO handlers use. It first proves it still sees + one reason of each shape, then compares against the declaration. + known_limit: "A reason produced through a shape the scan does not read is invisible to it" + expected_output: + undeclared_reasons: [] diff --git a/specs/system/sso.spec.yaml b/specs/system/sso.spec.yaml index fe84aee7..5f49431f 100644 --- a/specs/system/sso.spec.yaml +++ b/specs/system/sso.spec.yaml @@ -1,7 +1,7 @@ spec: id: system-sso title: Single sign-on (OIDC) — provider store + authorization-code flow - version: "1.1.0" + version: "1.2.0" status: approved tier: 1 @@ -96,7 +96,11 @@ spec: that already has one. Issuance MUST additionally revalidate account state under the per-user lock, because a disable committing between resolution and issuance would otherwise produce a session that nothing - later revokes. + later revokes. The refusal MUST be recorded as a login failure whose + reason names the state, sso_account_disabled or sso_account_deleted, + on both refusal paths, while the sign-in page shows only the generic + /login?sso_error=signin. An account-state refusal is an + authentication refusal, not a session-creation failure. type: security enforcement: error @@ -260,3 +264,45 @@ spec: - "A credential cookie delivered without a confirmed commit" - "An automatic replay or restart of the sign-in" - "A log or audit event asserting success or rollback for an unknown outcome" + + - id: AC-12 + description: > + A refused federated sign-in records which account state refused it, + on the callback's own audit row, while the sign-in page stays + generic. + priority: high + references_constraints: [C-05] + inputs: + initial_state: "A federation link created by an earlier successful sign-in" + variants: ["Disabled through the users service", "Soft-deleted through the users service"] + attribution: "The callback carries its own correlation id and only that request's audit row is read" + expected_output: + response: "Redirect to /login?sso_error=signin" + cookies_set: false + audit_reason: + Disabled: sso_account_disabled + Soft-deleted: sso_account_deleted + + - id: AC-13 + description: > + An account disabled between the provisioning commit and the issuance + lock receives nothing and keeps its provisioned row, and a later + callback reuses that row. A password reset in the same window does + not block issuance, because a federated sign-in does not use the + password. + priority: critical + references_constraints: [C-05] + inputs: + variants: + - "Disable committed before the issuance transaction takes the lock" + - "Administrative password reset committed at the same point" + expected_output: + disable: + response: "Redirect to /login?sso_error=signin" + credential_rows_for_the_new_user: 0 + provisioned_user_row: "Intact" + audit_reason: sso_account_disabled + subsequent: ["After Enable, a later callback signs in and does not provision a second user or link"] + password_reset: + sessions_added: 1 + session_authenticates: true From 53c63832b0bd94142f41fdaf106dbdc94dd2a400 Mon Sep 17 00:00:00 2001 From: Remylus Losius Date: Thu, 24 Sep 2026 20:33:55 -0400 Subject: [PATCH 2/6] fix(auth): bound the whole credential operation and correct what the limits claim Review corrections to the lock-wait change, 2026-09-24. The transaction-local lock_timeout limits each lock acquisition separately, later implicit row locks included. It does not limit pool acquisition, the transaction or the request, and exceeding it shows only that a wait exceeded the limit. The comments and C-43 now say that, and no longer claim it proves a stuck holder or leaves 55 s of the WriteTimeout. An operation deadline (identity.OperationDeadline, 15 s) now covers RunSerialized as a whole, pool acquisition through the commit and any retries, and the users service's account-state, reset and enable transactions. It never extends an earlier caller deadline. A deadline that expires during a commit stays an unknown outcome, including in the users service, whose commit errors now go through the same classifier. A lock that times out after the per-user lock was held rolls back and is not reported as the account lock: logout answers 500 auth.logout_incomplete, the others a retryable 503. The admin mapping covers disable, enable, reset and soft delete, which now uses the shared mapping, and maps an unknown commit to a non-retryable 503. Logout's lock-timeout answer is no longer retryable: it clears the cookies, so a repeated request may name no family or a different one. Its message names the account lock rather than saying the request did not reach the server. Specs: system-auth-identity 1.9.0, C-43 rewritten, AC-73 extended to all eight paths, AC-81 and AC-82 added, and the added criteria given explicit response, cookie and audit expectations. The manual structural note is removed from AC-78. Found while testing, filed and not changed here: bugs/OW-077, the cookie binder's idle slide waits without limit on a locked session row. Refs: bugs/OW-069, bugs/doing/OW-073, bugs/doing/OW-062 AC-54, bugs/OW-077 --- .secrets.baseline | 4 +- api/openapi.yaml | 37 +++- frontend/src/api/schema.d.ts | 17 +- internal/identity/operation_deadline_test.go | 157 +++++++++++++++ internal/identity/revoke.go | 50 +++-- internal/identity/serialize.go | 19 ++ internal/server/auth_handlers.go | 7 +- internal/server/closure_regressions_test.go | 191 +++++++++++++++++-- internal/server/sso_closure_test.go | 2 +- internal/server/users_admin_handlers.go | 15 +- internal/server/users_handlers.go | 12 +- internal/users/users.go | 18 +- specs/system/auth-identity.spec.yaml | 189 ++++++++++++++---- 13 files changed, 611 insertions(+), 107 deletions(-) create mode 100644 internal/identity/operation_deadline_test.go diff --git a/.secrets.baseline b/.secrets.baseline index 5db56cb2..6d949a9e 100644 --- a/.secrets.baseline +++ b/.secrets.baseline @@ -149,7 +149,7 @@ "filename": "api/openapi.yaml", "hashed_secret": "6b1fe243c0b63c8e43d2545520492f2f5bc19869", "is_verified": false, - "line_number": 251 + "line_number": 253 } ], "cmd/openwatch/setup.go": [ @@ -809,5 +809,5 @@ } ] }, - "generated_at": "2026-09-24T21:34:13Z" + "generated_at": "2026-09-25T00:33:45Z" } diff --git a/api/openapi.yaml b/api/openapi.yaml index 0aaefa4b..60467f51 100644 --- a/api/openapi.yaml +++ b/api/openapi.yaml @@ -156,10 +156,12 @@ paths: $ref: '#/components/schemas/ErrorEnvelope' '503': description: >- - server.error. Two outcomes, told apart by retryable. Both cookies are - cleared in both. retryable true: the per-user lock was not acquired in - time and nothing was revoked; a retry is safe. retryable false: the - revocation outcome is unknown and neither outcome is asserted. + server.error, not retryable, and both cookies are cleared. Two outcomes, + told apart by the message. The account lock was not acquired in time: + this attempt revoked nothing. The commit outcome is unknown: revocation + could not be confirmed. Neither invites an automatic retry, because + with the cookies cleared a repeated request may name no family, or a + different one. content: application/json: schema: @@ -803,6 +805,15 @@ paths: content: application/json: schema: {$ref: '#/components/schemas/ErrorEnvelope'} + '503': + description: >- + server.error. retryable true: a lock wait exceeded its limit and the + transaction rolled back, so the user was not deleted. retryable false: + the commit outcome is unknown. + content: + application/json: + schema: + $ref: '#/components/schemas/ErrorEnvelope' /api/v1/users/{id}/roles:assign: post: @@ -879,8 +890,10 @@ paths: schema: {$ref: '#/components/schemas/ErrorEnvelope'} '503': description: >- - server.error, retryable. The per-user lock was not acquired in time and - the change was not applied. + server.error. retryable true: a lock wait exceeded its limit and the + transaction rolled back, so the change was not applied. retryable + false: the commit outcome is unknown, and the change may or may not + have been applied. content: application/json: schema: @@ -922,8 +935,10 @@ paths: schema: {$ref: '#/components/schemas/ErrorEnvelope'} '503': description: >- - server.error, retryable. The per-user lock was not acquired in time and - the change was not applied. + server.error. retryable true: a lock wait exceeded its limit and the + transaction rolled back, so the change was not applied. retryable + false: the commit outcome is unknown, and the change may or may not + have been applied. content: application/json: schema: @@ -959,8 +974,10 @@ paths: schema: {$ref: '#/components/schemas/ErrorEnvelope'} '503': description: >- - server.error, retryable. The per-user lock was not acquired in time and - the change was not applied. + server.error. retryable true: a lock wait exceeded its limit and the + transaction rolled back, so the change was not applied. retryable + false: the commit outcome is unknown, and the change may or may not + have been applied. content: application/json: schema: diff --git a/frontend/src/api/schema.d.ts b/frontend/src/api/schema.d.ts index ae2285d2..fe7953ec 100644 --- a/frontend/src/api/schema.d.ts +++ b/frontend/src/api/schema.d.ts @@ -5081,7 +5081,7 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; - /** @description server.error. Two outcomes, told apart by retryable. Both cookies are cleared in both. retryable true: the per-user lock was not acquired in time and nothing was revoked; a retry is safe. retryable false: the revocation outcome is unknown and neither outcome is asserted. */ + /** @description server.error, not retryable, and both cookies are cleared. Two outcomes, told apart by the message. The account lock was not acquired in time: this attempt revoked nothing. The commit outcome is unknown: revocation could not be confirmed. Neither invites an automatic retry, because with the cookies cleared a repeated request may name no family, or a different one. */ 503: { headers: { [name: string]: unknown; @@ -6010,6 +6010,15 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; + /** @description server.error. retryable true: a lock wait exceeded its limit and the transaction rolled back, so the user was not deleted. retryable false: the commit outcome is unknown. */ + 503: { + headers: { + [name: string]: unknown; + }; + content: { + "application/json": components["schemas"]["ErrorEnvelope"]; + }; + }; }; }; postUserRolesAssign: { @@ -6118,7 +6127,7 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; - /** @description server.error, retryable. The per-user lock was not acquired in time and the change was not applied. */ + /** @description server.error. retryable true: a lock wait exceeded its limit and the transaction rolled back, so the change was not applied. retryable false: the commit outcome is unknown, and the change may or may not have been applied. */ 503: { headers: { [name: string]: unknown; @@ -6176,7 +6185,7 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; - /** @description server.error, retryable. The per-user lock was not acquired in time and the change was not applied. */ + /** @description server.error. retryable true: a lock wait exceeded its limit and the transaction rolled back, so the change was not applied. retryable false: the commit outcome is unknown, and the change may or may not have been applied. */ 503: { headers: { [name: string]: unknown; @@ -6225,7 +6234,7 @@ export interface operations { "application/json": components["schemas"]["ErrorEnvelope"]; }; }; - /** @description server.error, retryable. The per-user lock was not acquired in time and the change was not applied. */ + /** @description server.error. retryable true: a lock wait exceeded its limit and the transaction rolled back, so the change was not applied. retryable false: the commit outcome is unknown, and the change may or may not have been applied. */ 503: { headers: { [name: string]: unknown; diff --git a/internal/identity/operation_deadline_test.go b/internal/identity/operation_deadline_test.go new file mode 100644 index 00000000..957b71dc --- /dev/null +++ b/internal/identity/operation_deadline_test.go @@ -0,0 +1,157 @@ +// @spec system-auth-identity + +package identity + +import ( + "context" + "errors" + "testing" + "time" + + "github.com/google/uuid" + "github.com/jackc/pgx/v5" + "github.com/jackc/pgx/v5/pgconn" +) + +// blockingTx blocks at the lock or at the commit until its context ends, +// then fails with the context's error, as a real driver does. +type blockingTx struct { + pgx.Tx + blockLock bool + blockCommit bool +} + +type ctxRow struct{ err error } + +func (r ctxRow) Scan(dest ...any) error { + if r.err != nil { + return r.err + } + if len(dest) > 0 { + if p, ok := dest[0].(*int); ok { + *p = 1 + } + } + return nil +} + +func (b *blockingTx) Exec(context.Context, string, ...any) (pgconn.CommandTag, error) { + return pgconn.CommandTag{}, nil +} + +func (b *blockingTx) QueryRow(ctx context.Context, _ string, _ ...any) pgx.Row { + if b.blockLock { + <-ctx.Done() + return ctxRow{err: ctx.Err()} + } + return ctxRow{} +} + +func (b *blockingTx) Commit(ctx context.Context) error { + if b.blockCommit { + <-ctx.Done() + return ctx.Err() + } + return nil +} + +func (b *blockingTx) Rollback(context.Context) error { return nil } + +type blockingBeginner struct { + begun int + blockLock bool + blockCommit bool +} + +func (b *blockingBeginner) Begin(context.Context) (pgx.Tx, error) { + b.begun++ + return &blockingTx{blockLock: b.blockLock, blockCommit: b.blockCommit}, nil +} + +// @ac AC-82 +// AC-82: RunSerialized bounds the whole operation, never extends an +// earlier caller deadline, reports a deadline that expires during the +// commit as an unknown outcome, and one that expires before it as a +// known failure. +func TestRunSerialized_OperationDeadline(t *testing.T) { + t.Run("system-auth-identity/AC-82", func(t *testing.T) { + uid := uuid.New() + + t.Run("establishes a deadline", func(t *testing.T) { + var deadline time.Time + var ok bool + start := time.Now() + err := RunSerialized(context.Background(), &blockingBeginner{}, uid, func(ctx context.Context, _ pgx.Tx) error { + deadline, ok = ctx.Deadline() + return nil + }) + if err != nil { + t.Fatalf("run: %v", err) + } + if !ok { + t.Fatal("the operation ran with no deadline") + } + if limit := start.Add(OperationDeadline); deadline.After(limit.Add(time.Second)) { + t.Errorf("deadline %v is later than the operation limit %v", deadline, limit) + } + }) + + t.Run("preserves an earlier caller deadline", func(t *testing.T) { + parent, cancel := context.WithTimeout(context.Background(), 200*time.Millisecond) + defer cancel() + want, _ := parent.Deadline() + var got time.Time + if err := RunSerialized(parent, &blockingBeginner{}, uid, func(ctx context.Context, _ pgx.Tx) error { + got, _ = ctx.Deadline() + return nil + }); err != nil { + t.Fatalf("run: %v", err) + } + if !got.Equal(want) { + t.Errorf("deadline = %v, want the caller's %v", got, want) + } + }) + + t.Run("expiry during the commit is an unknown outcome", func(t *testing.T) { + parent, cancel := context.WithTimeout(context.Background(), 200*time.Millisecond) + defer cancel() + b := &blockingBeginner{blockCommit: true} + err := RunSerialized(parent, b, uid, func(context.Context, pgx.Tx) error { return nil }) + if !errors.Is(err, ErrCommitUnknown) { + t.Errorf("err = %v, want ErrCommitUnknown", err) + } + if b.begun != 1 { + t.Errorf("transactions begun = %d, want 1: an unknown outcome is not retried", b.begun) + } + }) + + t.Run("expiry before the commit is a known failure", func(t *testing.T) { + parent, cancel := context.WithTimeout(context.Background(), 200*time.Millisecond) + defer cancel() + b := &blockingBeginner{blockLock: true} + err := RunSerialized(parent, b, uid, func(context.Context, pgx.Tx) error { + t.Error("fn ran although the lock was never acquired") + return nil + }) + if !errors.Is(err, context.DeadlineExceeded) { + t.Errorf("err = %v, want the deadline", err) + } + if errors.Is(err, ErrCommitUnknown) || errors.Is(err, ErrLockWaitExceeded) { + t.Errorf("err = %v is misclassified: nothing reached a commit and no lock_timeout fired", err) + } + if b.begun != 1 { + t.Errorf("transactions begun = %d, want 1", b.begun) + } + }) + + t.Run("a commit error without a SQLSTATE is unknown outside RunSerialized too", func(t *testing.T) { + if err := ClassifyCommitError(context.DeadlineExceeded); !errors.Is(err, ErrCommitUnknown) { + t.Errorf("ClassifyCommitError(deadline) = %v, want ErrCommitUnknown", err) + } + known := &pgconn.PgError{Code: "23505"} + if err := ClassifyCommitError(known); errors.Is(err, ErrCommitUnknown) { + t.Error("a determinate commit error was classified unknown") + } + }) + }) +} diff --git a/internal/identity/revoke.go b/internal/identity/revoke.go index 93d1710e..08ca2621 100644 --- a/internal/identity/revoke.go +++ b/internal/identity/revoke.go @@ -64,11 +64,15 @@ func RevokeUserCredentialsPool(ctx context.Context, pool *pgxpool.Pool, userID u // A missing user row is reported as pgx.ErrNoRows so the caller can // treat it as a determinate refusal. Spec C-34. // -// The wait is bounded by LockWaitBound. Without a bound nothing ends it: -// the http.Server WriteTimeout does not cancel a handler, so a request -// blocked here waited until its client disconnected. A wait that exceeds -// the bound returns ErrLockWaitExceeded, a determinate failure: the -// transaction made no change. Spec C-43. +// Each lock wait in the caller's transaction is limited by LockWaitBound, +// through a transaction-local lock_timeout set here. PostgreSQL applies it +// to every lock acquisition that follows in the transaction, separately, +// including implicit row locks taken by later statements. It does NOT +// limit pool acquisition, the transaction as a whole or the request; that +// is OperationDeadline's job. A wait on THIS lock that exceeds the limit +// returns ErrLockWaitExceeded: the user lock was never acquired and +// nothing was read under it. A later lock that times out is reported by +// IsLockTimeout alone, because by then the user lock was held. Spec C-43. func LockUser(ctx context.Context, tx pgx.Tx, userID uuid.UUID) error { // set_config with is_local=true is SET LOCAL: it lasts until the // transaction ends and cannot leak to the pooled connection. @@ -79,8 +83,7 @@ func LockUser(ctx context.Context, tx pgx.Tx, userID uuid.UUID) error { var one int if err := tx.QueryRow(ctx, `SELECT 1 FROM users WHERE id = $1 FOR NO KEY UPDATE`, userID).Scan(&one); err != nil { - var pgErr *pgconn.PgError - if errors.As(err, &pgErr) && pgErr.Code == sqlStateLockNotAvailable { + if IsLockTimeout(err) { return fmt.Errorf("%w: %w", ErrLockWaitExceeded, err) } return err @@ -88,19 +91,34 @@ func LockUser(ctx context.Context, tx pgx.Tx, userID uuid.UUID) error { return nil } -// LockWaitBound caps how long a credential transaction waits for the -// per-user lock. The lock is held only across short database statements: -// password hashing and every network call run outside it by design -// (C-39), so a wait this long means a stuck holder rather than ordinary -// contention. It leaves most of the 60 s http.Server WriteTimeout for the -// response that reports the failure. Spec C-43. +// LockWaitBound is the configured limit on each lock wait inside a +// credential transaction. Exceeding it shows only that a wait exceeded the +// limit, not why. Spec C-43. const LockWaitBound = 5 * time.Second -// ErrLockWaitExceeded reports that the per-user lock was not acquired -// within LockWaitBound. Nothing was read or changed under the lock, so -// the caller may say that nothing happened and that a retry is safe. +// OperationDeadline limits a whole credential operation: pool +// acquisition, every statement, the commit, and any retries. It is set by +// WithOperationDeadline and never extends an earlier deadline the caller +// already carries. Spec C-43. +const OperationDeadline = 15 * time.Second + +// WithOperationDeadline returns a context that expires OperationDeadline +// from now, or at the caller's own deadline if that comes first. +func WithOperationDeadline(ctx context.Context) (context.Context, context.CancelFunc) { + return context.WithTimeout(ctx, OperationDeadline) +} + +// ErrLockWaitExceeded reports that the per-user lock itself was not +// acquired within LockWaitBound. Nothing was read or changed under it. var ErrLockWaitExceeded = errors.New("identity: per-user lock wait exceeded") +// IsLockTimeout reports whether err is PostgreSQL's lock_timeout, on the +// per-user lock or on any later lock in the same transaction. +func IsLockTimeout(err error) bool { + var pgErr *pgconn.PgError + return errors.As(err, &pgErr) && pgErr.Code == sqlStateLockNotAvailable +} + // sqlStateLockNotAvailable is what PostgreSQL raises when lock_timeout // expires. const sqlStateLockNotAvailable = "55P03" diff --git a/internal/identity/serialize.go b/internal/identity/serialize.go index 4e30f4ee..8fdf1bc0 100644 --- a/internal/identity/serialize.go +++ b/internal/identity/serialize.go @@ -119,6 +119,17 @@ func commitIsIndeterminate(err error) bool { return false } +// ClassifyCommitError wraps a commit error whose outcome is unknown in +// ErrCommitUnknown, so a caller outside RunSerialized reports it the same +// way: neither success nor failure. A determinate error is returned +// unchanged. Spec C-37, C-43. +func ClassifyCommitError(err error) error { + if err != nil && commitIsIndeterminate(err) { + return fmt.Errorf("%w: %v", ErrCommitUnknown, err) + } + return err +} + // RunSerialized runs fn inside ONE transaction that holds the per-user // lock, and owns the whole lifecycle: begin, lock, fn, commit. // @@ -131,7 +142,15 @@ func commitIsIndeterminate(err error) bool { // statement inside it cannot work. The loop stops early when the request // deadline has passed, so a retry never outlives the caller's context. // Spec C-37. +// +// The whole operation, pool acquisition, every statement, the commit and +// any retries, runs under OperationDeadline, or under the caller's own +// deadline when that is earlier. A deadline that expires during the +// commit leaves the outcome unknown and is reported as ErrCommitUnknown, +// like any other commit error without a SQLSTATE. Spec C-43. func RunSerialized(ctx context.Context, db TxBeginner, userID uuid.UUID, fn func(context.Context, pgx.Tx) error) error { + ctx, cancel := WithOperationDeadline(ctx) + defer cancel() var lastErr error for attempt := 1; attempt <= MaxSerializedAttempts; attempt++ { if err := ctx.Err(); err != nil { diff --git a/internal/server/auth_handlers.go b/internal/server/auth_handlers.go index dd0ff0de..9acb5186 100644 --- a/internal/server/auth_handlers.go +++ b/internal/server/auth_handlers.go @@ -412,10 +412,11 @@ func (h *handlers) PostAuthLogout(w http.ResponseWriter, r *http.Request) { // Nothing was revoked, and the response says so. The cookies are // still cleared above: the web client treats every logout // response as signed out, so keeping them would leave a working - // session in a browser the user believes is signed out. A retry - // is safe for a client that still holds the values. Spec C-43. + // session in a browser the user believes is signed out. Not + // retryable: with the cookies cleared, a repeated request may name + // no family, or a different one after another sign-in. Spec C-43. writeError(w, http.StatusServiceUnavailable, "server.error", "server", - "signed out on this device, but sign-out did not reach the server in time and nothing was revoked. The session may remain valid until it expires. Revoke it from Settings.", true) + "signed out on this device, but the account lock could not be acquired in time, so nothing was revoked. The session may remain valid until it expires. Revoke it from Settings.", false) return } if revokeUnknown { diff --git a/internal/server/closure_regressions_test.go b/internal/server/closure_regressions_test.go index 963cafbc..1aca44e4 100644 --- a/internal/server/closure_regressions_test.go +++ b/internal/server/closure_regressions_test.go @@ -149,6 +149,7 @@ type apiResult struct { status int code string retryable bool + message string body map[string]any cookies []*http.Cookie } @@ -164,6 +165,7 @@ func doAPI(t *testing.T, req *http.Request) apiResult { if e, ok := body["error"].(map[string]any); ok { res.code, _ = e["code"].(string) res.retryable, _ = e["retryable"].(bool) + res.message, _ = e["human_message"].(string) } return res } @@ -254,17 +256,27 @@ func holdUserLock(t *testing.T, pool *pgxpool.Pool, uid uuid.UUID, max time.Dura } // @ac AC-73 -// AC-73: the per-user lock wait is bounded in the production -// configuration. A request that cannot take the lock answers a retryable -// 503 once the bound expires and decides nothing. +// AC-73: a request that cannot take the per-user lock within the limit +// answers 503 and decides nothing: every credential path and all four +// administrative account mutations. func TestLockWait_BoundedInProductionConfiguration(t *testing.T) { t.Run("system-auth-identity/AC-73", func(t *testing.T) { url, pool := freshAPIServer(t) - for _, path := range []string{"login", "body refresh", "cookie refresh", "logout", "admin disable"} { + ctx := context.Background() + svc := users.NewService(pool, nil) + paths := []string{"login", "body refresh", "cookie refresh", "logout", + "admin disable", "admin enable", "admin reset", "admin soft delete"} + for _, path := range paths { path := path t.Run(path, func(t *testing.T) { t.Parallel() li := loginFresh(t, url, pool, "ac73"+strings.ReplaceAll(path, " ", "")) + if path == "admin enable" { + if err := svc.Disable(ctx, li.u.ID); err != nil { + t.Fatalf("disable: %v", err) + } + } + userURL := url + "/api/v1/users/" + li.u.ID.String() var req *http.Request switch path { case "login": @@ -276,8 +288,16 @@ func TestLockWait_BoundedInProductionConfiguration(t *testing.T) { case "logout": req = logoutRequest(url, li.sessionCookie, li.refreshCookie) case "admin disable": - req = asRole(t, "POST", url+"/api/v1/users/"+li.u.ID.String()+":disable", auth.RoleAdmin, nil) - } + req = asRole(t, "POST", userURL+":disable", auth.RoleAdmin, nil) + case "admin enable": + req = asRole(t, "POST", userURL+":enable", auth.RoleAdmin, nil) + case "admin reset": + req = asRole(t, "POST", userURL+":reset-password", auth.RoleAdmin, + map[string]string{"new_password": "ac73-reset-Passphrase-5520"}) // pragma: allowlist secret + case "admin soft delete": + req = asRole(t, "DELETE", userURL, auth.RoleAdmin, nil) + } + disabledBefore := isDisabled(t, pool, li.u.ID) before := snapshotCredentials(t, pool, li.u.ID) release := holdUserLock(t, pool, li.u.ID, identity.LockWaitBound+15*time.Second) start := time.Now() @@ -285,11 +305,18 @@ func TestLockWait_BoundedInProductionConfiguration(t *testing.T) { elapsed := time.Since(start) release() - if got.status != http.StatusServiceUnavailable || got.code != "server.error" || !got.retryable { - t.Errorf("response = %d %q retryable=%v, want 503 server.error retryable", got.status, got.code, got.retryable) + // Logout clears the cookies, so a repeated request may name + // no family; it is not retryable. Everything else is. + wantRetryable := path != "logout" + if got.status != http.StatusServiceUnavailable || got.code != "server.error" || got.retryable != wantRetryable { + t.Errorf("response = %d %q retryable=%v, want 503 server.error retryable=%v", + got.status, got.code, got.retryable, wantRetryable) + } + if path == "logout" && !strings.Contains(got.message, "account lock") { + t.Errorf("logout message %q does not name the account lock", got.message) } if elapsed < identity.LockWaitBound-250*time.Millisecond || elapsed > identity.LockWaitBound+10*time.Second { - t.Errorf("answered after %v; the bound is %v", elapsed, identity.LockWaitBound) + t.Errorf("answered after %v; the limit is %v", elapsed, identity.LockWaitBound) } if after := snapshotCredentials(t, pool, li.u.ID); !after.equal(before) { t.Error("credential rows changed although the lock was never acquired") @@ -302,17 +329,153 @@ func TestLockWait_BoundedInProductionConfiguration(t *testing.T) { if cleared := got.clearsCredential(); cleared != (path == "logout") { t.Errorf("credential cookies cleared = %v", cleared) } - if path == "admin disable" && isDisabled(t, pool, li.u.ID) { - t.Error("the account was disabled although the change reported not applied") + if isDisabled(t, pool, li.u.ID) != disabledBefore { + t.Error("the account's disabled state changed although the change was reported not applied") } - if code := authMe(t, url, li.sessionCookie); code != http.StatusOK { - t.Errorf("the presented session no longer works: %d", code) + var deleted bool + if err := pool.QueryRow(ctx, `SELECT deleted_at IS NOT NULL FROM users WHERE id = $1`, li.u.ID).Scan(&deleted); err != nil || deleted { + t.Errorf("the account was deleted although the change was reported not applied (err=%v)", err) + } + if path != "admin enable" { + if code := authMe(t, url, li.sessionCookie); code != http.StatusOK { + t.Errorf("the presented session no longer works: %d", code) + } } }) } }) } +// holdRowLocks takes FOR UPDATE on every row of table for the user, on a +// second connection, without touching the users row. +func holdRowLocks(t *testing.T, pool *pgxpool.Pool, table string, uid uuid.UUID, max time.Duration) (release func()) { + t.Helper() + ctx := context.Background() + holder, err := pool.Begin(ctx) + if err != nil { + t.Fatalf("begin holder: %v", err) + } + if _, err := holder.Exec(ctx, `SELECT 1 FROM `+table+` WHERE user_id = $1 FOR UPDATE`, uid); err != nil { + t.Fatalf("lock %s rows: %v", table, err) + } + var once sync.Once + release = func() { once.Do(func() { _ = holder.Rollback(ctx) }) } + timer := time.AfterFunc(max, release) + t.Cleanup(func() { timer.Stop(); release() }) + return release +} + +// @ac AC-81 +// AC-81: a lock that times out AFTER the per-user lock was acquired rolls +// the transaction back, and the answer does not claim the account lock was +// never acquired. +func TestLockWait_LaterLockTimesOut(t *testing.T) { + t.Run("system-auth-identity/AC-81", func(t *testing.T) { + url, pool := freshAPIServer(t) + for _, tc := range []struct{ path, table string }{ + {"body refresh", "refresh_tokens"}, + // Not sessions: a locked session row stalls the cookie + // binder's idle slide before logout runs (bugs/OW-077). The + // logout sweep revokes sessions first and refresh tokens + // second, so this still times out on a later lock. + {"logout", "refresh_tokens"}, + {"admin disable", "sessions"}, + } { + tc := tc + t.Run(tc.path, func(t *testing.T) { + t.Parallel() + li := loginFresh(t, url, pool, "ac81"+strings.ReplaceAll(tc.path, " ", "")) + var req *http.Request + switch tc.path { + case "body refresh": + req = bodyRefreshRequest(url, li.bodyRefresh) + case "logout": + req = logoutRequest(url, li.sessionCookie, li.refreshCookie) + case "admin disable": + req = asRole(t, "POST", url+"/api/v1/users/"+li.u.ID.String()+":disable", auth.RoleAdmin, nil) + } + before := snapshotCredentials(t, pool, li.u.ID) + release := holdRowLocks(t, pool, tc.table, li.u.ID, identity.LockWaitBound+15*time.Second) + start := time.Now() + got := doAPI(t, req) + elapsed := time.Since(start) + release() + + switch tc.path { + case "body refresh": + if got.status != http.StatusServiceUnavailable || got.code != "server.error" || !got.retryable { + t.Errorf("response = %d %q retryable=%v, want 503 server.error retryable", got.status, got.code, got.retryable) + } + case "logout": + // A known rollback: this attempt revoked nothing. + if got.status != http.StatusInternalServerError || got.code != "auth.logout_incomplete" { + t.Errorf("response = %d %q, want 500 auth.logout_incomplete", got.status, got.code) + } + if !got.clearsCredential() { + t.Error("logout did not clear the cookies") + } + case "admin disable": + if got.status != http.StatusServiceUnavailable || got.code != "server.error" || !got.retryable { + t.Errorf("response = %d %q retryable=%v, want 503 server.error retryable", got.status, got.code, got.retryable) + } + if isDisabled(t, pool, li.u.ID) { + t.Error("the account was disabled although the transaction rolled back") + } + } + if strings.Contains(got.message, "account lock") { + t.Errorf("message %q claims the account lock was not acquired; it was", got.message) + } + if elapsed < identity.LockWaitBound-250*time.Millisecond { + t.Errorf("answered after %v, before the %v limit on the later lock", elapsed, identity.LockWaitBound) + } + if !snapshotCredentials(t, pool, li.u.ID).equal(before) { + t.Error("credential rows changed although the transaction rolled back") + } + if got.setsCredential() || got.carriesToken() { + t.Error("the response issued a credential") + } + if tc.path == "body refresh" { + if again := doAPI(t, bodyRefreshRequest(url, li.bodyRefresh)); again.status != http.StatusOK { + t.Errorf("the token no longer rotates after the rollback: %d", again.status) + } + } + }) + } + }) +} + +// @ac AC-82 +// AC-82, at the users service: an earlier caller deadline ends the wait +// for the per-user lock before the lock limit does, and nothing changes. +// The deadline's other properties are asserted in the identity package. +func TestOperationDeadline_UsersServiceHonorsCallerDeadline(t *testing.T) { + t.Run("system-auth-identity/AC-82", func(t *testing.T) { + url, pool := freshAPIServer(t) + svc := users.NewService(pool, nil) + li := loginFresh(t, url, pool, "ac82caller") + before := snapshotCredentials(t, pool, li.u.ID) + release := holdUserLock(t, pool, li.u.ID, identity.LockWaitBound+15*time.Second) + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + start := time.Now() + err := svc.Disable(ctx, li.u.ID) + elapsed := time.Since(start) + release() + if err == nil { + t.Fatal("disable succeeded although its deadline expired while the lock was held elsewhere") + } + if elapsed > identity.LockWaitBound-time.Second { + t.Errorf("disable returned after %v; the caller's 1s deadline was not honored", elapsed) + } + if isDisabled(t, pool, li.u.ID) { + t.Error("the account was disabled although the operation did not complete") + } + if !snapshotCredentials(t, pool, li.u.ID).equal(before) { + t.Error("credential rows changed although the operation did not complete") + } + }) +} + // @ac AC-74 // AC-74: a refresh racing Disable leaves nothing usable once Disable // returns, in both orders and on both refresh paths. @@ -415,7 +578,7 @@ func TestEnable_DoesNotReviveWhatDisableRevoked(t *testing.T) { if err := svc.Disable(ctx, li.u.ID); err != nil { t.Fatalf("disable: %v", err) } - if err := svc.Enable(ctx, li.u.ID); err != nil { + if _, err := svc.Enable(ctx, li.u.ID); err != nil { t.Fatalf("enable: %v", err) } if code := authMe(t, url, li.sessionCookie); code != http.StatusUnauthorized { diff --git a/internal/server/sso_closure_test.go b/internal/server/sso_closure_test.go index f380e722..6cf2d3ed 100644 --- a/internal/server/sso_closure_test.go +++ b/internal/server/sso_closure_test.go @@ -107,7 +107,7 @@ func TestSSO_ProvisioningRace(t *testing.T) { } // Re-enabled, a later callback finds the same user. - if err := svc.Enable(ctx, uid); err != nil { + if _, err := svc.Enable(ctx, uid); err != nil { t.Fatalf("enable: %v", err) } _ = svc.AssignRole(ctx, uid, auth.RoleID("viewer"), nil) diff --git a/internal/server/users_admin_handlers.go b/internal/server/users_admin_handlers.go index 86f40dee..b1e4ae5c 100644 --- a/internal/server/users_admin_handlers.go +++ b/internal/server/users_admin_handlers.go @@ -31,11 +31,18 @@ func mapUserAdminErr(w http.ResponseWriter, err error) bool { return false case errors.Is(err, users.ErrUserNotFound): writeError(w, http.StatusNotFound, "users.not_found", "client", "user not found", false) - case errors.Is(err, identity.ErrLockWaitExceeded): - // The per-user lock was not acquired in time, so the change was - // not applied. Retrying is safe. Spec system-auth-identity C-43. + case errors.Is(err, identity.ErrCommitUnknown): + // The commit's outcome is unknown, including a deadline that + // expired during it. Neither result is asserted, and a blind + // retry is not invited. Spec system-auth-identity C-37, C-43. writeError(w, http.StatusServiceUnavailable, "server.error", "server", - "the change was not applied because the account could not be locked in time. Try again.", true) + "the change may or may not have been applied. Check the account before trying again.", false) + case identity.IsLockTimeout(err): + // A lock wait exceeded its limit, on the account lock or on a + // later row lock, and the transaction rolled back, so the change + // was not applied. Retrying is safe. Spec system-auth-identity C-43. + writeError(w, http.StatusServiceUnavailable, "server.error", "server", + "the change was not applied because a lock could not be acquired in time. Try again.", true) case errors.Is(err, identity.ErrPasswordTooShort), errors.Is(err, identity.ErrPasswordTooLong), errors.Is(err, identity.ErrPasswordBreached): diff --git a/internal/server/users_handlers.go b/internal/server/users_handlers.go index 92d30e04..8cc9b912 100644 --- a/internal/server/users_handlers.go +++ b/internal/server/users_handlers.go @@ -101,14 +101,10 @@ func (h *handlers) DeleteUserByID(w http.ResponseWriter, r *http.Request, id ope if denied := auth.EnforcePermission(w, r, auth.UserDelete); denied { return } - if err := h.users.SoftDelete(r.Context(), uuid.UUID(id)); err != nil { - if errors.Is(err, users.ErrUserNotFound) { - writeError(w, http.StatusNotFound, "users.not_found", "client", - "user not found", false) - return - } - writeError(w, http.StatusInternalServerError, "server.error", "server", - "delete failed", true) + // The shared mapping: 404 for a missing user, and the same lock + // timeout and unknown-commit answers as the other account mutations. + // Spec system-auth-identity C-43. + if err := h.users.SoftDelete(r.Context(), uuid.UUID(id)); mapUserAdminErr(w, err) { return } emitAudit(r, audit.AdminUserDeleted, id.String(), nil) diff --git a/internal/users/users.go b/internal/users/users.go index b8f10ba1..702866f1 100644 --- a/internal/users/users.go +++ b/internal/users/users.go @@ -390,6 +390,10 @@ func (s *Service) SoftDelete(ctx context.Context, id uuid.UUID) error { // revocation ran and before the state change was visible, and that // session is never revoked by anything. Spec C-34, C-36. func (s *Service) mutateAccountState(ctx context.Context, id uuid.UUID, stmt string) error { + // Bounded as a whole, and never beyond an earlier caller deadline. + // system-auth-identity C-43. + ctx, cancel := identity.WithOperationDeadline(ctx) + defer cancel() tx, err := s.pool.Begin(ctx) if err != nil { return fmt.Errorf("users: begin: %w", err) @@ -413,7 +417,7 @@ func (s *Service) mutateAccountState(ctx context.Context, id uuid.UUID, stmt str return err } if err := tx.Commit(ctx); err != nil { - return fmt.Errorf("users: commit: %w", err) + return fmt.Errorf("users: commit: %w", identity.ClassifyCommitError(err)) } return nil } @@ -438,6 +442,10 @@ func (s *Service) AdminResetPassword(ctx context.Context, id uuid.UUID, newPassw // the password changed with the revocation incomplete, which is the // worst of both: the user cannot sign in with the old password while // every credential minted from it still works. Spec C-34, C-36. + // Bounded as a whole, and never beyond an earlier caller deadline. + // system-auth-identity C-43. + ctx, cancel := identity.WithOperationDeadline(ctx) + defer cancel() tx, err := s.pool.Begin(ctx) if err != nil { return fmt.Errorf("users: begin: %w", err) @@ -456,7 +464,7 @@ func (s *Service) AdminResetPassword(ctx context.Context, id uuid.UUID, newPassw return fmt.Errorf("users: revoke credentials after reset: %w", err) } if err := tx.Commit(ctx); err != nil { - return fmt.Errorf("users: commit reset: %w", err) + return fmt.Errorf("users: commit reset: %w", identity.ClassifyCommitError(err)) } return nil } @@ -528,6 +536,10 @@ func (s *Service) Disable(ctx context.Context, id uuid.UUID) error { // // Spec api-users C-07, C-08; system-auth-identity C-34, C-36. func (s *Service) Enable(ctx context.Context, id uuid.UUID) (transitioned bool, err error) { + // Bounded as a whole, and never beyond an earlier caller deadline. + // system-auth-identity C-43. + ctx, cancel := identity.WithOperationDeadline(ctx) + defer cancel() tx, err := s.pool.Begin(ctx) if err != nil { return false, fmt.Errorf("users: begin: %w", err) @@ -565,7 +577,7 @@ func (s *Service) Enable(ctx context.Context, id uuid.UUID) (transitioned bool, return false, fmt.Errorf("users: revoke credentials on enable: %w", err) } if err := tx.Commit(ctx); err != nil { - return false, fmt.Errorf("users: commit: %w", err) + return false, fmt.Errorf("users: commit: %w", identity.ClassifyCommitError(err)) } return true, nil } diff --git a/specs/system/auth-identity.spec.yaml b/specs/system/auth-identity.spec.yaml index 080d882b..3772a4db 100644 --- a/specs/system/auth-identity.spec.yaml +++ b/specs/system/auth-identity.spec.yaml @@ -388,26 +388,37 @@ spec: enforcement: error - id: C-43 description: > - The wait for the per-user lock MUST be bounded in the production - configuration, not only under test. Nothing else bounds it: the - http.Server WriteTimeout does not cancel a handler, so a request - blocked on the lock waited until its client disconnected. The bound - is identity.LockWaitBound, 5 seconds, applied as a transaction-local - lock_timeout by the lock helper itself, so every path that takes the - lock inherits it, the administrative account mutations included. - The lock is held only across short database statements (C-39 keeps - password hashing and network calls outside it), so a wait that long - means a stuck holder, and the bound leaves most of the 60 second - WriteTimeout for the response. A wait that exceeds the bound is a - determinate failure: nothing was read under the lock and nothing - changed. It MUST be reported as 503 server.error with retryable - true, distinct from a revocation that failed and rolled back (logout - 500 auth.logout_incomplete) and from an unknown commit outcome (503 - with retryable false). Logout still clears both credential cookies - in that case, as it does for every outcome: the web client treats - any logout response as signed out, so a kept cookie would leave a - working session in a browser the user believes is signed out. The - message says nothing was revoked. + Credential transactions MUST be bounded in the production + configuration, not only under test. Nothing else bounds them: the + http.Server WriteTimeout does not cancel a handler. Two limits apply. + First, identity.LockWaitBound, 5 seconds, is set as a + transaction-local lock_timeout by the lock helper. PostgreSQL applies + it to each lock acquisition separately, including implicit row locks + taken by later statements in the same transaction; it does not limit + pool acquisition, the transaction as a whole or the request. Second, + identity.OperationDeadline, 15 seconds, is a context deadline over + the whole serialized operation: pool acquisition, every statement, + the commit and any retries, in RunSerialized and in the users + service's account-state, reset and enable transactions. It never + extends an earlier deadline the caller already carries. Exceeding + either limit shows only that a wait exceeded it, not why. Outcomes + MUST be reported by what is known. The per-user lock not acquired + in time: nothing was read under it and nothing changed. A later + lock timing out: the transaction rolled back, and the answer MUST + NOT claim the per-user lock was never acquired. A deadline expiring + during the commit: the outcome is unknown and is reported as + ErrCommitUnknown, never as success or failure. Credential and + administrative paths answer a known rollback from a lock timeout + with 503 server.error, retryable. Logout clears both credential + cookies on every outcome, because the web client treats any logout + response as signed out, and so its lock-timeout answer is 503 + server.error, not retryable: with the cookies cleared a repeated + request may name no family, or a different one. Its message says + the account lock was not acquired and nothing was revoked, which + keeps it distinct from an unknown commit, which says revocation + could not be confirmed. Not covered by these limits, and recorded + as such: reads a handler makes before the serialized transaction, + and the cookie binder's idle slide (bugs/OW-077). type: security enforcement: error @@ -1706,29 +1717,42 @@ spec: - id: AC-73 description: > - The per-user lock wait is bounded in the production configuration. - A request that cannot take the lock answers 503 server.error with - retryable true once the bound expires, and decides nothing. + A request that cannot take the per-user lock within the limit + answers 503 and decides nothing, on every credential path and on all + four administrative account mutations. priority: critical references_constraints: [C-34, C-43] inputs: - initial_state: "A second connection holds the per-user lock for longer than the bound" - operation: "Login, body refresh, cookie refresh, logout, and administrative disable" + initial_state: "A second connection holds the per-user lock for longer than the limit" + paths: + - "POST /auth/login" + - "POST /auth/refresh" + - "POST /auth/refresh-cookie" + - "POST /auth/logout" + - "POST /users/{id}:disable" + - "POST /users/{id}:enable (the user disabled beforehand)" + - "POST /users/{id}:reset-password" + - "DELETE /users/{id}" method: > - Each path runs against the unmodified server, with no test - override of the lock timeout. A safety timer releases the held - lock well after the bound, so a missing bound fails the test - instead of hanging it. + The unmodified server, with no test override of either limit. A + safety timer releases the held lock well after the limit, so a + missing limit fails the test instead of hanging it. expected_output: - response: {status: 503, code: server.error, retryable: true} - answered_after: "The bound, not before it" - durable_changes: [] - logout_cookies: "Cleared, as for every logout outcome" + per_path: + logout: + response: {status: 503, code: server.error, retryable: false} + message_states: "the account lock could not be acquired, so nothing was revoked" + cookies: "Both credential cookies cleared" + every_other_path: + response: {status: 503, code: server.error, retryable: true} + cookies: "None set and none cleared" + answered_after: "The limit, not before it" + transaction_effects: [] + audit: "No success event for the attempt" prohibited_changes: - "A credential issued or revoked" - - "A credential cookie set, or cleared by any path other than logout" - - "The account disabled although the change was reported not applied" - subsequent: ["The presented session still authenticates"] + - "The account disabled, enabled, reset or deleted although the change was reported not applied" + subsequent: ["The presented session still authenticates, except on the enable path, where it was revoked by the earlier disable"] - id: AC-74 description: > @@ -1742,8 +1766,14 @@ spec: - "The refresh holds the lock, Disable queues behind it, the refresh commits" attribution: "Credential rows by ID: before, after the coordinator, after the attempt" expected_output: - first_order: "The refresh is refused and writes no row" - second_order: "Every row the refresh wrote is revoked once Disable returns" + first_order: + response: {status: 401} + cookies: "No credential cookie set" + transaction_effects: "The refresh writes no row" + second_order: + response: {status: 200} + transaction_effects: "Every row the refresh wrote is revoked once Disable returns" + audit: "Not asserted" prohibited_changes: ["Any predecessor or successor credential authenticating after Disable returns"] - id: AC-75 @@ -1756,7 +1786,14 @@ spec: initial_state: "A signed-in user" operation: "Disable, then Enable, then present the pre-disable session cookie, access token and both refresh tokens" expected_output: + responses: + session_cookie: {status: 401} + access_token: {status: 401} + body_refresh: "Not 200" + cookie_refresh: "Not 200, and no session cookie set" credentials_authenticating: 0 + transaction_effects: "Enable revokes nothing further: Disable already revoked every credential" + audit: "Not asserted" subsequent: ["A fresh sign-in succeeds"] - id: AC-76 @@ -1773,6 +1810,8 @@ spec: - "Secret rotated and confirmed before the login takes the lock" - "Enrollment removed before the login takes the lock" expected_output: + cookies: "Set only on the successful login" + audit: "Not asserted" same_code: {successful_logins: 1, refused_code: auth.mfa_invalid, otp_uses_added: 1, sessions_added: 1} secret_rotated: {code: auth.mfa_invalid, rows_added: 0, otp_uses_added: 0} enrollment_removed: {status: 200, sessions_added: 1, otp_uses_added: 0} @@ -1789,7 +1828,9 @@ spec: expected_output: transactions_begun: 2 response: {status: 401} + cookies: "No credential cookie set" rows_added: 0 + audit: "Not asserted" - id: AC-78 description: > @@ -1810,10 +1851,8 @@ spec: attempt_rows_added: 0 otp_uses_added: 0 prohibited_changes: ["A 200 response", "A credential cookie", "A token in the response body"] - structural_review: > - Reported separately and by hand: every reachable write to sessions - or refresh_tokens sits inside the locked protocol, except the idle - slide in VerifySession. + cookies: "No credential cookie set" + audit: "Not asserted" - id: AC-79 description: > @@ -1826,7 +1865,10 @@ spec: controlled_failure: "The commit is a known rollback" expected_output: response: {status: 503, code: server.error} + cookies: "No credential cookie set" + body: "No access or refresh token" credential_rows_changed: false + audit: "Not asserted" subsequent: ["The same token rotates on the next request"] - id: AC-80 @@ -1844,3 +1886,66 @@ spec: known_limit: "A reason produced through a shape the scan does not read is invisible to it" expected_output: undeclared_reasons: [] + + - id: AC-81 + description: > + A lock that times out after the per-user lock was acquired rolls the + transaction back, and the answer does not claim the account lock was + never acquired. + priority: critical + references_constraints: [C-43] + inputs: + initial_state: "A second connection holds FOR UPDATE on the user's rows in a later table, not on the users row" + variants: + - name: "Body refresh" + held: "refresh_tokens" + - name: "Logout" + held: "refresh_tokens" + note: "Not sessions: a locked session row stalls the cookie binder before logout runs (bugs/OW-077)" + - name: "Administrative disable" + held: "sessions" + expected_output: + per_variant: + Body refresh: + response: {status: 503, code: server.error, retryable: true} + cookies: "None set" + subsequent: ["The same token rotates after the lock is released"] + Logout: + response: {status: 500, code: auth.logout_incomplete} + cookies: "Both credential cookies cleared" + Administrative disable: + response: {status: 503, code: server.error, retryable: true} + transaction_effects: "The account is not disabled" + answered_after: "The lock limit" + message_must_not_state: "The account lock was not acquired" + transaction_effects: "No credential row changes" + audit: "Not asserted" + + - id: AC-82 + description: > + The serialized operation has a deadline. It exists without the + caller supplying one, never extends an earlier caller deadline, + makes an expiry during the commit an unknown outcome, and makes an + expiry before the commit a known failure. The users service honors + an earlier caller deadline the same way. + priority: critical + references_constraints: [C-37, C-43] + inputs: + variants: + - "No caller deadline" + - "A caller deadline earlier than OperationDeadline" + - "The deadline expires while the commit is in progress" + - "The deadline expires while waiting for the per-user lock" + - "Users service Disable with a 1 second caller deadline while another connection holds the per-user lock" + method: > + The first four drive RunSerialized with a transaction source whose + lock or commit blocks until its context ends. The last uses the + real database. + expected_output: + per_variant: + No caller deadline: {deadline_present: true, at_most: "OperationDeadline from the start"} + Earlier caller deadline: {deadline: "The caller's, unchanged"} + Expiry during commit: {error: ErrCommitUnknown, transactions_begun: 1} + Expiry while waiting for the lock: {error: "context.DeadlineExceeded", not: [ErrCommitUnknown, ErrLockWaitExceeded], transactions_begun: 1} + Users service Disable: {returns: "An error, before the lock limit", transaction_effects: "Account not disabled; no credential row changes"} + response_cookies_audit: "Asserted at the HTTP layer by AC-73 and AC-81" From b0c3f0954d0eb929a7fc86f5a6e88b8fc46f49a0 Mon Sep 17 00:00:00 2001 From: Remylus Losius Date: Thu, 24 Sep 2026 21:21:24 -0400 Subject: [PATCH 3/6] fix(auth): bound cookie-session verification and refuse a session revoked during the wait The cookie binder slid a session's idle window with an unconditional UPDATE on the pool, with no lock limit and no deadline. With the session row held by another transaction, every cookie request for that user waited until the lock was released: 12 s for GET /auth/me and about 21 s for logout in the measurement that found it (bugs/OW-077). Founder decision 2026-09-24: bound the wait, do not skip the slide. Skipping would change the idle policy under contention. - The binder runs verification under identity.OperationDeadline, never beyond an earlier deadline the request carries, and hands that deadline to the credential and account-mutation handlers, so the handler's transaction spends the remaining budget instead of starting a new one. Other routes keep their own context. - The slide runs in its own short transaction with the per-lock limit. Its UPDATE re-checks revocation and both expiry deadlines, so a session revoked or expired while the request waited is refused with the reason the row now shows, not authenticated from the earlier read. - A verification that cannot complete answers 503 server.error without running the handler, clearing a cookie or triggering a refresh. - Logout verifies without sliding, then reaches its hash lookup, CSRF check and bounded revocation. Background requests stay non-sliding. The users service gains a transaction seam so the remaining #879 test gaps are covered: its default deadline, and durable and non-durable unknown commits over HTTP. Specs: system-auth-identity 1.9.0, C-43 amended, C-44 added, AC-83 to AC-89. Refs: bugs/OW-077, bugs/OW-069, bugs/doing/OW-062 AC-54 --- internal/identity/binder.go | 54 ++- internal/identity/revoke.go | 19 +- internal/identity/sessions.go | 63 ++- .../server/session_verification_bound_test.go | 386 ++++++++++++++++++ internal/users/users.go | 23 +- specs/system/auth-identity.spec.yaml | 170 +++++++- 6 files changed, 697 insertions(+), 18 deletions(-) create mode 100644 internal/server/session_verification_bound_test.go diff --git a/internal/identity/binder.go b/internal/identity/binder.go index b048a9a7..1424668f 100644 --- a/internal/identity/binder.go +++ b/internal/identity/binder.go @@ -41,6 +41,35 @@ const sseEventsPath = "/api/v1/events" // presented alongside is not an error there. // // Spec system-auth-identity C-12 / AC-21 (bypass list). +// logoutPath is the one credential route that verifies without sliding. +const logoutPath = "/api/v1/auth/logout" + +// boundedOperation reports whether a request's handler runs credential or +// account-state transactions, and so inherits the binder's deadline. +func boundedOperation(r *http.Request) bool { + p := r.URL.Path + if _, ok := authBypassPaths[p]; ok { + return true + } + switch p { + case "/api/v1/auth/mfa:enroll", "/api/v1/auth/mfa:verify": + return true + } + if strings.HasPrefix(p, "/api/v1/auth/sso/") && strings.HasSuffix(p, "/callback") { + return true + } + if rest, ok := strings.CutPrefix(p, "/api/v1/users/"); ok && !strings.Contains(rest, "/") { + switch { + case r.Method == http.MethodPost && (strings.HasSuffix(rest, ":disable") || + strings.HasSuffix(rest, ":enable") || strings.HasSuffix(rest, ":reset-password")): + return true + case r.Method == http.MethodDelete && !strings.Contains(rest, ":"): + return true + } + } + return false +} + var authBypassPaths = map[string]struct{}{ "/api/v1/auth/login": {}, "/api/v1/auth/logout": {}, @@ -122,7 +151,16 @@ func Binder(pool *pgxpool.Pool, lookups Lookups, opts ...BinderOption) func(http } return func(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - id, reason := resolveIdentity(r.Context(), pool, lookups, cfg, r) + // One budget for the request's credential work. Verification + // runs under it, never beyond an earlier deadline the request + // already carries. On the credential and account-mutation + // routes it is handed on, so the handler's transaction spends + // what is left rather than starting a fresh budget. Other + // routes keep their own context: a report or an event stream + // must not inherit a credential deadline. Spec C-43, C-44. + ctx, cancel := WithOperationDeadline(r.Context()) + defer cancel() + id, reason := resolveIdentity(ctx, pool, lookups, cfg, r) if unavailableReason(reason) { // The credential was not rejected: the server could not // tell. Answering 401 here would tell every signed-in @@ -146,7 +184,11 @@ func Binder(pool *pgxpool.Pool, lookups Lookups, opts ...BinderOption) func(http return } } - next.ServeHTTP(w, r.WithContext(auth.SetIdentity(r.Context(), id))) + handlerCtx := r.Context() + if boundedOperation(r) { + handlerCtx = ctx + } + next.ServeHTTP(w, r.WithContext(auth.SetIdentity(handlerCtx, id))) }) } } @@ -245,7 +287,13 @@ func resolveIdentity(ctx context.Context, pool *pgxpool.Pool, lookups Lookups, c // HTTP traffic. Fail-safe: an unmarked request slides as before, so a // client that does not send the header is unaffected. var vopts []VerifyOption - if r.Header.Get(BackgroundRefreshHeader) == "1" || r.URL.Path == sseEventsPath { + // + // Logout verifies without sliding too. Extending a session a moment + // before ending it serves nothing, and the slide is the one write + // on this path that can wait on a row a revocation holds. Logout + // still reaches its own hash lookup, CSRF check and bounded + // revocation. Spec C-44. + if r.Header.Get(BackgroundRefreshHeader) == "1" || r.URL.Path == sseEventsPath || r.URL.Path == logoutPath { vopts = append(vopts, WithoutSlide()) } sess, err := VerifySession(ctx, pool, cookie.Value, vopts...) diff --git a/internal/identity/revoke.go b/internal/identity/revoke.go index 08ca2621..61adb008 100644 --- a/internal/identity/revoke.go +++ b/internal/identity/revoke.go @@ -74,11 +74,8 @@ func RevokeUserCredentialsPool(ctx context.Context, pool *pgxpool.Pool, userID u // nothing was read under it. A later lock that times out is reported by // IsLockTimeout alone, because by then the user lock was held. Spec C-43. func LockUser(ctx context.Context, tx pgx.Tx, userID uuid.UUID) error { - // set_config with is_local=true is SET LOCAL: it lasts until the - // transaction ends and cannot leak to the pooled connection. - if _, err := tx.Exec(ctx, `SELECT set_config('lock_timeout', $1, true)`, - fmt.Sprintf("%dms", LockWaitBound.Milliseconds())); err != nil { - return fmt.Errorf("identity: set lock wait bound: %w", err) + if err := setLockWaitBound(ctx, tx); err != nil { + return err } var one int if err := tx.QueryRow(ctx, @@ -91,6 +88,18 @@ func LockUser(ctx context.Context, tx pgx.Tx, userID uuid.UUID) error { return nil } +// setLockWaitBound applies LockWaitBound to every lock the transaction +// waits for from here on. set_config with is_local=true is SET LOCAL: it +// lasts until the transaction ends and cannot leak to the pooled +// connection. +func setLockWaitBound(ctx context.Context, tx pgx.Tx) error { + if _, err := tx.Exec(ctx, `SELECT set_config('lock_timeout', $1, true)`, + fmt.Sprintf("%dms", LockWaitBound.Milliseconds())); err != nil { + return fmt.Errorf("identity: set lock wait bound: %w", err) + } + return nil +} + // LockWaitBound is the configured limit on each lock wait inside a // credential transaction. Exceeding it shows only that a wait exceeded the // limit, not why. Spec C-43. diff --git a/internal/identity/sessions.go b/internal/identity/sessions.go index b797d1bd..5c479655 100644 --- a/internal/identity/sessions.go +++ b/internal/identity/sessions.go @@ -183,6 +183,12 @@ func WithoutSlide() VerifyOption { return func(o *verifyOpts) { o.noSlide = true // last_seen + extends expires_at. // // Spec AC-07, AC-08, AC-10. +// +// The idle slide can wait: another transaction may hold the session row, +// for example while revoking it. That wait is limited by LockWaitBound and +// by ctx, and the slide re-checks the row when it finally writes, so a +// session revoked or expired during the wait is refused rather than +// authenticated from the read above. Spec system-auth-identity C-44. func VerifySession(ctx context.Context, pool *pgxpool.Pool, token string, opts ...VerifyOption) (Session, error) { var o verifyOpts for _, f := range opts { @@ -242,9 +248,8 @@ func VerifySession(ctx context.Context, pool *pgxpool.Pool, token string, opts . if newExpires.After(s.AbsoluteExpiresAt) { newExpires = s.AbsoluteExpiresAt } - const upd = `UPDATE sessions SET last_seen = $1, expires_at = $2 WHERE id = $3` - if _, err := pool.Exec(ctx, upd, now, newExpires, s.ID); err != nil { - return Session{}, fmt.Errorf("identity: touch session: %w", err) + if err := slideSession(ctx, pool, s.ID, now, newExpires); err != nil { + return Session{}, err } s.LastSeen = now s.ExpiresAt = newExpires @@ -317,3 +322,55 @@ func nilIfEmpty(s string) interface{} { // Silence the lint detector for the helper we keep around for future // callers in handlers (logout-against-supplied-token path). var _ = sameToken + +// slideSession extends the idle window of a session that is still live +// when the write happens. It runs in its own short transaction so the +// wait for the row carries the same per-lock limit as the credential +// transactions, and ctx bounds the rest, pool acquisition included. +// +// The UPDATE re-checks revocation and both deadlines at write time. If the +// row changed while this request waited, nothing is extended and the +// session is refused with the reason the row now shows. Spec C-44. +func slideSession(ctx context.Context, pool *pgxpool.Pool, id uuid.UUID, now, newExpires time.Time) error { + tx, err := pool.Begin(ctx) + if err != nil { + return fmt.Errorf("identity: touch session: begin: %w", err) + } + defer func() { _ = tx.Rollback(ctx) }() + if err := setLockWaitBound(ctx, tx); err != nil { + return err + } + const upd = ` + UPDATE sessions SET last_seen = $1, expires_at = $2 + WHERE id = $3 + AND revoked_at IS NULL + AND expires_at > clock_timestamp() + AND absolute_expires_at > clock_timestamp() + RETURNING id` + var touched uuid.UUID + err = tx.QueryRow(ctx, upd, now, newExpires, id).Scan(&touched) + if errors.Is(err, pgx.ErrNoRows) { + // The row no longer qualifies. Say why, from the row as it is now. + var revoked bool + if rerr := tx.QueryRow(ctx, + `SELECT revoked_at IS NOT NULL FROM sessions WHERE id = $1`, id).Scan(&revoked); rerr != nil { + if errors.Is(rerr, pgx.ErrNoRows) { + return ErrSessionNotFound + } + return fmt.Errorf("identity: touch session: re-read: %w", rerr) + } + if revoked { + return ErrSessionRevoked + } + return ErrSessionExpired + } + if err != nil { + return fmt.Errorf("identity: touch session: %w", err) + } + if err := tx.Commit(ctx); err != nil { + // Unknown or failed, the request is not authenticated on it: the + // binder answers 503, which asserts nothing about the session. + return fmt.Errorf("identity: touch session: commit: %w", err) + } + return nil +} diff --git a/internal/server/session_verification_bound_test.go b/internal/server/session_verification_bound_test.go new file mode 100644 index 00000000..927a10e7 --- /dev/null +++ b/internal/server/session_verification_bound_test.go @@ -0,0 +1,386 @@ +// @spec system-auth-identity +// +// Cookie-session verification is bounded (bugs/OW-077, C-44), and the +// users service's own limits and unknown commits (C-43). + +package server + +import ( + "context" + "errors" + "net/http" + "strings" + "sync" + "testing" + "time" + + "github.com/Hanalyx/openwatch/internal/auth" + "github.com/Hanalyx/openwatch/internal/identity" + "github.com/Hanalyx/openwatch/internal/users" + "github.com/google/uuid" + "github.com/jackc/pgx/v5" + "github.com/jackc/pgx/v5/pgxpool" +) + +// cookieMe sends GET /auth/me with the session cookie and its own +// correlation id. background marks it as a non-user request. +func cookieMe(t *testing.T, url string, c *http.Cookie, background bool) (apiResult, string) { + t.Helper() + cid := "ow77-" + strings.ReplaceAll(uuid.NewString(), "-", "") + req, _ := http.NewRequest("GET", url+"/api/v1/auth/me", nil) + req.AddCookie(c) + req.Header.Set("X-Correlation-Id", cid) + if background { + req.Header.Set(identity.BackgroundRefreshHeader, "1") + } + return doAPI(t, req), cid +} + +func sessionExpiry(t *testing.T, pool *pgxpool.Pool, id uuid.UUID) time.Time { + t.Helper() + var exp time.Time + if err := pool.QueryRow(context.Background(), `SELECT expires_at FROM sessions WHERE id = $1`, id).Scan(&exp); err != nil { + t.Fatalf("read expires_at: %v", err) + } + return exp +} + +// waitForSlideWaiter waits until a request is blocked on the idle slide. +func waitForSlideWaiter(t *testing.T, pool *pgxpool.Pool) bool { + t.Helper() + deadline := time.Now().Add(10 * time.Second) + for time.Now().Before(deadline) { + var n int + if err := pool.QueryRow(context.Background(), ` + SELECT count(*) FROM pg_stat_activity + WHERE wait_event_type = 'Lock' AND query ILIKE '%SET last_seen%' + AND pid <> pg_backend_pid()`).Scan(&n); err == nil && n > 0 { + return true + } + time.Sleep(20 * time.Millisecond) + } + return false +} + +// handlerRan reports whether /auth/me's own handler produced the body. +func (r apiResult) handlerRan() bool { + _, hasError := r.body["error"] + return !hasError && r.status == http.StatusOK +} + +// @ac AC-83 +// AC-83: an ordinary cookie request whose session row is locked elsewhere +// answers 503 once the lock limit expires. The protected handler does not +// run, no cookie is cleared, and the session is untouched. +func TestCookieVerification_LockedSessionIsBounded503(t *testing.T) { + t.Run("system-auth-identity/AC-83", func(t *testing.T) { + url, pool := freshAPIServer(t) + li := loginFresh(t, url, pool, "ac83locked") + sid := sessionIDOf(t, pool, li.u.ID) + expBefore := sessionExpiry(t, pool, sid) + release := holdRowLocks(t, pool, "sessions", li.u.ID, identity.LockWaitBound+15*time.Second) + start := time.Now() + got, cid := cookieMe(t, url, li.sessionCookie, false) + elapsed := time.Since(start) + release() + + if got.status != http.StatusServiceUnavailable || got.code != "server.error" { + t.Errorf("response = %d %q, want 503 server.error", got.status, got.code) + } + if got.handlerRan() { + t.Error("the protected handler ran") + } + if got.clearsCredential() || got.setsCredential() { + t.Error("the response changed a credential cookie") + } + if elapsed < identity.LockWaitBound-250*time.Millisecond || elapsed > identity.LockWaitBound+5*time.Second { + t.Errorf("answered after %v; the lock limit is %v", elapsed, identity.LockWaitBound) + } + if reason := loginFailureReasonFor(t, pool, cid); reason != "session_lookup_failed" { + t.Errorf("audit reason = %q, want session_lookup_failed", reason) + } + if !sessionExpiry(t, pool, sid).Equal(expBefore) { + t.Error("the idle window moved although verification did not complete") + } + if code := authMe(t, url, li.sessionCookie); code != http.StatusOK { + t.Errorf("the session no longer works after the lock was released: %d", code) + } + }) +} + +// @ac AC-84 +// AC-84: a lock released before the limit lets verification finish +// normally, and the idle window is extended. +func TestCookieVerification_ReleaseBeforeLimitSlides(t *testing.T) { + t.Run("system-auth-identity/AC-84", func(t *testing.T) { + url, pool := freshAPIServer(t) + li := loginFresh(t, url, pool, "ac84released") + sid := sessionIDOf(t, pool, li.u.ID) + expBefore := sessionExpiry(t, pool, sid) + release := holdRowLocks(t, pool, "sessions", li.u.ID, identity.LockWaitBound+15*time.Second) + done := make(chan apiResult, 1) + go func() { + got, _ := cookieMe(t, url, li.sessionCookie, false) + done <- got + }() + if !waitForSlideWaiter(t, pool) { + t.Fatal("the request never waited on the idle slide") + } + time.Sleep(time.Second) + release() + got := <-done + if got.status != http.StatusOK || !got.handlerRan() { + t.Errorf("response = %d, want 200 from the handler", got.status) + } + if !sessionExpiry(t, pool, sid).After(expBefore) { + t.Error("the idle window was not extended") + } + }) +} + +// @ac AC-85 +// AC-85: a session revoked while verification waits is refused. The +// request does not authenticate from the read it made before waiting. +func TestCookieVerification_RevokedDuringWaitIsRefused(t *testing.T) { + t.Run("system-auth-identity/AC-85", func(t *testing.T) { + url, pool := freshAPIServer(t) + ctx := context.Background() + li := loginFresh(t, url, pool, "ac85revoked") + holder, err := pool.Begin(ctx) + if err != nil { + t.Fatalf("begin: %v", err) + } + defer func() { _ = holder.Rollback(ctx) }() + // The revocation takes the row lock and holds it uncommitted. + if _, err := holder.Exec(ctx, `UPDATE sessions SET revoked_at = now() WHERE user_id = $1`, li.u.ID); err != nil { + t.Fatalf("revoke under a held lock: %v", err) + } + type out struct { + got apiResult + cid string + } + done := make(chan out, 1) + go func() { + got, cid := cookieMe(t, url, li.sessionCookie, false) + done <- out{got, cid} + }() + if !waitForSlideWaiter(t, pool) { + t.Fatal("the request never waited on the idle slide") + } + if err := holder.Commit(ctx); err != nil { + t.Fatalf("commit revocation: %v", err) + } + o := <-done + if o.got.status != http.StatusUnauthorized || o.got.handlerRan() { + t.Errorf("response = %d, want 401 without the handler running", o.got.status) + } + if reason := loginFailureReasonFor(t, pool, o.cid); reason != "session_revoked" { + t.Errorf("audit reason = %q, want session_revoked", reason) + } + }) +} + +// @ac AC-86 +// AC-86: logout under a real session-row lock reaches its own bounded +// outcome instead of waiting in the binder. +func TestLogout_SessionRowLockIsBounded(t *testing.T) { + t.Run("system-auth-identity/AC-86", func(t *testing.T) { + url, pool := freshAPIServer(t) + li := loginFresh(t, url, pool, "ac86logout") + before := snapshotCredentials(t, pool, li.u.ID) + release := holdRowLocks(t, pool, "sessions", li.u.ID, identity.LockWaitBound+15*time.Second) + start := time.Now() + got := doAPI(t, logoutRequest(url, li.sessionCookie, li.refreshCookie)) + elapsed := time.Since(start) + release() + if got.status != http.StatusInternalServerError || got.code != "auth.logout_incomplete" { + t.Errorf("response = %d %q, want 500 auth.logout_incomplete", got.status, got.code) + } + if !got.clearsCredential() { + t.Error("logout did not clear the cookies") + } + if strings.Contains(got.message, "account lock") { + t.Errorf("message %q claims the account lock was not acquired; it was", got.message) + } + // One lock limit, in the revocation: the binder did not wait. + if elapsed < identity.LockWaitBound-250*time.Millisecond || elapsed > 2*identity.LockWaitBound-time.Second { + t.Errorf("answered after %v; want one %v lock limit, not two", elapsed, identity.LockWaitBound) + } + if !snapshotCredentials(t, pool, li.u.ID).equal(before) { + t.Error("credential rows changed although the revocation rolled back") + } + }) +} + +// capturingBeginner records the deadline of the context each transaction +// began under. +type capturingBeginner struct { + inner identity.TxBeginner + mu sync.Mutex + got []time.Time +} + +func (c *capturingBeginner) Begin(ctx context.Context) (pgx.Tx, error) { + d, ok := ctx.Deadline() + c.mu.Lock() + if ok { + c.got = append(c.got, d) + } else { + c.got = append(c.got, time.Time{}) + } + c.mu.Unlock() + return c.inner.Begin(ctx) +} + +func (c *capturingBeginner) first() time.Time { + c.mu.Lock() + defer c.mu.Unlock() + if len(c.got) == 0 { + return time.Time{} + } + return c.got[0] +} + +// @ac AC-87 +// AC-87: an earlier caller deadline ends verification before the lock +// limit, and a credential request has one budget, not one per layer. +func TestVerificationDeadline_OneBudgetAndCallerFirst(t *testing.T) { + t.Run("system-auth-identity/AC-87", func(t *testing.T) { + url, pool, srv := freshAPIServerWithHandles(t) + + t.Run("an earlier caller deadline ends verification", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac87caller") + release := holdRowLocks(t, pool, "sessions", li.u.ID, identity.LockWaitBound+15*time.Second) + defer release() + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + start := time.Now() + _, err := identity.VerifySession(ctx, pool, li.sessionCookie.Value) + elapsed := time.Since(start) + if err == nil { + t.Fatal("verification succeeded although its deadline expired during the wait") + } + if errors.Is(err, identity.ErrSessionRevoked) || errors.Is(err, identity.ErrSessionExpired) || errors.Is(err, identity.ErrSessionNotFound) { + t.Errorf("err = %v reports a session state, but nothing about the session was learned", err) + } + if elapsed > identity.LockWaitBound-time.Second { + t.Errorf("returned after %v; the 1s caller deadline was not honored", elapsed) + } + }) + + t.Run("one budget across the binder and the handler", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac87budget") + cb := &capturingBeginner{inner: pool} + srv.handlers.serializer = cb + defer func() { srv.handlers.serializer = nil }() + release := holdRowLocks(t, pool, "sessions", li.u.ID, identity.LockWaitBound+15*time.Second) + // The login carries the session cookie, so the binder slides it + // and waits on the held row. Release after 2 s. + time.AfterFunc(2*time.Second, release) + req := loginRequest(url, li.u.Username, li.u.Password, nil) + req.AddCookie(li.sessionCookie) + start := time.Now() + got := doAPI(t, req) + if got.status != http.StatusOK { + t.Fatalf("login = %d %q, want 200", got.status, got.code) + } + d := cb.first() + if d.IsZero() { + t.Fatal("the login transaction ran with no deadline") + } + if limit := start.Add(identity.OperationDeadline + 500*time.Millisecond); d.After(limit) { + t.Errorf("transaction deadline %v is after %v: the handler restarted the budget after the binder spent 2 s", + d.Sub(start), identity.OperationDeadline) + } + }) + }) +} + +// @ac AC-88 +// AC-88: a background request neither slides the idle window nor waits +// on a locked session row. +func TestCookieVerification_BackgroundDoesNotSlideOrWait(t *testing.T) { + t.Run("system-auth-identity/AC-88", func(t *testing.T) { + url, pool := freshAPIServer(t) + li := loginFresh(t, url, pool, "ac88background") + sid := sessionIDOf(t, pool, li.u.ID) + expBefore := sessionExpiry(t, pool, sid) + release := holdRowLocks(t, pool, "sessions", li.u.ID, identity.LockWaitBound+15*time.Second) + start := time.Now() + got, _ := cookieMe(t, url, li.sessionCookie, true) + elapsed := time.Since(start) + release() + if got.status != http.StatusOK || !got.handlerRan() { + t.Errorf("background request = %d, want 200", got.status) + } + if elapsed > time.Second { + t.Errorf("background request took %v; it waited on the session row", elapsed) + } + if !sessionExpiry(t, pool, sid).Equal(expBefore) { + t.Error("a background request moved the idle window") + } + }) +} + +// @ac AC-89 +// AC-89: the users service's account transactions carry a deadline of +// their own, and an unknown commit reaches the administrator as an +// unknown outcome, whether or not the change was durable. +func TestUsersService_DeadlineAndUnknownCommit(t *testing.T) { + t.Run("system-auth-identity/AC-89", func(t *testing.T) { + url, pool, srv := freshAPIServerWithHandles(t) + + t.Run("default deadline", func(t *testing.T) { + svc := users.NewService(pool, nil) + cb := &capturingBeginner{inner: pool} + svc.UseTxSource(cb) + u := seedAuthUser(t, svc, "ac89deadline", false) + start := time.Now() + if err := svc.Disable(context.Background(), u.ID); err != nil { + t.Fatalf("disable: %v", err) + } + d := cb.first() + if d.IsZero() { + t.Fatal("the account transaction ran with no deadline") + } + if d.After(start.Add(identity.OperationDeadline + 500*time.Millisecond)) { + t.Errorf("deadline %v from the start, want at most %v", d.Sub(start), identity.OperationDeadline) + } + }) + + for _, durable := range []bool{true, false} { + durable := durable + name := map[bool]string{true: "durable", false: "non-durable"}[durable] + t.Run("unknown commit, "+name, func(t *testing.T) { + li := loginFresh(t, url, pool, "ac89"+strings.ReplaceAll(name, "-", "")) + srv.handlers.users.UseTxSource(&indeterminateBeginner{inner: pool, commitFirst: durable}) + req := asRole(t, "POST", url+"/api/v1/users/"+li.u.ID.String()+":disable", auth.RoleAdmin, nil) + cid := "ac89-" + strings.ReplaceAll(uuid.NewString(), "-", "") + req.Header.Set("X-Correlation-Id", cid) + got := doAPI(t, req) + srv.handlers.users.UseTxSource(nil) + + if got.status != http.StatusServiceUnavailable || got.code != "server.error" || got.retryable { + t.Errorf("response = %d %q retryable=%v, want 503 server.error not retryable", got.status, got.code, got.retryable) + } + if !strings.Contains(got.message, "may or may not") { + t.Errorf("message %q asserts an outcome", got.message) + } + if isDisabled(t, pool, li.u.ID) != durable { + t.Errorf("disabled = %v, want %v for the %s variant", !durable, durable, name) + } + // No success event for an outcome nobody knows. Absence is + // read after a settle period, because the writer batches. + time.Sleep(2 * time.Second) + var n int + if err := pool.QueryRow(context.Background(), + `SELECT count(*) FROM audit_events WHERE action = 'admin.user.disabled' AND correlation_id = $1`, cid).Scan(&n); err != nil { + t.Fatalf("read audit: %v", err) + } + if n != 0 { + t.Errorf("admin.user.disabled recorded %d times for an unknown outcome", n) + } + }) + } + }) +} diff --git a/internal/users/users.go b/internal/users/users.go index 702866f1..3e5993fa 100644 --- a/internal/users/users.go +++ b/internal/users/users.go @@ -105,6 +105,23 @@ var rolePrecedence = map[auth.RoleID]int{ type Service struct { pool *pgxpool.Pool corpus identity.BreachCorpus // nil = skip breach check (dev mode only) + // txs, when set, replaces the pool as the source of the locked + // account-state, reset and enable transactions. Production leaves it + // nil; tests set it to select a commit outcome. + txs identity.TxBeginner +} + +// UseTxSource replaces the transaction source for the locked account +// transactions. It exists so tests can force a durable or non-durable +// unknown commit; production never calls it. +func (s *Service) UseTxSource(b identity.TxBeginner) { s.txs = b } + +// lockedTx begins a transaction for the locked account operations. +func (s *Service) lockedTx(ctx context.Context) (pgx.Tx, error) { + if s.txs != nil { + return s.txs.Begin(ctx) + } + return s.pool.Begin(ctx) } // NewService binds a Service to a DB pool. The breach corpus is @@ -394,7 +411,7 @@ func (s *Service) mutateAccountState(ctx context.Context, id uuid.UUID, stmt str // system-auth-identity C-43. ctx, cancel := identity.WithOperationDeadline(ctx) defer cancel() - tx, err := s.pool.Begin(ctx) + tx, err := s.lockedTx(ctx) if err != nil { return fmt.Errorf("users: begin: %w", err) } @@ -446,7 +463,7 @@ func (s *Service) AdminResetPassword(ctx context.Context, id uuid.UUID, newPassw // system-auth-identity C-43. ctx, cancel := identity.WithOperationDeadline(ctx) defer cancel() - tx, err := s.pool.Begin(ctx) + tx, err := s.lockedTx(ctx) if err != nil { return fmt.Errorf("users: begin: %w", err) } @@ -540,7 +557,7 @@ func (s *Service) Enable(ctx context.Context, id uuid.UUID) (transitioned bool, // system-auth-identity C-43. ctx, cancel := identity.WithOperationDeadline(ctx) defer cancel() - tx, err := s.pool.Begin(ctx) + tx, err := s.lockedTx(ctx) if err != nil { return false, fmt.Errorf("users: begin: %w", err) } diff --git a/specs/system/auth-identity.spec.yaml b/specs/system/auth-identity.spec.yaml index 3772a4db..a5c3e7c1 100644 --- a/specs/system/auth-identity.spec.yaml +++ b/specs/system/auth-identity.spec.yaml @@ -416,9 +416,31 @@ spec: request may name no family, or a different one. Its message says the account lock was not acquired and nothing was revoked, which keeps it distinct from an unknown commit, which says revocation - could not be confirmed. Not covered by these limits, and recorded - as such: reads a handler makes before the serialized transaction, - and the cookie binder's idle slide (bugs/OW-077). + could not be confirmed. The deadline starts at the identity binder + (C-44) and is handed to the handlers of the credential and + account-mutation routes, so their reads before the transaction and + the transaction itself spend one budget; RunSerialized and the users + service apply it again only as a ceiling, which never extends it. + type: security + enforcement: error + - id: C-44 + description: > + Cookie-session verification MUST be bounded and MUST NOT + authenticate from a stale read. The binder runs verification under + identity.OperationDeadline, never beyond an earlier deadline the + request carries. The idle slide runs in its own short transaction + with the LockWaitBound lock limit, so a session row held by another + transaction delays a request by at most that limit, and the slide + re-checks revocation and both expiry deadlines when it writes: a + session revoked or expired while the request waited is refused with + the reason the row now shows. A verification that cannot complete, + from the lock limit or the deadline, is an infrastructure failure: + 503 server.error, retryable, with no protected handler run, no + cookie cleared and no refresh triggered. Background requests + (X-Background-Refresh, the event stream) and logout verify without + sliding, so they neither extend the idle window nor wait on the + row; logout still reaches its hash lookup, CSRF check and bounded + revocation. bugs/OW-077. type: security enforcement: error @@ -1901,7 +1923,7 @@ spec: held: "refresh_tokens" - name: "Logout" held: "refresh_tokens" - note: "Not sessions: a locked session row stalls the cookie binder before logout runs (bugs/OW-077)" + note: "The refresh rows are the later lock here; a held session row is AC-86" - name: "Administrative disable" held: "sessions" expected_output: @@ -1949,3 +1971,143 @@ spec: Expiry while waiting for the lock: {error: "context.DeadlineExceeded", not: [ErrCommitUnknown, ErrLockWaitExceeded], transactions_begun: 1} Users service Disable: {returns: "An error, before the lock limit", transaction_effects: "Account not disabled; no credential row changes"} response_cookies_audit: "Asserted at the HTTP layer by AC-73 and AC-81" + + - id: AC-83 + description: > + An ordinary cookie request whose session row is locked by another + transaction answers 503 once the lock limit expires. The protected + handler does not run, no cookie changes, and the session is untouched. + priority: critical + references_constraints: [C-44] + inputs: + initial_state: "A live session; a second connection holds FOR UPDATE on its row past the lock limit" + operation: "GET /auth/me with the session cookie and its own correlation id" + expected_output: + response: {status: 503, code: server.error, retryable: true} + handler_ran: false + cookies: "None set and none cleared" + answered_after: "The lock limit" + audit: {action: auth.login.failure, reason: session_lookup_failed, read_by: "The request's correlation id"} + transaction_effects: "The session's expires_at is unchanged" + subsequent: ["After the lock is released the session authenticates"] + + - id: AC-84 + description: > + A lock released before the limit lets verification finish normally, + and the idle window is extended. + priority: high + references_constraints: [C-44] + inputs: + initial_state: "A live session whose row is held by a second connection" + operation: "GET /auth/me with the session cookie; the lock is released about one second after the request starts waiting" + expected_output: + response: {status: 200} + handler_ran: true + cookies: "None changed" + transaction_effects: "The session's expires_at moves later" + audit: "Not asserted" + + - id: AC-85 + description: > + A session revoked while verification waits for its row is refused. + The request does not authenticate from the read it made before + waiting. + priority: critical + references_constraints: [C-44] + inputs: + initial_state: "A live session; a second connection revokes it and holds the row uncommitted" + operation: "GET /auth/me with the session cookie; the revocation commits while the request waits" + expected_output: + response: {status: 401} + handler_ran: false + audit: {action: auth.login.failure, reason: session_revoked, read_by: "The request's correlation id"} + transaction_effects: "The idle window is not extended" + cookies: "Not asserted" + + - id: AC-86 + description: > + Logout under a real session-row lock reaches its own bounded outcome + instead of waiting in the binder. + priority: critical + references_constraints: [C-41, C-43, C-44] + inputs: + initial_state: "A signed-in user; a second connection holds FOR UPDATE on the user's session rows" + operation: "POST /auth/logout with both cookies and a valid CSRF pair" + expected_output: + response: {status: 500, code: auth.logout_incomplete} + cookies: "Both credential cookies cleared" + answered_after: "One lock limit, in the revocation; the binder did not wait" + message_must_not_state: "The account lock was not acquired" + transaction_effects: "No credential row changes" + audit: "No auth.logout event (nothing was revoked); not asserted" + + - id: AC-87 + description: > + An earlier caller deadline ends verification before the lock limit, + and a credential request has one time budget across the binder and + the handler, not one per layer. + priority: critical + references_constraints: [C-43, C-44] + inputs: + variants: + - name: "Earlier caller deadline" + setup: "VerifySession with a 1 s deadline while the session row is held" + - name: "One budget" + setup: "POST /auth/login carrying a session cookie whose row is held for 2 s, so the binder spends 2 s before the handler runs" + expected_output: + per_variant: + Earlier caller deadline: + returns: "An error that reports no session state, before the lock limit" + One budget: + response: {status: 200} + cookies: "The login's session cookie set" + login_transaction_deadline: "At most OperationDeadline from the request's start" + audit: "Not asserted" + + - id: AC-88 + description: > + A background request neither slides the idle window nor waits on a + locked session row. + priority: high + references_constraints: [C-44] + inputs: + initial_state: "A live session whose row is held by a second connection" + operation: "GET /auth/me with the session cookie and X-Background-Refresh: 1" + expected_output: + response: {status: 200} + handler_ran: true + answered_within: "One second" + transaction_effects: "The session's expires_at is unchanged" + cookies: "None changed" + audit: "Not asserted" + + - id: AC-89 + description: > + The users service's account transactions carry the operation + deadline without a caller supplying one, and an unknown commit on an + administrative mutation reaches the administrator as an unknown + outcome, whether or not the change was durable. + priority: critical + references_constraints: [C-37, C-43] + inputs: + variants: + - name: "Default deadline" + setup: "Service Disable with context.Background, through a transaction source that records the deadline" + - name: "Unknown commit, durable" + setup: "POST /users/{id}:disable; the commit applies, then its acknowledgement is lost" + - name: "Unknown commit, non-durable" + setup: "POST /users/{id}:disable; the commit does not apply and its outcome is unknown" + expected_output: + per_variant: + Default deadline: + deadline: "Present, at most OperationDeadline from the call" + Unknown commit, durable: + response: {status: 503, code: server.error, retryable: false} + message_states: "The change may or may not have been applied" + transaction_effects: "The account is disabled" + Unknown commit, non-durable: + response: {status: 503, code: server.error, retryable: false} + message_states: "The change may or may not have been applied" + transaction_effects: "The account is not disabled" + cookies: "None set" + audit: "No admin.user.disabled row for the request's correlation id, read after a settle period" From 4a0469740e1d27799b61578fa294d233caa6217b Mon Sep 17 00:00:00 2001 From: Remylus Losius Date: Fri, 25 Sep 2026 09:00:04 -0400 Subject: [PATCH 4/6] fix(users): answer "not applied" when an admin change never began or rolled back Go CI run 36081673305 failed AC-73 on b0c3f095. Two separate causes. The fixture. AC-73 ran eight lock-holding cases in parallel on the test pool, whose default size follows the CPU count. On a small pool the holders starved the requests of connections, so they hit the 15 s operation deadline instead of the 5 s lock limit. Reproduced locally with an explicit 4-connection pool. AC-73 and AC-81 now run one case at a time on a pool explicitly sized to 8, and each case confirms every connection is back before the next. The production defect the failure exposed. When the operation deadline expired before an admin transaction began, the handler answered 500 "user operation failed". Nothing had been applied. Failures are now classified by stage, with the commit stage tested first: - uncertain commit: 503, not retryable, even when a deadline interrupted it (ClassifyCommitError keeps both errors visible); - never began (identity.ErrNotBegun): 503, retryable, "could not start"; - lock timeout, or a deadline before the commit: rolled back, 503, retryable, "not applied". Rollbacks run on a context detached from the expired one. AC-90 covers pool exhaustion on all four admin mutations with a deliberately small pool, a deadline after the transaction began, the mapping order, and a deadline during the commit. Specs: system-auth-identity 1.9.0, C-43 amended, AC-73 and AC-81 inputs amended, AC-90 added. Refs: bugs/OW-069, bugs/doing/OW-062 AC-54 --- internal/identity/serialize.go | 30 ++- internal/identity/sessions.go | 2 +- internal/server/admin_stage_test.go | 280 ++++++++++++++++++++ internal/server/api_helpers_test.go | 32 ++- internal/server/closure_regressions_test.go | 32 ++- internal/server/users_admin_handlers.go | 24 +- internal/users/users.go | 19 +- specs/system/auth-identity.spec.yaml | 76 +++++- 8 files changed, 470 insertions(+), 25 deletions(-) create mode 100644 internal/server/admin_stage_test.go diff --git a/internal/identity/serialize.go b/internal/identity/serialize.go index 8fdf1bc0..75c27e31 100644 --- a/internal/identity/serialize.go +++ b/internal/identity/serialize.go @@ -6,6 +6,7 @@ import ( "fmt" "log/slog" "strings" + "time" "github.com/google/uuid" "github.com/jackc/pgx/v5" @@ -125,11 +126,34 @@ func commitIsIndeterminate(err error) bool { // unchanged. Spec C-37, C-43. func ClassifyCommitError(err error) error { if err != nil && commitIsIndeterminate(err) { - return fmt.Errorf("%w: %v", ErrCommitUnknown, err) + // Both stay visible to errors.Is. A deadline that expired during + // the commit is therefore still a deadline underneath, and a + // caller MUST test ErrCommitUnknown first: the commit's outcome + // is what matters, not what interrupted it. + return fmt.Errorf("%w: %w", ErrCommitUnknown, err) } return err } +// ErrNotBegun reports that a transaction never began, for example because +// no pooled connection became free before the deadline. Nothing was read +// or written, so the operation was not applied. Spec C-43. +var ErrNotBegun = errors.New("identity: transaction did not begin") + +// RollbackDetached rolls tx back on a context detached from ctx's +// cancellation, with its own short limit. When a deadline expired between +// statements, a rollback on the expired context would fail at once and the +// connection would be discarded; this one ends the transaction on the +// connection. When the deadline canceled a query in flight, pgx has +// already closed the connection and the server aborts the transaction with +// it, so this rollback changes nothing. A transaction that never reached +// COMMIT cannot have committed either way. +func RollbackDetached(ctx context.Context, tx pgx.Tx) { + rctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), 2*time.Second) + defer cancel() + _ = tx.Rollback(rctx) +} + // RunSerialized runs fn inside ONE transaction that holds the per-user // lock, and owns the whole lifecycle: begin, lock, fn, commit. // @@ -184,12 +208,12 @@ func RunSerialized(ctx context.Context, db TxBeginner, userID uuid.UUID, fn func func runSerializedOnce(ctx context.Context, db TxBeginner, userID uuid.UUID, fn func(context.Context, pgx.Tx) error) (err error) { tx, err := db.Begin(ctx) if err != nil { - return fmt.Errorf("identity: begin: %w", err) + return fmt.Errorf("identity: begin: %w: %w", ErrNotBegun, err) } committed := false defer func() { if !committed { - _ = tx.Rollback(ctx) + RollbackDetached(ctx, tx) } }() diff --git a/internal/identity/sessions.go b/internal/identity/sessions.go index 5c479655..97a8a16f 100644 --- a/internal/identity/sessions.go +++ b/internal/identity/sessions.go @@ -336,7 +336,7 @@ func slideSession(ctx context.Context, pool *pgxpool.Pool, id uuid.UUID, now, ne if err != nil { return fmt.Errorf("identity: touch session: begin: %w", err) } - defer func() { _ = tx.Rollback(ctx) }() + defer RollbackDetached(ctx, tx) if err := setLockWaitBound(ctx, tx); err != nil { return err } diff --git a/internal/server/admin_stage_test.go b/internal/server/admin_stage_test.go new file mode 100644 index 00000000..0f45c58f --- /dev/null +++ b/internal/server/admin_stage_test.go @@ -0,0 +1,280 @@ +// @spec system-auth-identity +// +// Administrative account mutations report failures by the stage the +// transaction reached (C-43): never began, rolled back before the commit, +// or uncertain at the commit. + +package server + +import ( + "context" + "errors" + "fmt" + "net/http" + "net/http/httptest" + "strings" + "sync" + "testing" + "time" + + "github.com/Hanalyx/openwatch/internal/auth" + "github.com/Hanalyx/openwatch/internal/identity" + "github.com/Hanalyx/openwatch/internal/users" + "github.com/google/uuid" + "github.com/jackc/pgx/v5" +) + +// beginRecorder records every Begin outcome from the pool it wraps. +type beginRecorder struct { + inner identity.TxBeginner + mu sync.Mutex + began int + errs []error +} + +func (b *beginRecorder) Begin(ctx context.Context) (pgx.Tx, error) { + tx, err := b.inner.Begin(ctx) + b.mu.Lock() + defer b.mu.Unlock() + if err != nil { + b.errs = append(b.errs, err) + return nil, err + } + b.began++ + return tx, nil +} + +// deadlineAtCommitBeginner rolls back, then fails the commit with the +// context deadline, as when the deadline expires while COMMIT is in flight +// and the outcome cannot be known. +type deadlineAtCommitBeginner struct{ inner identity.TxBeginner } + +type deadlineAtCommitTx struct{ pgx.Tx } + +func (b deadlineAtCommitBeginner) Begin(ctx context.Context) (pgx.Tx, error) { + tx, err := b.inner.Begin(ctx) + if err != nil { + return nil, err + } + return deadlineAtCommitTx{tx}, nil +} + +func (tx deadlineAtCommitTx) Commit(ctx context.Context) error { + _ = tx.Tx.Rollback(ctx) + return context.DeadlineExceeded +} + +type accountState struct { + disabled, deleted bool + passwordHash string +} + +func readAccountState(t *testing.T, pool interface { + QueryRow(context.Context, string, ...any) pgx.Row +}, id uuid.UUID) accountState { + t.Helper() + var s accountState + if err := pool.QueryRow(context.Background(), + `SELECT disabled_at IS NOT NULL, deleted_at IS NOT NULL, password_hash FROM users WHERE id = $1`, id). + Scan(&s.disabled, &s.deleted, &s.passwordHash); err != nil { + t.Fatalf("read account: %v", err) + } + return s +} + +// @ac AC-90 +// AC-90: an administrative mutation that cannot start its transaction, or +// whose deadline expires after it began, reports "not applied" and changes +// nothing; the commit stage keeps precedence, so an uncertain commit is +// never reported as not applied. +func TestAdminMutations_ClassifiedByTransactionStage(t *testing.T) { + t.Run("system-auth-identity/AC-90", func(t *testing.T) { + url, pool, srv := freshAPIServerWithMaxConns(t, lockTestPoolSize) + ctx := context.Background() + svc := users.NewService(pool, nil) + + t.Run("pool exhausted: no transaction begins", func(t *testing.T) { + // A deliberately small pool for the account transactions, with + // its only connection held. The binder and the audit writer use + // the server's own pool, so the request reaches the handler. + small := poolWithMaxConns(t, 1) + held, err := small.Acquire(ctx) + if err != nil { + t.Fatalf("hold the small pool's connection: %v", err) + } + rec := &beginRecorder{inner: small} + srv.handlers.users.UseTxSource(rec) + defer srv.handlers.users.UseTxSource(nil) + + type tcase struct { + name string + id uuid.UUID + req func(id uuid.UUID) *http.Request + } + mk := func(name string, disable bool, req func(uuid.UUID) *http.Request) tcase { + li := loginFresh(t, url, pool, "ac90"+strings.ReplaceAll(name, " ", "")) + if disable { + if err := svc.Disable(ctx, li.u.ID); err != nil { + t.Fatalf("disable: %v", err) + } + } + return tcase{name, li.u.ID, req} + } + userURL := func(id uuid.UUID) string { return url + "/api/v1/users/" + id.String() } + cases := []tcase{ + mk("disable", false, func(id uuid.UUID) *http.Request { + return asRole(t, "POST", userURL(id)+":disable", auth.RoleAdmin, nil) + }), + mk("enable", true, func(id uuid.UUID) *http.Request { + return asRole(t, "POST", userURL(id)+":enable", auth.RoleAdmin, nil) + }), + mk("reset", false, func(id uuid.UUID) *http.Request { + return asRole(t, "POST", userURL(id)+":reset-password", auth.RoleAdmin, + map[string]string{"new_password": "ac90-reset-Passphrase-3317"}) // pragma: allowlist secret + }), + mk("soft delete", false, func(id uuid.UUID) *http.Request { + return asRole(t, "DELETE", userURL(id), auth.RoleAdmin, nil) + }), + } + // The four requests run together: each waits the full operation + // deadline for a connection that never frees. + var wg sync.WaitGroup + for _, c := range cases { + c := c + before := readAccountState(t, pool, c.id) + creds := snapshotCredentials(t, pool, c.id) + wg.Add(1) + go func() { + defer wg.Done() + req := c.req(c.id) + cid := "ac90-" + strings.ReplaceAll(uuid.NewString(), "-", "") + req.Header.Set("X-Correlation-Id", cid) + start := time.Now() + got := doAPI(t, req) + elapsed := time.Since(start) + if got.status != http.StatusServiceUnavailable || got.code != "server.error" || !got.retryable { + t.Errorf("%s: response = %d %q retryable=%v, want 503 server.error retryable", c.name, got.status, got.code, got.retryable) + } + if !strings.Contains(got.message, "could not start") { + t.Errorf("%s: message %q does not say the change could not start", c.name, got.message) + } + if elapsed < identity.OperationDeadline-time.Second { + t.Errorf("%s: answered after %v, before the %v operation deadline", c.name, elapsed, identity.OperationDeadline) + } + if after := readAccountState(t, pool, c.id); after != before { + t.Errorf("%s: account state changed: %+v -> %+v", c.name, before, after) + } + if !snapshotCredentials(t, pool, c.id).equal(creds) { + t.Errorf("%s: credential rows changed", c.name) + } + time.Sleep(2 * time.Second) // the audit writer batches + var n int + if err := pool.QueryRow(context.Background(), + `SELECT count(*) FROM audit_events WHERE action LIKE 'admin.user.%' AND correlation_id = $1`, cid).Scan(&n); err != nil { + t.Errorf("%s: read audit: %v", c.name, err) + } else if n != 0 { + t.Errorf("%s: %d success audit events for a change that was not applied", c.name, n) + } + }() + } + wg.Wait() + held.Release() + + rec.mu.Lock() + defer rec.mu.Unlock() + if rec.began != 0 { + t.Errorf("%d transactions began on the exhausted pool, want 0", rec.began) + } + if len(rec.errs) != len(cases) { + t.Errorf("begin attempts = %d, want %d", len(rec.errs), len(cases)) + } + for _, e := range rec.errs { + if !errors.Is(e, context.DeadlineExceeded) { + t.Errorf("begin failed with %v, want the operation deadline", e) + } + } + }) + + t.Run("deadline after the transaction began rolls back and releases", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac90midwork") + before := readAccountState(t, pool, li.u.ID) + release := holdUserLock(t, pool, li.u.ID, identity.LockWaitBound+15*time.Second) + dctx, cancel := context.WithTimeout(ctx, time.Second) + err := svc.Disable(dctx, li.u.ID) + cancel() + release() + if err == nil || errors.Is(err, identity.ErrNotBegun) || errors.Is(err, identity.ErrCommitUnknown) { + t.Errorf("err = %v, want a deadline after the transaction began", err) + } + if !errors.Is(err, context.DeadlineExceeded) { + t.Errorf("err = %v does not carry the deadline", err) + } + if readAccountState(t, pool, li.u.ID) != before { + t.Error("the account changed although the transaction did not reach its commit") + } + waitPoolIdle(t, pool) + // The transaction ended. The deadline canceled a query in + // flight, so pgx closed that connection and the server aborted + // the transaction with it; no backend is left holding the + // account lock, and it can be taken at once. + var idleInTx int + if err := pool.QueryRow(ctx, ` + SELECT count(*) FROM pg_stat_activity + WHERE datname = current_database() AND state LIKE 'idle in transaction%' + AND pid <> pg_backend_pid()`).Scan(&idleInTx); err != nil { + t.Fatalf("read activity: %v", err) + } + if idleInTx != 0 { + t.Errorf("%d backends left idle in a transaction", idleInTx) + } + lctx, lcancel := context.WithTimeout(ctx, time.Second) + defer lcancel() + probe, err := pool.Begin(lctx) + if err != nil { + t.Fatalf("begin probe: %v", err) + } + if err := identity.LockUser(lctx, probe, li.u.ID); err != nil { + t.Errorf("the account lock is still held after the deadline: %v", err) + } + _ = probe.Rollback(ctx) + }) + + t.Run("mapping is by stage, commit first", func(t *testing.T) { + for _, tc := range []struct { + name string + err error + status int + retryable bool + says string + }{ + {"not begun", fmt.Errorf("users: begin: %w: %w", identity.ErrNotBegun, context.DeadlineExceeded), 503, true, "could not start"}, + {"rolled back after a deadline", fmt.Errorf("users: lock: %w", context.DeadlineExceeded), 503, true, "did not complete in time"}, + {"uncertain commit interrupted by a deadline", identity.ClassifyCommitError(context.DeadlineExceeded), 503, false, "may or may not"}, + } { + rec := httptest.NewRecorder() + if !mapUserAdminErr(rec, tc.err) { + t.Fatalf("%s: not mapped", tc.name) + } + body := rec.Body.String() + if rec.Code != tc.status || !strings.Contains(body, tc.says) || + strings.Contains(body, `"retryable":true`) != tc.retryable { + t.Errorf("%s: %d %s", tc.name, rec.Code, body) + } + } + }) + + t.Run("deadline during the commit stays unknown over HTTP", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac90commit") + before := readAccountState(t, pool, li.u.ID) + srv.handlers.users.UseTxSource(deadlineAtCommitBeginner{inner: pool}) + got := doAPI(t, asRole(t, "POST", url+"/api/v1/users/"+li.u.ID.String()+":disable", auth.RoleAdmin, nil)) + srv.handlers.users.UseTxSource(nil) + if got.status != http.StatusServiceUnavailable || got.retryable || !strings.Contains(got.message, "may or may not") { + t.Errorf("response = %d retryable=%v %q, want the unknown outcome", got.status, got.retryable, got.message) + } + if readAccountState(t, pool, li.u.ID) != before { + t.Error("the account changed although this variant rolled back") + } + }) + }) +} diff --git a/internal/server/api_helpers_test.go b/internal/server/api_helpers_test.go index f2140b1b..2ab70ea5 100644 --- a/internal/server/api_helpers_test.go +++ b/internal/server/api_helpers_test.go @@ -163,11 +163,39 @@ func freshAPIServerWithHandles(t *testing.T) (string, *pgxpool.Pool, *Server) { // (so -p N parallel packages never share tables), but the gate still // guards against pointing OPENWATCH_TEST_DSN at a dev/prod server. _ = apiTestDSN(t) + return apiServerOnPool(t, dbtest.Pool(t)) +} + +// freshAPIServerWithMaxConns is freshAPIServerWithHandles on a pool with +// an explicit connection limit. The default limit follows the machine's +// CPU count, so a test that holds connections must not rely on it. +func freshAPIServerWithMaxConns(t *testing.T, maxConns int32) (string, *pgxpool.Pool, *Server) { + t.Helper() + _ = apiTestDSN(t) + return apiServerOnPool(t, poolWithMaxConns(t, maxConns)) +} + +// poolWithMaxConns opens a pool on this package's test database with an +// explicit connection limit, closed on cleanup. +func poolWithMaxConns(t *testing.T, maxConns int32) *pgxpool.Pool { + t.Helper() + cfg, err := pgxpool.ParseConfig(dbtest.DSN(t)) + if err != nil { + t.Fatalf("parse test DSN: %v", err) + } + cfg.MaxConns = maxConns + pool, err := pgxpool.NewWithConfig(context.Background(), cfg) + if err != nil { + t.Fatalf("open pool: %v", err) + } + t.Cleanup(pool.Close) + return pool +} +func apiServerOnPool(t *testing.T, pool *pgxpool.Pool) (string, *pgxpool.Pool, *Server) { + t.Helper() ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) t.Cleanup(cancel) - - pool := dbtest.Pool(t) _, _ = pool.Exec(ctx, "TRUNCATE TABLE audit_events") _, _ = pool.Exec(ctx, "TRUNCATE TABLE idempotency_keys") _, _ = pool.Exec(ctx, "TRUNCATE TABLE system_config") diff --git a/internal/server/closure_regressions_test.go b/internal/server/closure_regressions_test.go index 1aca44e4..67d61823 100644 --- a/internal/server/closure_regressions_test.go +++ b/internal/server/closure_regressions_test.go @@ -261,7 +261,11 @@ func holdUserLock(t *testing.T, pool *pgxpool.Pool, uid uuid.UUID, max time.Dura // administrative account mutations. func TestLockWait_BoundedInProductionConfiguration(t *testing.T) { t.Run("system-auth-identity/AC-73", func(t *testing.T) { - url, pool := freshAPIServer(t) + // Sequential, on an explicitly sized pool. The default size follows + // the CPU count, and on a 4-connection pool eight parallel holders + // starved the requests of connections, so they hit the operation + // deadline instead of the lock limit (Go CI run 36081673305). + url, pool, _ := freshAPIServerWithMaxConns(t, lockTestPoolSize) ctx := context.Background() svc := users.NewService(pool, nil) paths := []string{"login", "body refresh", "cookie refresh", "logout", @@ -269,7 +273,7 @@ func TestLockWait_BoundedInProductionConfiguration(t *testing.T) { for _, path := range paths { path := path t.Run(path, func(t *testing.T) { - t.Parallel() + defer waitPoolIdle(t, pool) li := loginFresh(t, url, pool, "ac73"+strings.ReplaceAll(path, " ", "")) if path == "admin enable" { if err := svc.Disable(ctx, li.u.ID); err != nil { @@ -346,6 +350,26 @@ func TestLockWait_BoundedInProductionConfiguration(t *testing.T) { }) } +// lockTestPoolSize covers one request, one lock holder and the test's own +// observation queries, with room for the audit writer, when cases run one +// at a time. +const lockTestPoolSize = 8 + +// waitPoolIdle confirms every connection went back to the pool, so the +// next case starts with its holder's connection released. The audit +// writer borrows a connection briefly, so it polls, bounded. +func waitPoolIdle(t *testing.T, pool *pgxpool.Pool) { + t.Helper() + deadline := time.Now().Add(5 * time.Second) + for time.Now().Before(deadline) { + if pool.Stat().AcquiredConns() == 0 { + return + } + time.Sleep(20 * time.Millisecond) + } + t.Errorf("%d connections still acquired after the case", pool.Stat().AcquiredConns()) +} + // holdRowLocks takes FOR UPDATE on every row of table for the user, on a // second connection, without touching the users row. func holdRowLocks(t *testing.T, pool *pgxpool.Pool, table string, uid uuid.UUID, max time.Duration) (release func()) { @@ -371,7 +395,7 @@ func holdRowLocks(t *testing.T, pool *pgxpool.Pool, table string, uid uuid.UUID, // never acquired. func TestLockWait_LaterLockTimesOut(t *testing.T) { t.Run("system-auth-identity/AC-81", func(t *testing.T) { - url, pool := freshAPIServer(t) + url, pool, _ := freshAPIServerWithMaxConns(t, lockTestPoolSize) for _, tc := range []struct{ path, table string }{ {"body refresh", "refresh_tokens"}, // Not sessions: a locked session row stalls the cookie @@ -383,7 +407,7 @@ func TestLockWait_LaterLockTimesOut(t *testing.T) { } { tc := tc t.Run(tc.path, func(t *testing.T) { - t.Parallel() + defer waitPoolIdle(t, pool) li := loginFresh(t, url, pool, "ac81"+strings.ReplaceAll(tc.path, " ", "")) var req *http.Request switch tc.path { diff --git a/internal/server/users_admin_handlers.go b/internal/server/users_admin_handlers.go index b1e4ae5c..04146149 100644 --- a/internal/server/users_admin_handlers.go +++ b/internal/server/users_admin_handlers.go @@ -9,6 +9,7 @@ package server import ( + "context" "encoding/json" "errors" "net/http" @@ -31,18 +32,31 @@ func mapUserAdminErr(w http.ResponseWriter, err error) bool { return false case errors.Is(err, users.ErrUserNotFound): writeError(w, http.StatusNotFound, "users.not_found", "client", "user not found", false) + // Classified by the stage the transaction reached, in this order. + // The commit stage comes FIRST: an uncertain commit stays uncertain + // even when what interrupted it was a deadline, which the later cases + // would otherwise read as "not applied". Spec system-auth-identity + // C-37, C-43. case errors.Is(err, identity.ErrCommitUnknown): - // The commit's outcome is unknown, including a deadline that - // expired during it. Neither result is asserted, and a blind - // retry is not invited. Spec system-auth-identity C-37, C-43. + // Neither result is asserted, and a blind retry is not invited. writeError(w, http.StatusServiceUnavailable, "server.error", "server", "the change may or may not have been applied. Check the account before trying again.", false) + case errors.Is(err, identity.ErrNotBegun): + // No transaction began, typically because no connection became + // free before the deadline. Nothing was read or written. + writeError(w, http.StatusServiceUnavailable, "server.error", "server", + "the change was not applied because the server could not start it in time. Try again.", true) case identity.IsLockTimeout(err): // A lock wait exceeded its limit, on the account lock or on a - // later row lock, and the transaction rolled back, so the change - // was not applied. Retrying is safe. Spec system-auth-identity C-43. + // later row lock, and the transaction rolled back. writeError(w, http.StatusServiceUnavailable, "server.error", "server", "the change was not applied because a lock could not be acquired in time. Try again.", true) + case errors.Is(err, context.DeadlineExceeded): + // The deadline expired after the transaction began and before its + // commit, so it rolled back: a transaction that never reached + // COMMIT cannot have committed. + writeError(w, http.StatusServiceUnavailable, "server.error", "server", + "the change was not applied because it did not complete in time. Try again.", true) case errors.Is(err, identity.ErrPasswordTooShort), errors.Is(err, identity.ErrPasswordTooLong), errors.Is(err, identity.ErrPasswordBreached): diff --git a/internal/users/users.go b/internal/users/users.go index 3e5993fa..01d4bfa2 100644 --- a/internal/users/users.go +++ b/internal/users/users.go @@ -118,10 +118,17 @@ func (s *Service) UseTxSource(b identity.TxBeginner) { s.txs = b } // lockedTx begins a transaction for the locked account operations. func (s *Service) lockedTx(ctx context.Context) (pgx.Tx, error) { + var tx pgx.Tx + var err error if s.txs != nil { - return s.txs.Begin(ctx) + tx, err = s.txs.Begin(ctx) + } else { + tx, err = s.pool.Begin(ctx) } - return s.pool.Begin(ctx) + if err != nil { + return nil, fmt.Errorf("%w: %w", identity.ErrNotBegun, err) + } + return tx, nil } // NewService binds a Service to a DB pool. The breach corpus is @@ -195,7 +202,7 @@ func (s *Service) CreateFederatedUser(ctx context.Context, username, email strin if err != nil { return User{}, fmt.Errorf("users: begin: %w", err) } - defer func() { _ = tx.Rollback(ctx) }() + defer identity.RollbackDetached(ctx, tx) var u User const insUser = ` @@ -415,7 +422,7 @@ func (s *Service) mutateAccountState(ctx context.Context, id uuid.UUID, stmt str if err != nil { return fmt.Errorf("users: begin: %w", err) } - defer func() { _ = tx.Rollback(ctx) }() + defer identity.RollbackDetached(ctx, tx) if err := identity.LockUser(ctx, tx, id); err != nil { if errors.Is(err, pgx.ErrNoRows) { @@ -467,7 +474,7 @@ func (s *Service) AdminResetPassword(ctx context.Context, id uuid.UUID, newPassw if err != nil { return fmt.Errorf("users: begin: %w", err) } - defer func() { _ = tx.Rollback(ctx) }() + defer identity.RollbackDetached(ctx, tx) if err := identity.LockUser(ctx, tx, id); err != nil { if errors.Is(err, pgx.ErrNoRows) { return ErrUserNotFound @@ -561,7 +568,7 @@ func (s *Service) Enable(ctx context.Context, id uuid.UUID) (transitioned bool, if err != nil { return false, fmt.Errorf("users: begin: %w", err) } - defer func() { _ = tx.Rollback(ctx) }() + defer identity.RollbackDetached(ctx, tx) if err := identity.LockUser(ctx, tx, id); err != nil { if errors.Is(err, pgx.ErrNoRows) { diff --git a/specs/system/auth-identity.spec.yaml b/specs/system/auth-identity.spec.yaml index a5c3e7c1..217a2053 100644 --- a/specs/system/auth-identity.spec.yaml +++ b/specs/system/auth-identity.spec.yaml @@ -409,7 +409,13 @@ spec: during the commit: the outcome is unknown and is reported as ErrCommitUnknown, never as success or failure. Credential and administrative paths answer a known rollback from a lock timeout - with 503 server.error, retryable. Logout clears both credential + with 503 server.error, retryable. Administrative account mutations + are classified by the stage the transaction reached, and the commit + stage is tested FIRST: an uncertain commit stays unknown (503, not + retryable) even when what interrupted it was a deadline. A + transaction that never began, because no connection became free + before the deadline, and one that rolled back after a lock timeout + or a deadline before its commit, are "not applied" (503, retryable). Logout clears both credential cookies on every outcome, because the web client treats any logout response as signed out, and so its lock-timeout answer is 503 server.error, not retryable: with the cookies cleared a repeated @@ -1756,9 +1762,19 @@ spec: - "POST /users/{id}:reset-password" - "DELETE /users/{id}" method: > - The unmodified server, with no test override of either limit. A - safety timer releases the held lock well after the limit, so a - missing limit fails the test instead of hanging it. + The unmodified server, with no test override of either limit, on a + pool explicitly sized to 8 connections, one case at a time. Each + case confirms every connection is back in the pool before the next + begins. A safety timer releases the held lock well after the + limit, so a missing limit fails the test instead of hanging it. + fixture_history: > + The first version ran the eight cases in parallel on the default + pool, whose size follows the CPU count. On a 4-connection pool the + holders starved the requests of connections, so they hit the + 15 s operation deadline instead of the lock limit (Go CI run + 36081673305, reproduced locally with an explicit 4-connection + pool). That was a fixture assumption, separate from the + production defect AC-90 covers. expected_output: per_path: logout: @@ -1918,6 +1934,7 @@ spec: references_constraints: [C-43] inputs: initial_state: "A second connection holds FOR UPDATE on the user's rows in a later table, not on the users row" + method: "One case at a time on a pool explicitly sized to 8 connections; every connection is back in the pool before the next case" variants: - name: "Body refresh" held: "refresh_tokens" @@ -2111,3 +2128,54 @@ spec: transaction_effects: "The account is not disabled" cookies: "None set" audit: "No admin.user.disabled row for the request's correlation id, read after a settle period" + + - id: AC-90 + description: > + An administrative account mutation reports its failure by the stage + the transaction reached. One that could not start reports "not + applied" and changes nothing; one whose deadline expired after it + began rolls back and releases the account; an uncertain commit is + never reported as "not applied", even when a deadline interrupted + it. + priority: critical + references_constraints: [C-37, C-43] + inputs: + variants: + - name: "Pool exhausted" + setup: > + The account transactions draw from a separate 1-connection pool + whose connection is held. POST :disable, POST :enable (user + disabled first), POST :reset-password and DELETE /users/{id}, + each with its own correlation id, run together. + - name: "Deadline after the transaction began" + setup: "Service Disable with a 1 s caller deadline while another connection holds the account lock" + - name: "Mapping order" + setup: "The handler's error mapping given a not-begun error, a rolled-back deadline, and a commit made uncertain by a deadline" + - name: "Deadline during the commit" + setup: "POST :disable; the commit is rolled back, then fails with the context deadline" + expected_output: + per_variant: + Pool exhausted: + response: {status: 503, code: server.error, retryable: true} + message_states: "The change could not start" + answered_after: "The operation deadline" + transactions_begun: 0 + begin_errors: "Every one carries the operation deadline" + transaction_effects: "Account state and credential rows unchanged" + audit: "No admin.user.* row for any request's correlation id, read after a settle period" + cookies: "None set" + Deadline after the transaction began: + returns: "An error carrying the deadline; neither ErrNotBegun nor ErrCommitUnknown" + transaction_effects: "The account is unchanged" + subsequent: + - "Every connection is back in the pool" + - "No backend is left idle in a transaction" + - "The account lock can be taken at once" + Mapping order: + not_begun: {status: 503, retryable: true, message_states: "could not start"} + rolled_back_deadline: {status: 503, retryable: true, message_states: "did not complete in time"} + uncertain_commit_from_deadline: {status: 503, retryable: false, message_states: "may or may not have been applied"} + Deadline during the commit: + response: {status: 503, code: server.error, retryable: false} + message_states: "The change may or may not have been applied" + transaction_effects: "The account is unchanged in this rolled-back variant" From 49ff8d45c377a4431081e15cb834183fde66eeeb Mon Sep 17 00:00:00 2001 From: Remylus Losius Date: Fri, 25 Sep 2026 09:55:32 -0400 Subject: [PATCH 5/6] test(auth): prove the detached rollback is bounded and never changes the reported outcome Review follow-up to 4a046974. RollbackDetached's limit is now a named constant, RollbackCleanupLimit (2 s), and a rollback that fails for any reason other than an already closed transaction is logged. Its result still never changes how an attempt is reported. AC-91 covers four cases: - The cleanup context is not done while the rollback runs, keeps the caller's values, and carries a positive deadline at most 2 s away. - A real rollback failure in the driver (backend terminated, SQLSTATE 57P01) closes the connection; an untouched control stays open. This exercises pgx v5.9.2 itself, not a mock. - Through the users service's transaction seam, a pre-commit failure whose cleanup also fails still answers the retryable 503 "not applied", and an uncertain commit whose cleanup fails still answers the non-retryable 503. Each uses a user created for the case, so its unchanged-state assertions describe that attempt alone. C-43 now states that cleanup can add up to 2 s beyond the 15 s operation deadline and is not contained within it. Specs: system-auth-identity 1.9.0, C-43 amended, AC-90 input narrowed, AC-91 added. Refs: bugs/OW-069, bugs/doing/OW-062 AC-54 --- internal/identity/rollback_cleanup_test.go | 64 +++++++++ internal/identity/serialize.go | 33 +++-- internal/server/rollback_cleanup_test.go | 154 +++++++++++++++++++++ specs/system/auth-identity.spec.yaml | 65 ++++++++- 4 files changed, 305 insertions(+), 11 deletions(-) create mode 100644 internal/identity/rollback_cleanup_test.go create mode 100644 internal/server/rollback_cleanup_test.go diff --git a/internal/identity/rollback_cleanup_test.go b/internal/identity/rollback_cleanup_test.go new file mode 100644 index 00000000..d082ae37 --- /dev/null +++ b/internal/identity/rollback_cleanup_test.go @@ -0,0 +1,64 @@ +// @spec system-auth-identity + +package identity + +import ( + "context" + "testing" + "time" + + "github.com/jackc/pgx/v5" +) + +// rollbackCapture records the context its Rollback receives. +type rollbackCapture struct { + pgx.Tx + got context.Context + errAt error // ctx.Err() while the rollback runs + calledAt time.Time +} + +func (r *rollbackCapture) Rollback(ctx context.Context) error { + r.got = ctx + r.errAt = ctx.Err() + r.calledAt = time.Now() + return nil +} + +type cleanupKey struct{} + +// @ac AC-91 +// AC-91, the cleanup context: detached from the operation's cancellation, +// carrying its values, with a deadline of its own no more than +// RollbackCleanupLimit away. +func TestRollbackDetached_CleanupContext(t *testing.T) { + t.Run("system-auth-identity/AC-91", func(t *testing.T) { + parent, cancel := context.WithTimeout( + context.WithValue(context.Background(), cleanupKey{}, "request-value"), time.Millisecond) + defer cancel() + <-parent.Done() // the operation deadline has expired + + tx := &rollbackCapture{} + RollbackDetached(parent, tx) + if tx.got == nil { + t.Fatal("Rollback was not called") + } + if err := tx.errAt; err != nil { + t.Errorf("cleanup context is already done (%v): it was not detached from the expired operation", err) + } + if v, _ := tx.got.Value(cleanupKey{}).(string); v != "request-value" { + t.Errorf("cleanup context lost the caller's values (got %q)", v) + } + deadline, ok := tx.got.Deadline() + if !ok { + t.Fatal("cleanup context has no deadline: cleanup is unbounded") + } + remaining := deadline.Sub(tx.calledAt) + if remaining <= 0 || remaining > RollbackCleanupLimit { + t.Errorf("cleanup deadline %v away, want positive and at most %v", remaining, RollbackCleanupLimit) + } + if RollbackCleanupLimit > 2*time.Second { + t.Errorf("RollbackCleanupLimit = %v, the documented limit is 2s", RollbackCleanupLimit) + } + }) +} diff --git a/internal/identity/serialize.go b/internal/identity/serialize.go index 75c27e31..999f01be 100644 --- a/internal/identity/serialize.go +++ b/internal/identity/serialize.go @@ -140,18 +140,33 @@ func ClassifyCommitError(err error) error { // or written, so the operation was not applied. Spec C-43. var ErrNotBegun = errors.New("identity: transaction did not begin") +// RollbackCleanupLimit bounds the detached rollback. Cleanup runs after +// the operation deadline may already have expired, so it can add up to +// this much beyond OperationDeadline; it is not contained within it. +// Spec C-43. +const RollbackCleanupLimit = 2 * time.Second + // RollbackDetached rolls tx back on a context detached from ctx's -// cancellation, with its own short limit. When a deadline expired between -// statements, a rollback on the expired context would fail at once and the -// connection would be discarded; this one ends the transaction on the -// connection. When the deadline canceled a query in flight, pgx has -// already closed the connection and the server aborts the transaction with -// it, so this rollback changes nothing. A transaction that never reached -// COMMIT cannot have committed either way. +// cancellation, keeping ctx's values, with its own RollbackCleanupLimit. +// When a deadline expired between statements, a rollback on the expired +// context would fail at once and the connection would be discarded; this +// one ends the transaction on the connection. When the deadline canceled a +// query in flight, pgx has already closed the connection and the server +// aborts the transaction with it. +// +// Its result never changes how the operation is reported. A transaction +// that never reached COMMIT cannot have committed, whether or not cleanup +// is confirmed; what an unconfirmed rollback leaves uncertain is when the +// server releases the transaction's locks. And an uncertain commit stays +// uncertain: cleanup after it proves nothing about the commit. When the +// rollback fails, pgx discards the connection and the failure is logged. func RollbackDetached(ctx context.Context, tx pgx.Tx) { - rctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), 2*time.Second) + rctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), RollbackCleanupLimit) defer cancel() - _ = tx.Rollback(rctx) + if err := tx.Rollback(rctx); err != nil && !errors.Is(err, pgx.ErrTxClosed) { + slog.WarnContext(rctx, "identity: rollback did not complete; the connection is discarded", + slog.String("error", err.Error())) + } } // RunSerialized runs fn inside ONE transaction that holds the per-user diff --git a/internal/server/rollback_cleanup_test.go b/internal/server/rollback_cleanup_test.go new file mode 100644 index 00000000..04bc8715 --- /dev/null +++ b/internal/server/rollback_cleanup_test.go @@ -0,0 +1,154 @@ +// @spec system-auth-identity +// +// Cleanup after a failed administrative transaction (C-43, AC-91). The +// real driver's failure path is exercised against the database; the HTTP +// classification is exercised through the users service's transaction +// seam. Durable-state assertions use a user created for the case, so they +// describe this attempt alone. + +package server + +import ( + "context" + "errors" + "fmt" + "net/http" + "strings" + "sync/atomic" + "testing" + "time" + + "github.com/Hanalyx/openwatch/internal/auth" + "github.com/Hanalyx/openwatch/internal/identity" + "github.com/jackc/pgx/v5" + pgerr "github.com/jackc/pgx/v5/pgconn" +) + +// failingCleanupBeginner wraps real transactions. Its rollback always +// reports a failure, after really rolling back. mode selects how the +// attempt fails first: "pre-commit" fails the first statement with the +// deadline; "unknown commit" rolls back and then fails the commit with no +// SQLSTATE, so its outcome cannot be known. +type failingCleanupBeginner struct { + inner identity.TxBeginner + mode string + rollbacks atomic.Int32 +} + +type failingCleanupTx struct { + pgx.Tx + b *failingCleanupBeginner +} + +func (b *failingCleanupBeginner) Begin(ctx context.Context) (pgx.Tx, error) { + tx, err := b.inner.Begin(ctx) + if err != nil { + return nil, err + } + return &failingCleanupTx{Tx: tx, b: b}, nil +} + +func (tx *failingCleanupTx) Exec(ctx context.Context, sql string, args ...any) (pgerr.CommandTag, error) { + if tx.b.mode == "pre-commit" && strings.Contains(sql, "set_config") { + return pgerr.CommandTag{}, context.DeadlineExceeded + } + return tx.Tx.Exec(ctx, sql, args...) +} + +func (tx *failingCleanupTx) Commit(ctx context.Context) error { + if tx.b.mode == "unknown commit" { + _ = tx.Tx.Rollback(ctx) + return fmt.Errorf("write tcp 127.0.0.1:5432: %w", errors.New("connection reset by peer")) + } + return tx.Tx.Commit(ctx) +} + +func (tx *failingCleanupTx) Rollback(ctx context.Context) error { + tx.b.rollbacks.Add(1) + _ = tx.Tx.Rollback(ctx) + return errors.New("injected cleanup failure") +} + +// @ac AC-91 +// AC-91: a rollback that fails in the real driver discards the +// connection, and a failed cleanup never changes how the attempt is +// reported. +func TestRollbackCleanup_FailureAndClassification(t *testing.T) { + t.Run("system-auth-identity/AC-91", func(t *testing.T) { + url, pool, srv := freshAPIServerWithMaxConns(t, lockTestPoolSize) + ctx := context.Background() + + t.Run("a real rollback failure discards the connection", func(t *testing.T) { + for _, terminate := range []bool{false, true} { + tx, err := pool.Begin(ctx) + if err != nil { + t.Fatalf("begin: %v", err) + } + var pid int32 + if err := tx.QueryRow(ctx, `SELECT pg_backend_pid()`).Scan(&pid); err != nil { + t.Fatalf("backend pid: %v", err) + } + if terminate { + // The backend goes away under an open transaction, so the + // real ROLLBACK fails on the wire. + if _, err := pool.Exec(ctx, `SELECT pg_terminate_backend($1)`, pid); err != nil { + t.Fatalf("terminate backend: %v", err) + } + deadline := time.Now().Add(5 * time.Second) + for time.Now().Before(deadline) { + var n int + _ = pool.QueryRow(ctx, `SELECT count(*) FROM pg_stat_activity WHERE pid = $1`, pid).Scan(&n) + if n == 0 { + break + } + time.Sleep(20 * time.Millisecond) + } + } + conn := tx.Conn() + identity.RollbackDetached(ctx, tx) + if closed := conn.IsClosed(); closed != terminate { + t.Errorf("terminated=%v: connection closed = %v, want %v", terminate, closed, terminate) + } + } + waitPoolIdle(t, pool) + }) + + for _, tc := range []struct { + mode string + retryable bool + says string + }{ + {"pre-commit", true, "did not complete in time"}, + {"unknown commit", false, "may or may not"}, + } { + tc := tc + t.Run(tc.mode+" with failed cleanup", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac91"+strings.ReplaceAll(tc.mode, " ", "")) + before := readAccountState(t, pool, li.u.ID) + creds := snapshotCredentials(t, pool, li.u.ID) + b := &failingCleanupBeginner{inner: pool, mode: tc.mode} + srv.handlers.users.UseTxSource(b) + got := doAPI(t, asRole(t, "POST", url+"/api/v1/users/"+li.u.ID.String()+":disable", auth.RoleAdmin, nil)) + srv.handlers.users.UseTxSource(nil) + + if b.rollbacks.Load() == 0 { + t.Fatal("the cleanup was never attempted, so this case proves nothing") + } + if got.status != http.StatusServiceUnavailable || got.code != "server.error" || got.retryable != tc.retryable { + t.Errorf("response = %d %q retryable=%v, want 503 server.error retryable=%v", got.status, got.code, got.retryable, tc.retryable) + } + if !strings.Contains(got.message, tc.says) { + t.Errorf("message %q, want it to say %q", got.message, tc.says) + } + // A user created for this case, so these describe this + // attempt: nothing it wrote survived. + if readAccountState(t, pool, li.u.ID) != before { + t.Error("the account changed") + } + if !snapshotCredentials(t, pool, li.u.ID).equal(creds) { + t.Error("credential rows changed") + } + }) + } + }) +} diff --git a/specs/system/auth-identity.spec.yaml b/specs/system/auth-identity.spec.yaml index 217a2053..99055aa9 100644 --- a/specs/system/auth-identity.spec.yaml +++ b/specs/system/auth-identity.spec.yaml @@ -415,7 +415,16 @@ spec: retryable) even when what interrupted it was a deadline. A transaction that never began, because no connection became free before the deadline, and one that rolled back after a lock timeout - or a deadline before its commit, are "not applied" (503, retryable). Logout clears both credential + or a deadline before its commit, are "not applied" (503, retryable). + The rollback after a failure runs on a context detached from the + operation's cancellation, keeping its values, with its own limit, + identity.RollbackCleanupLimit, 2 seconds. Cleanup can therefore add + up to 2 seconds beyond OperationDeadline; it is not contained within + it. Its result never changes how the attempt is reported: a + transaction that never reached COMMIT cannot have committed, so an + unconfirmed rollback leaves only the release of its locks + uncertain, and a failed cleanup after an uncertain commit never + turns it into "not applied". Logout clears both credential cookies on every outcome, because the web client treats any logout response as signed out, and so its lock-timeout answer is 503 server.error, not retryable: with the cookies cleared a repeated @@ -2161,7 +2170,7 @@ spec: answered_after: "The operation deadline" transactions_begun: 0 begin_errors: "Every one carries the operation deadline" - transaction_effects: "Account state and credential rows unchanged" + transaction_effects: "Account state and credential rows unchanged, for users created for this case, so the assertion describes this attempt alone" audit: "No admin.user.* row for any request's correlation id, read after a settle period" cookies: "None set" Deadline after the transaction began: @@ -2179,3 +2188,55 @@ spec: response: {status: 503, code: server.error, retryable: false} message_states: "The change may or may not have been applied" transaction_effects: "The account is unchanged in this rolled-back variant" + + - id: AC-91 + description: > + Cleanup after a failed administrative transaction is bounded, and its + outcome never changes how the attempt is reported. The rollback runs + on a context detached from the expired operation that keeps its + values and carries its own deadline; a rollback that really fails in + the driver discards the connection; and a failed cleanup leaves a + pre-commit failure "not applied" and an uncertain commit uncertain. + priority: critical + references_constraints: [C-37, C-43] + inputs: + variants: + - name: "Cleanup context" + setup: "RollbackDetached called with an operation context whose deadline has already expired and which carries a value" + - name: "Real driver failure" + setup: > + A pooled transaction whose backend is terminated with + pg_terminate_backend before RollbackDetached runs, and a + control transaction whose backend is left alone + - name: "Pre-commit failure, cleanup fails" + setup: > + POST /users/{id}:disable through the transaction seam: the first + statement fails with the deadline, and the rollback reports a + failure after really rolling back + - name: "Uncertain commit, cleanup fails" + setup: > + POST /users/{id}:disable through the transaction seam: the + commit fails with no SQLSTATE, and the rollback reports a + failure + fixture: "Each HTTP variant uses a user created for it, so durable-state assertions describe that attempt alone" + expected_output: + per_variant: + Cleanup context: + done_while_rolling_back: false + caller_value_present: true + deadline: "Present, positive, at most RollbackCleanupLimit (2 s) away" + Real driver failure: + terminated: "The rollback fails (SQLSTATE 57P01) and the connection is closed" + control: "The connection stays open" + Pre-commit failure, cleanup fails: + response: {status: 503, code: server.error, retryable: true} + message_states: "did not complete in time" + transaction_effects: "Account state and credential rows unchanged" + cookies: "None set" + Uncertain commit, cleanup fails: + response: {status: 503, code: server.error, retryable: false} + message_states: "may or may not have been applied" + transaction_effects: "Account unchanged in this rolled-back variant" + cookies: "None set" + audit: "Not asserted" + timing: "Cleanup may add up to 2 s beyond the 15 s operation deadline" From 1f08433de7ccb2efa027fa897114176a983d1a4c Mon Sep 17 00:00:00 2001 From: Remylus Losius Date: Fri, 25 Sep 2026 10:52:58 -0400 Subject: [PATCH 6/6] fix(auth): report a committed admin change truthfully and answer 503 when the role lookup fails Review corrections to 49ff8d45, from a source review of the head. A committed disable or enable could be reported as not applied. The handler committed, emitted its success audit, then re-read the user; a failure of that read went through the admin error mapping, so a deadline read as "not applied" and a concurrent delete as 404. DisableUser and EnableUser now read the user inside the locked transaction and return it only after the commit is confirmed. No read follows the commit. A failed role lookup answered 401. The cookie binder mapped every role lookup error to session_user_lookup_failed, a refused credential, which can trigger a refresh during an infrastructure failure. Only identity.ErrNoRoles, the confirmed answer, still refuses; any other error answers 503 as role_lookup_unavailable, declared in the audit contract. RolesForUser now checks rows.Err(), so an error that ends the rows can no longer read as an empty role list. AC-91 now asserts the driver's real rollback error, SQLSTATE 57P01, through RollbackDetachedErr; RollbackDetached still discards it. Specs: system-auth-identity 1.9.0, C-45 and AC-92 added, AC-91 amended; api-users 1.4.0, C-08 amended, AC-21 added. Refs: bugs/OW-069, bugs/doing/OW-062 --- audit/events.yaml | 7 +- internal/audit/events.gen.go | 4 +- internal/identity/account_state_test.go | 4 +- internal/identity/binder.go | 21 +++- internal/identity/serialize.go | 15 ++- internal/server/committed_response_test.go | 111 ++++++++++++++++++ internal/server/role_lookup_test.go | 97 ++++++++++++++++ internal/server/rollback_cleanup_test.go | 9 +- internal/server/users_admin_handlers.go | 20 ++-- internal/users/role_rows_test.go | 53 +++++++++ internal/users/users.go | 128 +++++++++++++++------ specs/api/users.spec.yaml | 16 ++- specs/system/auth-identity.spec.yaml | 53 ++++++++- 13 files changed, 477 insertions(+), 61 deletions(-) create mode 100644 internal/server/committed_response_test.go create mode 100644 internal/server/role_lookup_test.go create mode 100644 internal/users/role_rows_test.go diff --git a/audit/events.yaml b/audit/events.yaml index 6e49043f..8016acf9 100644 --- a/audit/events.yaml +++ b/audit/events.yaml @@ -73,9 +73,9 @@ events: binders record the session, access-token and account-state reasons. SSO records the sso_ reasons, and sso_account_disabled or sso_account_deleted when the local account may not sign in; the - sign-in page stays generic. account_state_unavailable and - session_lookup_failed mean the server could not tell, and the - request answered 503, not 401. invalid_credentials, account_locked, + sign-in page stays generic. account_state_unavailable, + session_lookup_failed and role_lookup_unavailable mean the server + could not tell, and the request answered 503, not 401. invalid_credentials, account_locked, mfa_failed and sso_failed are legacy values that nothing records now; older rows may carry them. username is the submitted name, clipped. remote_addr and user_agent are recorded by the binders, @@ -95,6 +95,7 @@ events: session_lookup_failed, session_user_lookup_failed, invalid_api_token, invalid_jwt, jwt_expired, jwt_verify_failed, invalid_jwt_subject, invalid_jwt_session, + role_lookup_unavailable, sid_absent, session_absent, session_owner_mismatch, session_absolute_expired, session_binding_unknown, sso_login_init_failed, sso_idp_error, sso_state_expired, diff --git a/internal/audit/events.gen.go b/internal/audit/events.gen.go index 645ab286..76800e07 100644 --- a/internal/audit/events.gen.go +++ b/internal/audit/events.gen.go @@ -25,7 +25,7 @@ const ( const ( // User authenticated successfully AuthLoginSuccess Code = "auth.login.success" - // Authentication attempt failed, or a presented credential was refused. reason names why. Password login records wrong_password, unknown_user, account_disabled, mfa_required, mfa_invalid, mfa_required_during_login or password_changed_during_login. The binders record the session, access-token and account-state reasons. SSO records the sso_ reasons, and sso_account_disabled or sso_account_deleted when the local account may not sign in; the sign-in page stays generic. account_state_unavailable and session_lookup_failed mean the server could not tell, and the request answered 503, not 401. invalid_credentials, account_locked, mfa_failed and sso_failed are legacy values that nothing records now; older rows may carry them. username is the submitted name, clipped. remote_addr and user_agent are recorded by the binders, the user agent clipped. + // Authentication attempt failed, or a presented credential was refused. reason names why. Password login records wrong_password, unknown_user, account_disabled, mfa_required, mfa_invalid, mfa_required_during_login or password_changed_during_login. The binders record the session, access-token and account-state reasons. SSO records the sso_ reasons, and sso_account_disabled or sso_account_deleted when the local account may not sign in; the sign-in page stays generic. account_state_unavailable, session_lookup_failed and role_lookup_unavailable mean the server could not tell, and the request answered 503, not 401. invalid_credentials, account_locked, mfa_failed and sso_failed are legacy values that nothing records now; older rows may carry them. username is the submitted name, clipped. remote_addr and user_agent are recorded by the binders, the user agent clipped. AuthLoginFailure Code = "auth.login.failure" // User explicitly logged out. One login family is ended, located by the request's cookies. anchor names which cookie selected it. target_conflict is true when both cookies resolved to different families; only the session cookie's family was revoked. No credential values are recorded. AuthLogout Code = "auth.logout" @@ -350,7 +350,7 @@ var Metadata = map[Code]EventMeta{ Code: AuthLoginFailure, Category: "auth", Severity: SeverityWarning, - Description: `Authentication attempt failed, or a presented credential was refused. reason names why. Password login records wrong_password, unknown_user, account_disabled, mfa_required, mfa_invalid, mfa_required_during_login or password_changed_during_login. The binders record the session, access-token and account-state reasons. SSO records the sso_ reasons, and sso_account_disabled or sso_account_deleted when the local account may not sign in; the sign-in page stays generic. account_state_unavailable and session_lookup_failed mean the server could not tell, and the request answered 503, not 401. invalid_credentials, account_locked, mfa_failed and sso_failed are legacy values that nothing records now; older rows may carry them. username is the submitted name, clipped. remote_addr and user_agent are recorded by the binders, the user agent clipped.`, + Description: `Authentication attempt failed, or a presented credential was refused. reason names why. Password login records wrong_password, unknown_user, account_disabled, mfa_required, mfa_invalid, mfa_required_during_login or password_changed_during_login. The binders record the session, access-token and account-state reasons. SSO records the sso_ reasons, and sso_account_disabled or sso_account_deleted when the local account may not sign in; the sign-in page stays generic. account_state_unavailable, session_lookup_failed and role_lookup_unavailable mean the server could not tell, and the request answered 503, not 401. invalid_credentials, account_locked, mfa_failed and sso_failed are legacy values that nothing records now; older rows may carry them. username is the submitted name, clipped. remote_addr and user_agent are recorded by the binders, the user agent clipped.`, ActorTypes: []string{"user"}, DetailKeys: []string{"auth_method", "reason", "remote_addr", "user_agent", "username"}, }, diff --git a/internal/identity/account_state_test.go b/internal/identity/account_state_test.go index 9741f0ba..28ba54a2 100644 --- a/internal/identity/account_state_test.go +++ b/internal/identity/account_state_test.go @@ -77,7 +77,9 @@ func TestBinder_CookieArmEnforcesAccountState(t *testing.T) { http.StatusUnauthorized, "account_deleted", false}, {"active control", stubLookups{role: auth.RoleAdmin, status: AccountActive}, http.StatusOK, "", true}, - {"active with no roles", stubLookups{status: AccountActive, roleErr: errors.New("no roles")}, + // ErrNoRoles is the confirmed answer; any other lookup error is + // an unavailable lookup and answers 503 (C-45, AC-92). + {"active with no roles", stubLookups{status: AccountActive, roleErr: ErrNoRoles}, http.StatusUnauthorized, "session_user_lookup_failed", false}, } reasons := map[string]string{} diff --git a/internal/identity/binder.go b/internal/identity/binder.go index 1424668f..4312c2d7 100644 --- a/internal/identity/binder.go +++ b/internal/identity/binder.go @@ -202,10 +202,19 @@ const reasonStateUnavailable = "account_state_unavailable" // query could not be answered. Also 503, never 401. Spec C-32. const reasonSessionLookupFailed = "session_lookup_failed" +// reasonRoleLookupUnavailable is the cookie arm's role lookup failing to +// answer. Also 503, never 401. Spec C-45. +const reasonRoleLookupUnavailable = "role_lookup_unavailable" + +// ErrNoRoles is a role lookup's confirmed answer that the user holds no +// role. Any other lookup error means the answer is unknown. +var ErrNoRoles = errors.New("identity: user has no roles") + // unavailableReason reports whether a rejection reason means "could not // determine" rather than "refused", which is what separates 503 from 401. func unavailableReason(reason string) bool { - return reason == reasonStateUnavailable || reason == reasonSessionLookupFailed + return reason == reasonStateUnavailable || reason == reasonSessionLookupFailed || + reason == reasonRoleLookupUnavailable } // writeStateUnavailable emits the 503 envelope for an infrastructure @@ -320,8 +329,16 @@ func resolveIdentity(ctx context.Context, pool *pgxpool.Pool, lookups Lookups, c return anon(), reason } role, err := lookups.RoleForUser(ctx, sess.UserID) - if err != nil { + switch { + case errors.Is(err, ErrNoRoles): + // Confirmed: the user holds no role. A refused credential. return anon(), "session_user_lookup_failed" + case err != nil: + // The lookup did not answer, from a deadline or a database + // failure. That says nothing about the credential, so it is + // an infrastructure failure: 503, no handler, no cookie + // change, no refresh. Spec C-45. + return anon(), reasonRoleLookupUnavailable } return withGrants(ctx, lookups, auth.Identity{ ID: sess.UserID.String(), diff --git a/internal/identity/serialize.go b/internal/identity/serialize.go index 999f01be..4ce58b14 100644 --- a/internal/identity/serialize.go +++ b/internal/identity/serialize.go @@ -161,14 +161,21 @@ const RollbackCleanupLimit = 2 * time.Second // uncertain: cleanup after it proves nothing about the commit. When the // rollback fails, pgx discards the connection and the failure is logged. func RollbackDetached(ctx context.Context, tx pgx.Tx) { - rctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), RollbackCleanupLimit) - defer cancel() - if err := tx.Rollback(rctx); err != nil && !errors.Is(err, pgx.ErrTxClosed) { - slog.WarnContext(rctx, "identity: rollback did not complete; the connection is discarded", + if err := RollbackDetachedErr(ctx, tx); err != nil && !errors.Is(err, pgx.ErrTxClosed) { + slog.WarnContext(context.WithoutCancel(ctx), "identity: rollback did not complete; the connection is discarded", slog.String("error", err.Error())) } } +// RollbackDetachedErr is RollbackDetached returning the rollback's own +// error, so a test can see what the driver reported. Production callers +// use RollbackDetached, because the result must not change the outcome. +func RollbackDetachedErr(ctx context.Context, tx pgx.Tx) error { + rctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), RollbackCleanupLimit) + defer cancel() + return tx.Rollback(rctx) +} + // RunSerialized runs fn inside ONE transaction that holds the per-user // lock, and owns the whole lifecycle: begin, lock, fn, commit. // diff --git a/internal/server/committed_response_test.go b/internal/server/committed_response_test.go new file mode 100644 index 00000000..52267c2a --- /dev/null +++ b/internal/server/committed_response_test.go @@ -0,0 +1,111 @@ +// @spec api-users +// +// A committed disable or enable is reported as committed, even when the +// database cannot be read after the commit (C-08, AC-21). + +package server + +import ( + "context" + "net/http" + "testing" + + "github.com/Hanalyx/openwatch/internal/auth" + "github.com/Hanalyx/openwatch/internal/identity" + "github.com/jackc/pgx/v5" + "github.com/jackc/pgx/v5/pgxpool" +) + +// breakReadsAfterCommit commits for real, then renames the users table on +// another connection so any read of it after the commit fails. +type breakReadsAfterCommit struct { + inner identity.TxBeginner + pool *pgxpool.Pool + t *testing.T +} + +type breakReadsTx struct { + pgx.Tx + b *breakReadsAfterCommit +} + +func (b *breakReadsAfterCommit) Begin(ctx context.Context) (pgx.Tx, error) { + tx, err := b.inner.Begin(ctx) + if err != nil { + return nil, err + } + return &breakReadsTx{Tx: tx, b: b}, nil +} + +func (tx *breakReadsTx) Commit(ctx context.Context) error { + if err := tx.Tx.Commit(ctx); err != nil { + return err + } + if _, err := tx.b.pool.Exec(context.Background(), `ALTER TABLE users RENAME TO users_ac21`); err != nil { + tx.b.t.Errorf("break reads after the commit: %v", err) + } + return nil +} + +func restoreUsersTable(t *testing.T, pool *pgxpool.Pool) { + t.Helper() + var n int + _ = pool.QueryRow(context.Background(), `SELECT count(*) FROM pg_class WHERE relname = 'users_ac21'`).Scan(&n) + if n == 1 { + if _, err := pool.Exec(context.Background(), `ALTER TABLE users_ac21 RENAME TO users`); err != nil { + t.Fatalf("RESTORE users table: %v", err) + } + } +} + +// @ac AC-21 +// AC-21: a disable or enable that commits answers 200 with the committed +// state even when nothing can be read after the commit. It is never +// reported as not applied or not found, and nothing invites repeating it. +func TestAdminAccountChange_CommittedIsReportedAsCommitted(t *testing.T) { + t.Run("api-users/AC-21", func(t *testing.T) { + url, pool, srv := freshAPIServerWithHandles(t) + ctx := context.Background() + t.Cleanup(func() { restoreUsersTable(t, pool) }) + + for _, tc := range []struct { + name string + path string + disableFirst bool + wantDisabled bool + }{ + {"disable", ":disable", false, true}, + {"enable", ":enable", true, false}, + } { + tc := tc + t.Run(tc.name, func(t *testing.T) { + li := loginFresh(t, url, pool, "ac21"+tc.name) + if tc.disableFirst { + if _, err := srv.handlers.users.DisableUser(ctx, li.u.ID); err != nil { + t.Fatalf("disable: %v", err) + } + } + srv.handlers.users.UseTxSource(&breakReadsAfterCommit{inner: pool, pool: pool, t: t}) + got := doAPI(t, asRole(t, "POST", url+"/api/v1/users/"+li.u.ID.String()+tc.path, auth.RoleAdmin, nil)) + srv.handlers.users.UseTxSource(nil) + restoreUsersTable(t, pool) + + if got.status != http.StatusOK { + t.Fatalf("response = %d %q %q, want 200 for a committed change", got.status, got.code, got.message) + } + if got.retryable || got.code != "" { + t.Errorf("the response carries an error envelope (%q retryable=%v) for a committed change", got.code, got.retryable) + } + if disabledAt := got.body["disabled_at"]; (disabledAt != nil) != tc.wantDisabled { + t.Errorf("response disabled_at = %v, want set=%v", disabledAt, tc.wantDisabled) + } + if isDisabled(t, pool, li.u.ID) != tc.wantDisabled { + t.Errorf("durable disabled state = %v, want %v", !tc.wantDisabled, tc.wantDisabled) + } + if s, r := liveCounts(t, pool, li.u.ID); s != 0 || r != 0 { + t.Errorf("live credentials after the committed %s = %d/%d, want 0/0", tc.name, s, r) + } + }) + } + }) +} diff --git a/internal/server/role_lookup_test.go b/internal/server/role_lookup_test.go new file mode 100644 index 00000000..5ad6b163 --- /dev/null +++ b/internal/server/role_lookup_test.go @@ -0,0 +1,97 @@ +// @spec system-auth-identity +// +// The cookie binder's role lookup (C-45, AC-92): a confirmed "no roles" +// refuses the credential, and a lookup that fails is an infrastructure +// failure. + +package server + +import ( + "context" + "net/http" + "testing" + "time" +) + +// @ac AC-92 +// AC-92: a role lookup that fails answers 503, runs no handler and changes +// no cookie; a confirmed "no roles" still answers 401. +func TestCookieBinder_RoleLookupFailureIs503(t *testing.T) { + t.Run("system-auth-identity/AC-92", func(t *testing.T) { + url, pool, _ := freshAPIServerWithMaxConns(t, lockTestPoolSize) + ctx := context.Background() + + t.Run("lookup fails", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac92failing") + holder, err := pool.Begin(ctx) + if err != nil { + t.Fatalf("begin holder: %v", err) + } + defer func() { _ = holder.Rollback(ctx) }() + // Blocks every read of user_roles, so the binder's role query + // waits; the test then cancels that query, a real database + // failure on the lookup. + if _, err := holder.Exec(ctx, `LOCK TABLE user_roles IN ACCESS EXCLUSIVE MODE`); err != nil { + t.Fatalf("lock user_roles: %v", err) + } + type out struct { + got apiResult + cid string + } + done := make(chan out, 1) + go func() { + got, cid := cookieMe(t, url, li.sessionCookie, false) + done <- out{got, cid} + }() + var pid int32 + deadline := time.Now().Add(10 * time.Second) + for pid == 0 && time.Now().Before(deadline) { + _ = pool.QueryRow(ctx, ` + SELECT pid FROM pg_stat_activity + WHERE wait_event_type = 'Lock' AND query ILIKE '%FROM user_roles%' + AND pid <> pg_backend_pid() LIMIT 1`).Scan(&pid) + if pid == 0 { + time.Sleep(20 * time.Millisecond) + } + } + if pid == 0 { + t.Fatal("the role query never waited on user_roles") + } + if _, err := pool.Exec(ctx, `SELECT pg_cancel_backend($1)`, pid); err != nil { + t.Fatalf("cancel the role query: %v", err) + } + o := <-done + _ = holder.Rollback(ctx) + + if o.got.status != http.StatusServiceUnavailable || o.got.code != "server.error" { + t.Errorf("response = %d %q, want 503 server.error", o.got.status, o.got.code) + } + if o.got.handlerRan() { + t.Error("the protected handler ran") + } + if o.got.clearsCredential() || o.got.setsCredential() { + t.Error("the response changed a credential cookie") + } + if reason := loginFailureReasonFor(t, pool, o.cid); reason != "role_lookup_unavailable" { + t.Errorf("audit reason = %q, want role_lookup_unavailable", reason) + } + if code := authMe(t, url, li.sessionCookie); code != http.StatusOK { + t.Errorf("the session no longer works after the lookup recovered: %d", code) + } + }) + + t.Run("confirmed no roles", func(t *testing.T) { + li := loginFresh(t, url, pool, "ac92noroles") + if _, err := pool.Exec(ctx, `DELETE FROM user_roles WHERE user_id = $1`, li.u.ID); err != nil { + t.Fatalf("remove roles: %v", err) + } + got, cid := cookieMe(t, url, li.sessionCookie, false) + if got.status != http.StatusUnauthorized || got.handlerRan() { + t.Errorf("response = %d, want 401 without the handler running", got.status) + } + if reason := loginFailureReasonFor(t, pool, cid); reason != "session_user_lookup_failed" { + t.Errorf("audit reason = %q, want session_user_lookup_failed", reason) + } + }) + }) +} diff --git a/internal/server/rollback_cleanup_test.go b/internal/server/rollback_cleanup_test.go index 04bc8715..194b9d89 100644 --- a/internal/server/rollback_cleanup_test.go +++ b/internal/server/rollback_cleanup_test.go @@ -105,7 +105,14 @@ func TestRollbackCleanup_FailureAndClassification(t *testing.T) { } } conn := tx.Conn() - identity.RollbackDetached(ctx, tx) + rerr := identity.RollbackDetachedErr(ctx, tx) + var pgErr *pgerr.PgError + switch { + case terminate && !(errors.As(rerr, &pgErr) && pgErr.Code == "57P01"): + t.Errorf("rollback after termination returned %v, want SQLSTATE 57P01", rerr) + case !terminate && rerr != nil: + t.Errorf("control rollback returned %v, want nil", rerr) + } if closed := conn.IsClosed(); closed != terminate { t.Errorf("terminated=%v: connection closed = %v, want %v", terminate, closed, terminate) } diff --git a/internal/server/users_admin_handlers.go b/internal/server/users_admin_handlers.go index 04146149..6f6f706e 100644 --- a/internal/server/users_admin_handlers.go +++ b/internal/server/users_admin_handlers.go @@ -104,11 +104,15 @@ func (h *handlers) PostUserDisable(w http.ResponseWriter, r *http.Request, id op "you cannot disable your own account", false) return } - if err := h.users.Disable(r.Context(), uuid.UUID(id)); mapUserAdminErr(w, err) { + // The user comes back from the locked transaction, returned only after + // its commit is confirmed. No read follows the commit, so a committed + // disable cannot be reported as not applied or not found. api-users C-08. + u, err := h.users.DisableUser(r.Context(), uuid.UUID(id)) + if mapUserAdminErr(w, err) { return } emitAudit(r, audit.AdminUserDisabled, caller, map[string]any{"target_user_id": id.String()}) - h.writeUser(w, r, uuid.UUID(id)) + writeJSON(w, http.StatusOK, userResponse(u)) } // PostUserEnable implements api.ServerInterface. @@ -117,7 +121,7 @@ func (h *handlers) PostUserEnable(w http.ResponseWriter, r *http.Request, id ope if denied := auth.EnforcePermission(w, r, auth.AdminUserManage); denied { return } - transitioned, err := h.users.Enable(r.Context(), uuid.UUID(id)) + u, transitioned, err := h.users.EnableUser(r.Context(), uuid.UUID(id)) if mapUserAdminErr(w, err) { return } @@ -135,15 +139,5 @@ func (h *handlers) PostUserEnable(w http.ResponseWriter, r *http.Request, id ope "transition": transitioned, "revocation_scope": scope, }) - h.writeUser(w, r, uuid.UUID(id)) -} - -// writeUser re-reads the user and writes it as a 200 UserResponse. Used by -// disable/enable so the client gets the updated disabled_at without a refetch. -func (h *handlers) writeUser(w http.ResponseWriter, r *http.Request, id uuid.UUID) { - u, err := h.users.GetUserByID(r.Context(), id) - if mapUserAdminErr(w, err) { - return - } writeJSON(w, http.StatusOK, userResponse(u)) } diff --git a/internal/users/role_rows_test.go b/internal/users/role_rows_test.go new file mode 100644 index 00000000..e9692a03 --- /dev/null +++ b/internal/users/role_rows_test.go @@ -0,0 +1,53 @@ +// @spec system-auth-identity + +package users + +import ( + "context" + "errors" + "testing" + + "github.com/Hanalyx/openwatch/internal/identity" + "github.com/google/uuid" + "github.com/jackc/pgx/v5" +) + +// streamErrRows yields no row and then reports that the stream failed, +// as when the connection breaks part way through a result. +type streamErrRows struct { + pgx.Rows + err error +} + +func (r *streamErrRows) Next() bool { return false } +func (r *streamErrRows) Err() error { return r.err } +func (r *streamErrRows) Close() {} + +type streamErrQuerier struct{ err error } + +func (q streamErrQuerier) Query(context.Context, string, ...any) (pgx.Rows, error) { + return &streamErrRows{err: q.err}, nil +} + +// @ac AC-92 +// AC-92, at the role lookup: an error that ends the rows is a failed +// lookup, never an empty role list, so it cannot read as "no roles". +func TestRoleLookup_StreamErrorIsNotNoRoles(t *testing.T) { + t.Run("system-auth-identity/AC-92", func(t *testing.T) { + broken := errors.New("stream failed part way through") + s := &Service{roleRows: streamErrQuerier{err: broken}} + id := uuid.New() + + roles, err := s.RolesForUser(context.Background(), id) + if !errors.Is(err, broken) { + t.Errorf("RolesForUser = %v, %v; want the stream error", roles, err) + } + _, err = s.RoleForUser(context.Background(), id) + if errors.Is(err, identity.ErrNoRoles) { + t.Error("a failed stream was reported as the confirmed no-roles answer") + } + if err == nil { + t.Error("a failed stream produced a role") + } + }) +} diff --git a/internal/users/users.go b/internal/users/users.go index 01d4bfa2..93429100 100644 --- a/internal/users/users.go +++ b/internal/users/users.go @@ -25,9 +25,11 @@ import ( // Service errors. Returned from the CRUD + role-mgmt API. var ( - ErrUserNotFound = errors.New("users: not found") - ErrUnknownRole = errors.New("users: role does not exist") - ErrUserHasNoRoles = errors.New("users: user has no roles assigned") + ErrUserNotFound = errors.New("users: not found") + ErrUnknownRole = errors.New("users: role does not exist") + // ErrUserHasNoRoles is identity.ErrNoRoles, so the binder can tell a + // confirmed "no roles" from a lookup that failed. + ErrUserHasNoRoles = identity.ErrNoRoles // ErrUserDisabled is returned when an operation targets a disabled // account, or (for the login path) when a disabled user authenticates. ErrUserDisabled = errors.New("users: account is disabled") @@ -109,6 +111,14 @@ type Service struct { // account-state, reset and enable transactions. Production leaves it // nil; tests set it to select a commit outcome. txs identity.TxBeginner + // roleRows, when set, replaces the pool for the role lookup, so a + // test can end the rows with a stream error. Production leaves it nil. + roleRows rowsQuerier +} + +// rowsQuerier is the part of the pool the role lookup reads through. +type rowsQuerier interface { + Query(ctx context.Context, sql string, args ...any) (pgx.Rows, error) } // UseTxSource replaces the transaction source for the locked account @@ -235,14 +245,18 @@ func (s *Service) CreateFederatedUser(ctx context.Context, username, email strin // // Spec AC-04. func (s *Service) GetUserByID(ctx context.Context, id uuid.UUID) (User, error) { - const stmt = ` - SELECT id, username, email, last_password_change_at, created_at, updated_at, disabled_at, - full_name, display_name, job_title, timezone, phone - FROM users - WHERE id = $1 AND deleted_at IS NULL` - return s.queryOne(ctx, stmt, id) + return s.queryOne(ctx, userByIDStmt, id) } +// userByIDStmt reads an active user by id. It is shared by GetUserByID and +// the locked account transactions, which read the user they changed before +// committing so the response needs no read after the commit. +const userByIDStmt = ` + SELECT id, username, email, last_password_change_at, created_at, updated_at, disabled_at, + full_name, display_name, job_title, timezone, phone + FROM users + WHERE id = $1 AND deleted_at IS NULL` + // GetUserByUsername returns the user when active; ErrUserNotFound for // unknown or soft-deleted usernames. // @@ -402,7 +416,8 @@ func (s *Service) SoftDelete(ctx context.Context, id uuid.UUID) error { // The deletion and the revocation commit together. A deleted account // whose sessions outlive the delete is the defect this closes, and // two separate statements can leave exactly that state. Spec C-34, C-36. - return s.mutateAccountState(ctx, id, stmt) + _, err := s.mutateAccountState(ctx, id, stmt, false) + return err } // mutateAccountState runs an account-state UPDATE and the user-wide @@ -413,37 +428,49 @@ func (s *Service) SoftDelete(ctx context.Context, id uuid.UUID) error { // a refresh committing concurrently can insert a session after the // revocation ran and before the state change was visible, and that // session is never revoked by anything. Spec C-34, C-36. -func (s *Service) mutateAccountState(ctx context.Context, id uuid.UUID, stmt string) error { +// +// With readBack it also reads the changed user inside the transaction and +// returns it only once the commit is confirmed, so a caller that answers +// with the user needs no read after the commit. A read after the commit +// could fail on its own, and its failure would then be reported as if the +// committed change had not happened. api-users C-08. +func (s *Service) mutateAccountState(ctx context.Context, id uuid.UUID, stmt string, readBack bool) (User, error) { // Bounded as a whole, and never beyond an earlier caller deadline. // system-auth-identity C-43. ctx, cancel := identity.WithOperationDeadline(ctx) defer cancel() tx, err := s.lockedTx(ctx) if err != nil { - return fmt.Errorf("users: begin: %w", err) + return User{}, fmt.Errorf("users: begin: %w", err) } defer identity.RollbackDetached(ctx, tx) if err := identity.LockUser(ctx, tx, id); err != nil { if errors.Is(err, pgx.ErrNoRows) { - return ErrUserNotFound + return User{}, ErrUserNotFound } - return fmt.Errorf("users: lock: %w", err) + return User{}, fmt.Errorf("users: lock: %w", err) } tag, err := tx.Exec(ctx, stmt, id) if err != nil { - return fmt.Errorf("users: account state: %w", err) + return User{}, fmt.Errorf("users: account state: %w", err) } if tag.RowsAffected() == 0 { - return ErrUserNotFound + return User{}, ErrUserNotFound } if err := identity.RevokeUserCredentials(ctx, tx, id); err != nil { - return err + return User{}, err + } + var u User + if readBack { + if u, err = queryUser(ctx, tx, userByIDStmt, id); err != nil { + return User{}, fmt.Errorf("users: read back: %w", err) + } } if err := tx.Commit(ctx); err != nil { - return fmt.Errorf("users: commit: %w", identity.ClassifyCommitError(err)) + return User{}, fmt.Errorf("users: commit: %w", identity.ClassifyCommitError(err)) } - return nil + return u, nil } // AdminResetPassword sets a user's password on an administrator's authority: @@ -538,11 +565,19 @@ func writePasswordTx(ctx context.Context, db identity.DBTX, id uuid.UUID, hash s // // Spec api-users (disable/enable). func (s *Service) Disable(ctx context.Context, id uuid.UUID) error { + _, err := s.DisableUser(ctx, id) + return err +} + +// DisableUser is Disable returning the disabled user as the transaction +// read it, before its confirmed commit. The admin handler answers with +// it, so a committed disable is never reported through a later read. +func (s *Service) DisableUser(ctx context.Context, id uuid.UUID) (User, error) { const stmt = `UPDATE users SET disabled_at = now(), updated_at = now() WHERE id = $1 AND deleted_at IS NULL` // One transaction under the per-user lock: the disable and the // user-wide interactive revocation commit together. Spec C-34, C-36. - return s.mutateAccountState(ctx, id, stmt) + return s.mutateAccountState(ctx, id, stmt, true) } // Enable clears the disabled flag. A real disabled-to-enabled transition @@ -560,21 +595,28 @@ func (s *Service) Disable(ctx context.Context, id uuid.UUID) error { // // Spec api-users C-07, C-08; system-auth-identity C-34, C-36. func (s *Service) Enable(ctx context.Context, id uuid.UUID) (transitioned bool, err error) { + _, transitioned, err = s.EnableUser(ctx, id) + return transitioned, err +} + +// EnableUser is Enable returning the user as the locked transaction read +// it, before its confirmed commit, for the same reason as DisableUser. +func (s *Service) EnableUser(ctx context.Context, id uuid.UUID) (u User, transitioned bool, err error) { // Bounded as a whole, and never beyond an earlier caller deadline. // system-auth-identity C-43. ctx, cancel := identity.WithOperationDeadline(ctx) defer cancel() tx, err := s.lockedTx(ctx) if err != nil { - return false, fmt.Errorf("users: begin: %w", err) + return User{}, false, fmt.Errorf("users: begin: %w", err) } defer identity.RollbackDetached(ctx, tx) if err := identity.LockUser(ctx, tx, id); err != nil { if errors.Is(err, pgx.ErrNoRows) { - return false, ErrUserNotFound + return User{}, false, ErrUserNotFound } - return false, fmt.Errorf("users: lock: %w", err) + return User{}, false, fmt.Errorf("users: lock: %w", err) } // Read under the lock. The state decides whether this call is a // transition, and "already enabled" must stay distinguishable from @@ -583,27 +625,34 @@ func (s *Service) Enable(ctx context.Context, id uuid.UUID) (transitioned bool, if err := tx.QueryRow(ctx, `SELECT disabled_at IS NOT NULL, deleted_at IS NOT NULL FROM users WHERE id = $1`, id).Scan(&disabled, &deleted); err != nil { - return false, fmt.Errorf("users: enable: read state: %w", err) + return User{}, false, fmt.Errorf("users: enable: read state: %w", err) } if deleted { - return false, ErrUserNotFound + return User{}, false, ErrUserNotFound } if !disabled { - return false, nil + // Nothing to change. The user as read under the lock is the answer. + if u, err = queryUser(ctx, tx, userByIDStmt, id); err != nil { + return User{}, false, fmt.Errorf("users: enable: read back: %w", err) + } + return u, false, nil } if _, err := tx.Exec(ctx, `UPDATE users SET disabled_at = NULL, updated_at = now() WHERE id = $1`, id); err != nil { - return false, fmt.Errorf("users: enable: %w", err) + return User{}, false, fmt.Errorf("users: enable: %w", err) } // The transition and the revocation commit together, so the account // is never enabled with a stale credential still live. if err := identity.RevokeUserCredentials(ctx, tx, id); err != nil { - return false, fmt.Errorf("users: revoke credentials on enable: %w", err) + return User{}, false, fmt.Errorf("users: revoke credentials on enable: %w", err) + } + if u, err = queryUser(ctx, tx, userByIDStmt, id); err != nil { + return User{}, false, fmt.Errorf("users: enable: read back: %w", err) } if err := tx.Commit(ctx); err != nil { - return false, fmt.Errorf("users: commit: %w", identity.ClassifyCommitError(err)) + return User{}, false, fmt.Errorf("users: commit: %w", identity.ClassifyCommitError(err)) } - return true, nil + return u, true, nil } // AssignRole inserts a user_roles row. Role must exist; FK enforcement @@ -649,7 +698,11 @@ func (s *Service) RolesForUser(ctx context.Context, userID uuid.UUID) ([]auth.Ro FROM user_roles ur JOIN users u ON u.id = ur.user_id WHERE ur.user_id = $1 AND u.deleted_at IS NULL` - rows, err := s.pool.Query(ctx, stmt, userID) + var q rowsQuerier = s.pool + if s.roleRows != nil { + q = s.roleRows + } + rows, err := q.Query(ctx, stmt, userID) if err != nil { return nil, fmt.Errorf("users: list roles: %w", err) } @@ -662,6 +715,12 @@ func (s *Service) RolesForUser(ctx context.Context, userID uuid.UUID) ([]auth.Ro } out = append(out, auth.RoleID(rid)) } + // Without this, an error part way through the rows ends the loop + // silently and an unavailable lookup reads as "no roles", which the + // binder answers as a refused credential. system-auth-identity C-45. + if err := rows.Err(); err != nil { + return nil, fmt.Errorf("users: list roles: %w", err) + } return out, nil } @@ -712,8 +771,13 @@ func (s *Service) AccountStatusFor(ctx context.Context, userID uuid.UUID) (ident // queryOne is the GetByID/GetByUsername shared helper. func (s *Service) queryOne(ctx context.Context, stmt string, arg any) (User, error) { + return queryUser(ctx, s.pool, stmt, arg) +} + +// queryUser reads one user through q, a pool or a transaction. +func queryUser(ctx context.Context, q identity.DBTX, stmt string, arg any) (User, error) { var u User - err := s.pool.QueryRow(ctx, stmt, arg).Scan( + err := q.QueryRow(ctx, stmt, arg).Scan( &u.ID, &u.Username, &u.Email, &u.LastPasswordChangeAt, &u.CreatedAt, &u.UpdatedAt, &u.DisabledAt, &u.FullName, &u.DisplayName, &u.JobTitle, &u.Timezone, &u.Phone, diff --git a/specs/api/users.spec.yaml b/specs/api/users.spec.yaml index 368bce88..7488b375 100644 --- a/specs/api/users.spec.yaml +++ b/specs/api/users.spec.yaml @@ -86,7 +86,7 @@ spec: type: security enforcement: error - id: C-08 - description: 'Each admin user-management mutation MUST emit its audit code (admin.user.password_reset | admin.user.disabled | admin.user.enabled) carrying detail.target_user_id; an unknown or soft-deleted target MUST return 404 users.not_found. admin.user.enabled MUST also carry detail.transition (true only when the call changed the account from disabled to enabled) and detail.revocation_scope (interactive for a transition, none otherwise), both taken from the locked transaction that made the change, never inferred from a later read.' + description: 'Each admin user-management mutation MUST emit its audit code (admin.user.password_reset | admin.user.disabled | admin.user.enabled) carrying detail.target_user_id; an unknown or soft-deleted target MUST return 404 users.not_found. admin.user.enabled MUST also carry detail.transition (true only when the call changed the account from disabled to enabled) and detail.revocation_scope (interactive for a transition, none otherwise), both taken from the locked transaction that made the change, never inferred from a later read. The :disable and :enable responses carry the user as that transaction read it, returned only after its commit is confirmed; no read follows the commit, so a committed change is never reported as not applied or not found.' type: technical enforcement: error @@ -211,3 +211,17 @@ spec: transaction_effects: [] subsequent: ["The user's existing session still authenticates"] cookies_set: none + - id: AC-21 + description: 'A :disable or :enable that commits answers 200 with the committed state even when nothing can be read after the commit. It is never reported as not applied or not found, and the response invites no repeat.' + priority: critical + references_constraints: [C-07, C-08] + inputs: + initial_state: "A signed-in user; for :enable, disabled beforehand" + operation: "POST /users/{id}:disable or :enable as an administrator" + controlled_failure: "The transaction commits for real, then the users table is renamed, so any read after the commit fails" + expected_output: + response: {status: 200, error_envelope: false} + body: "disabled_at set for :disable, null for :enable" + transaction_effects: ["The durable disabled state matches the response", "The user's sessions and refresh tokens are revoked"] + cookies: "None set" + audit: "Not asserted" diff --git a/specs/system/auth-identity.spec.yaml b/specs/system/auth-identity.spec.yaml index 99055aa9..ecadbef7 100644 --- a/specs/system/auth-identity.spec.yaml +++ b/specs/system/auth-identity.spec.yaml @@ -438,6 +438,19 @@ spec: service apply it again only as a ceiling, which never extends it. type: security enforcement: error + - id: C-45 + description: > + The cookie binder MUST tell a confirmed "no roles" answer from a role + lookup that failed. Only identity.ErrNoRoles, returned when the + lookup read its rows to the end without error and found none, is a + refused credential (401, session_user_lookup_failed). Any other + lookup error, a deadline, a canceled query or an error that ends + the rows, is an infrastructure failure: 503 server.error, + role_lookup_unavailable, with no protected handler run, no cookie + changed and no refresh triggered. The role query MUST check the + rows' error before treating an empty result as authoritative. + type: security + enforcement: error - id: C-44 description: > Cookie-session verification MUST be bounded and MUST NOT @@ -2226,8 +2239,8 @@ spec: caller_value_present: true deadline: "Present, positive, at most RollbackCleanupLimit (2 s) away" Real driver failure: - terminated: "The rollback fails (SQLSTATE 57P01) and the connection is closed" - control: "The connection stays open" + terminated: "RollbackDetachedErr returns the driver's error, SQLSTATE 57P01, and the connection is closed" + control: "RollbackDetachedErr returns nil and the connection stays open" Pre-commit failure, cleanup fails: response: {status: 503, code: server.error, retryable: true} message_states: "did not complete in time" @@ -2240,3 +2253,39 @@ spec: cookies: "None set" audit: "Not asserted" timing: "Cleanup may add up to 2 s beyond the 15 s operation deadline" + + - id: AC-92 + description: > + A cookie request whose role lookup fails answers 503, runs no + handler and changes no cookie; a confirmed "no roles" still answers + 401; and an error that ends the role rows is a failed lookup, not + an empty role list. + priority: critical + references_constraints: [C-45] + inputs: + variants: + - name: "Lookup fails" + setup: > + A second connection holds ACCESS EXCLUSIVE on user_roles; the + binder's role query waits and is canceled with + pg_cancel_backend; GET /auth/me with the session cookie and its + own correlation id + - name: "Confirmed no roles" + setup: "The user's role rows are deleted; GET /auth/me with the session cookie" + - name: "Rows end with an error" + setup: "The role lookup reads rows that yield nothing and then report a stream error" + expected_output: + per_variant: + Lookup fails: + response: {status: 503, code: server.error} + handler_ran: false + cookies: "None set and none cleared" + audit: {action: auth.login.failure, reason: role_lookup_unavailable, read_by: "The request's correlation id"} + subsequent: ["The session authenticates once the lock is gone"] + Confirmed no roles: + response: {status: 401} + handler_ran: false + audit: {action: auth.login.failure, reason: session_user_lookup_failed} + Rows end with an error: + returns: "The stream error, not an empty role list and not ErrNoRoles" + transaction_effects: "None; a read-only lookup"