fix(audit): 审计按账号 id 归属并记录来源 IP/UA，登录失败与限速入审计和指标，写入失败计数告警

deploy/alerts/felis-alerts.yaml

@@ -6,7 +6,9 @@
 #   - felis-operator pod :8080/metrics      → felis_servers_total, felis_start_duration_seconds
 #   - felis-api internal :8081/metrics      → felis_image_build_failures_total,
 #                                             felis_mail_total, felis_rate_limited_total,
-#                                             felis_auth_otp_lockouts_total
+#                                             felis_auth_otp_lockouts_total,
+#                                             felis_auth_failures_total,
+#                                             felis_audit_write_failures_total
 #   - node-exporter textfile collector      → felis_db_backup_* (felis-db-backup.timer)
 # node_* / kube_* series come from node-exporter / kube-state-metrics.
 groups:
@@ -142,3 +144,25 @@ groups:
             The audit log names the account (action auth.otp.locked); the owner was
             mailed. Unless they fumbled codes, someone is guessing at it
             (troubleshooting §17).
+      - alert: FelisSignInFailures
+        expr: sum(increase(felis_auth_failures_total[15m])) > 30
+        for: 5m
+        labels:
+          severity: warning
+        annotations:
+          summary: "over 30 refused sign-ins in 15 minutes"
+          description: >-
+            Wrong codes, unknown addresses or bad passkey assertions well above people
+            mistyping: someone is guessing or enumerating. `sum by (door, reason)
+            (increase(felis_auth_failures_total[15m]))` shows where; the audit rows
+            (action auth.<door>.failed) carry each caller's client_ip (troubleshooting §17).
+      - alert: FelisAuditWriteFailing
+        expr: increase(felis_audit_write_failures_total[15m]) > 0
+        labels:
+          severity: warning
+        annotations:
+          summary: "felis-api failed to write audit rows"
+          description: >-
+            The actions went through but their audit rows were lost. The felis-api log
+            names each lost row (`audit: lost ...`); the usual cause is PostgreSQL
+            being unreachable or out of disk.

deploy/alerts/felis-alerts_test.yml

@@ -236,3 +236,58 @@ tests:
       - eval_time: 90m
         alertname: FelisOTPAccountLocked
         exp_alerts: []
+  - name: sign-in failure rate
+    interval: 1m
+    input_series:
+      # Two doors failing at 3/min between them from t=0.
+      - series: 'felis_auth_failures_total{door="login_email",reason="bad_code",job="felis-api"}'
+        values: '0+2x40'
+      - series: 'felis_auth_failures_total{door="op_login",reason="no_account",job="felis-api"}'
+        values: '0+1x40'
+    alert_rule_test:
+      - eval_time: 8m
+        alertname: FelisSignInFailures
+        exp_alerts: []
+      - eval_time: 25m
+        alertname: FelisSignInFailures
+        exp_alerts:
+          - exp_labels:
+              severity: warning
+            exp_annotations:
+              summary: "over 30 refused sign-ins in 15 minutes"
+              description: >-
+                Wrong codes, unknown addresses or bad passkey assertions well above people
+                mistyping: someone is guessing or enumerating. `sum by (door, reason)
+                (increase(felis_auth_failures_total[15m]))` shows where; the audit rows
+                (action auth.<door>.failed) carry each caller's client_ip (troubleshooting §17).
+  - name: people mistyping stays quiet
+    interval: 1m
+    input_series:
+      - series: 'felis_auth_failures_total{door="login_email",reason="bad_code",job="felis-api"}'
+        values: '0 0 1 1 2 2 3 3 4 4 5x30'
+    alert_rule_test:
+      - eval_time: 30m
+        alertname: FelisSignInFailures
+        exp_alerts: []
+  - name: audit rows lost
+    interval: 1m
+    input_series:
+      - series: 'felis_audit_write_failures_total{job="felis-api",instance="api-0"}'
+        values: '0 0 0 2x20'
+    alert_rule_test:
+      - eval_time: 2m
+        alertname: FelisAuditWriteFailing
+        exp_alerts: []
+      - eval_time: 5m
+        alertname: FelisAuditWriteFailing
+        exp_alerts:
+          - exp_labels:
+              severity: warning
+              job: felis-api
+              instance: api-0
+            exp_annotations:
+              summary: "felis-api failed to write audit rows"
+              description: >-
+                The actions went through but their audit rows were lost. The felis-api log
+                names each lost row (`audit: lost ...`); the usual cause is PostgreSQL
+                being unreachable or out of disk.

deploy/alerts/felis-prometheusrule.yaml

@@ -144,3 +144,25 @@ spec:
               The audit log names the account (action auth.otp.locked); the owner was
               mailed. Unless they fumbled codes, someone is guessing at it
               (troubleshooting §17).
+        - alert: FelisSignInFailures
+          expr: sum(increase(felis_auth_failures_total[15m])) > 30
+          for: 5m
+          labels:
+            severity: warning
+          annotations:
+            summary: "over 30 refused sign-ins in 15 minutes"
+            description: >-
+              Wrong codes, unknown addresses or bad passkey assertions well above people
+              mistyping: someone is guessing or enumerating. `sum by (door, reason)
+              (increase(felis_auth_failures_total[15m]))` shows where; the audit rows
+              (action auth.<door>.failed) carry each caller's client_ip (troubleshooting §17).
+        - alert: FelisAuditWriteFailing
+          expr: increase(felis_audit_write_failures_total[15m]) > 0
+          labels:
+            severity: warning
+          annotations:
+            summary: "felis-api failed to write audit rows"
+            description: >-
+              The actions went through but their audit rows were lost. The felis-api log
+              names each lost row (`audit: lost ...`); the usual cause is PostgreSQL
+              being unreachable or out of disk.

docs/troubleshooting.md

@@ -933,7 +933,9 @@ The series come from two processes:
 - `felis-api` internal face `:8081/metrics` (Service `felis-api-internal`) —
   `felis_image_build_failures_total`, and the sign-in series of §17
   (`felis_mail_total`, `felis_rate_limited_total`,
-  `felis_auth_otp_lockouts_total`). Unauthenticated like the probes;
+  `felis_auth_otp_lockouts_total`, `felis_auth_failures_total`,
+  `felis_sessions_revoked_total`, `felis_audit_write_failures_total`).
+  Unauthenticated like the probes;
   ClusterIP-only, and the external face never serves it.
 - `felis_reaper_worlds_deleted_total` is produced inside the one-shot reaper
   CronJob, which exits long before any scrape interval — without a pushgateway
@@ -945,8 +947,8 @@ The series come from two processes:
 `deploy/alerts/` ships ready-made rules: build failures, slow starts, node
 disk/memory thresholds, the kubelet `DiskPressure` condition, control-plane
 database backup freshness (§16; needs node-exporter's textfile collector), and
-sign-in abuse: the mail budget, relay failures, throttled floods and account
+sign-in abuse: the mail budget, relay failures, throttled floods, account
-code locks (§17).
+code locks and the refused sign-in rate, plus lost audit rows (§17).
 
 - Plain Prometheus: add `felis-alerts.yaml` to `rule_files`. Check and unit-test
   it standalone with `promtool check rules felis-alerts.yaml` and
@@ -1171,7 +1173,7 @@ Skips the pre-migration snapshot (`migrate up -no-backup`). The installer warns
 loudly when it is set. Use it only when the snapshot cannot work and you have
 another backup, e.g. an external database newer than the host's `pg_dump`.
 
-## 17. Sign-in refused with 429, mail budget, account code locks
+## 17. Sign-in refused with 429, mail budget, account code locks, failed sign-ins
 
 The public sign-in doors (`/api/v1/auth/*` except logout and the op-login
 status poll) have three limits of their own. Each answers 429 with a
@@ -1232,6 +1234,29 @@ sudo -u postgres psql felis -c \
   "DELETE FROM otp_failure_windows WHERE user_id = (SELECT id FROM users WHERE username = '<name>');"
 ```
 
+### Who tried: the audit trail
+
+Every refused sign-in writes an `auth.<door>.failed` row (payload `reason`:
+`bad_code`, `no_account`, `staff_account`, `not_staff`, `bad_assertion`, ...)
+and counts in `felis_auth_failures_total{door,reason}`; `FelisSignInFailures`
+fires above 30 in 15 minutes. The first refusal of each throttled burst writes
+`auth.rate_limited` with the source address. Rows carry `actor_user_id` (the
+account, the column to attribute by), `client_ip` (the same address the limit
+keys on) and `user_agent`. `actor` is display text: a verified email or the
+username, never an address the caller set without verifying.
+
+```sh
+sudo -u postgres psql felis -c "
+  SELECT created_at, action, actor, client_ip, payload->>'reason' AS reason
+  FROM audit_logs
+  WHERE action LIKE 'auth.%' AND created_at > now() - interval '1 hour'
+  ORDER BY created_at DESC LIMIT 50;"
+```
+
+A failed audit write does not fail the action; it logs `audit: lost ...` in
+`felis-api` and counts in `felis_audit_write_failures_total`
+(`FelisAuditWriteFailing`). The cause is almost always PostgreSQL (§16).
+
 ### Optional: a Cloudflare rate limiting rule in front
 
 The limits above live in the API, so they hold on any edge. Behind Cloudflare
@@ -1274,3 +1299,5 @@ for 10 seconds (the Free plan's limits).
 | Sign-in 429 `rate_limited` for everyone at once | §17 |
 | 429 `mail_rate_limited` / `FelisMailBudgetExhausted` | §17 |
 | Right code refused; `otp_account_locked` / `FelisOTPAccountLocked` | §17 |
+| `FelisSignInFailures` / who is guessing, from where | §17 |
+| `FelisAuditWriteFailing` | §17 |

internal/api/api_test.go

@@ -47,6 +47,7 @@ type fakeRepo struct {
 	serverResources map[string]ResourceSpec
 	resourceUpdates map[string]ResourceSpec
 	audits          []AuditEntry
+	failAudit       error // Audit fails with it (a store outage)
 	joins           []string
 	// create-server seeding (spec §15)
 	seeded  map[string]bool   // name -> servers row exists
@@ -745,6 +746,9 @@ func (f *fakeRepo) SeedServer(_ context.Context, name, subdomain string, _, _, _
 }
 func (f *fakeRepo) Ping(_ context.Context) error { return f.pingErr }
 func (f *fakeRepo) Audit(_ context.Context, e AuditEntry) error {
+	if f.failAudit != nil {
+		return f.failAudit
+	}
 	f.audits = append(f.audits, e)
 	return nil
 }
@@ -857,7 +861,8 @@ func (f *fakeRepo) SessionUser(_ context.Context, tokenHash string, now time.Tim
 				return nil, ErrNotFound
 			}
 			return &SessionedUser{
-				ID: u.ID, Email: u.Email, Role: u.Role,
+				ID: u.ID, Username: u.Username, Email: u.Email, Role: u.Role,
+				EmailVerified: u.EmailVerified,
 			}, nil
 		}
 	}

internal/api/audit.go

@@ -0,0 +1,172 @@
+package api
+
+import (
+	"cmp"
+	"context"
+	"encoding/json"
+	"errors"
+	"log"
+	"net/http"
+	"strings"
+	"time"
+	"unicode/utf8"
+
+	"felis.lolicon.best/internal/metrics"
+)
+
+// Audit rows (audit_logs, spec §6).
+//
+// Every row an HTTP request writes carries the acting account's id
+// (actor_user_id), the caller's address (the one the sign-in limit keys on) and
+// user agent; actor is display text. A failed write never fails the operation
+// it records, which already happened, but it is logged and counted
+// (felis_audit_write_failures_total, FelisAuditWriteFailing): a silent drop is
+// how a database blip erases the trail.
+
+const (
+	// auditWriteTimeout bounds one audit insert. The write outlives the caller's
+	// request context, so a client that hangs up right after the action cannot
+	// cancel its own audit row.
+	auditWriteTimeout = 5 * time.Second
+	// auditUserAgentMax bounds the stored user agent; the header is the caller's
+	// to write.
+	auditUserAgentMax = 256
+	// anonymousActor names a caller no account was resolved for.
+	anonymousActor = "anonymous"
+)
+
+// auditActor is the display name for a principal: an email only when something
+// vouches for it (an Access JWT, or a session whose address was verified), else
+// the username. A player can set their address to anyone's before verifying it,
+// so an unverified email would let them sign rows as that person.
+func auditActor(p *Principal) string {
+	switch {
+	case p == nil:
+		return anonymousActor
+	case p.Email != "" && (p.EmailVerified || !p.ViaSession):
+		return p.Email
+	case p.Username != "":
+		return p.Username
+	case p.UserID != "":
+		return p.UserID
+	}
+	return anonymousActor
+}
+
+// audit records an action by the signed-in caller. target is the object acted
+// on (a server name, a user or credential id) and lands in server_name.
+func (a *API) audit(r *http.Request, action, target string) {
+	p := principalFromContext(r.Context())
+	e := AuditEntry{Actor: auditActor(p), Action: action, ServerName: target}
+	if p != nil {
+		e.ActorUserID = p.UserID
+	}
+	a.auditEntry(r, e)
+}
+
+// auditAccount records an action a pre-session door took for the account it
+// resolved (u nil: none was). The username is the actor: the door has not yet
+// proven anything about the address.
+func (a *API) auditAccount(r *http.Request, u *StaffUser, action, target string) {
+	e := AuditEntry{Actor: anonymousActor, Action: action, ServerName: target}
+	if u != nil {
+		e.Actor, e.ActorUserID = u.Username, u.ID
+	}
+	a.auditEntry(r, e)
+}
+
+// auditEntry fills the request detail into e and writes it. Source defaults to
+// external; internal callers set it and the component actor themselves.
+func (a *API) auditEntry(r *http.Request, e AuditEntry) {
+	if e.Source == "" {
+		e.Source = "external"
+	}
+	e.RequestID = requestIDFromContext(r.Context())
+	if e.Source == "external" {
+		if ip := a.clientIP(r); ip.IsValid() {
+			e.ClientIP = ip.String()
+		}
+		e.UserAgent = truncateUTF8(r.UserAgent(), auditUserAgentMax)
+	}
+	a.writeAudit(r.Context(), e)
+}
+
+// writeAudit inserts e, logging and counting a failure.
+func (a *API) writeAudit(ctx context.Context, e AuditEntry) {
+	ctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), auditWriteTimeout)
+	defer cancel()
+	if err := a.Repo.Audit(ctx, e); err != nil {
+		metrics.AuditWriteFailuresTotal.Inc()
+		log.Printf("audit: lost %s by %s (user %q, request_id=%s): %v",
+			e.Action, e.Actor, e.ActorUserID, e.RequestID, err)
+	}
+}
+
+// authFailure records one refused sign-in attempt: felis_auth_failures_total
+// by door and reason, and an auth.<door>.failed row naming the account when
+// the door resolved one (u nil: the signed-in caller if any, else anonymous).
+// The doors keep their answers uniform so a prober learns nothing; the reason
+// is for the operator.
+func (a *API) authFailure(r *http.Request, door, reason string, u *StaffUser) {
+	metrics.AuthFailuresTotal.WithLabelValues(door, reason).Inc()
+	e := AuditEntry{Action: "auth." + door + ".failed", Payload: auditPayload(map[string]any{"reason": reason})}
+	switch p := principalFromContext(r.Context()); {
+	case u != nil:
+		e.Actor, e.ActorUserID = cmp.Or(u.Username, u.ID), u.ID
+	case p != nil:
+		e.Actor, e.ActorUserID = auditActor(p), p.UserID
+	default:
+		e.Actor = anonymousActor
+	}
+	a.auditEntry(r, e)
+}
+
+// passkeyCloneRejected records an assertion refused for a regressed signature
+// counter. It keeps its own action so a cloned authenticator stands out from
+// ordinary failures, and counts as a failure of its door. u nil: a signed-in
+// step-up, attributed to the caller.
+func (a *API) passkeyCloneRejected(r *http.Request, door string, u *StaffUser, credentialID string) {
+	metrics.AuthFailuresTotal.WithLabelValues(door, "clone_rejected").Inc()
+	if u == nil {
+		a.audit(r, "auth.passkey_clone_rejected", credentialID)
+		return
+	}
+	a.auditAccount(r, u, "auth.passkey_clone_rejected", credentialID)
+}
+
+// isOTPRefusal reports whether err is a refused code (wrong, spent, or the
+// account's budget locked), as opposed to a fault.
+func isOTPRefusal(err error) bool {
+	return errors.Is(err, ErrOTPInvalid) || errors.Is(err, ErrOTPLocked) || errors.Is(err, ErrOTPAccountLocked)
+}
+
+// otpFailureReason names a refused code for authFailure.
+func otpFailureReason(err error) string {
+	switch {
+	case errors.Is(err, ErrOTPAccountLocked):
+		return "account_locked"
+	case errors.Is(err, ErrOTPLocked):
+		return "code_locked"
+	}
+	return "bad_code"
+}
+
+// auditPayload marshals a small detail map for AuditEntry.Payload.
+func auditPayload(v map[string]any) []byte {
+	b, _ := json.Marshal(v)
+	return b
+}
+
+// truncateUTF8 makes s valid UTF-8 (a header may carry any byte, a text
+// column refuses invalid sequences) and cuts it to at most n bytes on a rune
+// boundary.
+func truncateUTF8(s string, n int) string {
+	s = strings.ToValidUTF8(s, "\uFFFD")
+	if len(s) <= n {
+		return s
+	}
+	for n > 0 && !utf8.RuneStart(s[n]) {
+		n--
+	}
+	return s[:n]
+}

internal/api/audit_test.go

@@ -0,0 +1,177 @@
+package api
+
+import (
+	"errors"
+	"net/http"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/prometheus/client_golang/prometheus/testutil"
+
+	"felis.lolicon.best/internal/metrics"
+)
+
+// Audit attribution: a row names the acting account by id and never by an
+// address the caller merely asserted; refused sign-ins, throttling and logouts
+// leave rows; a failed write is counted instead of vanishing.
+
+func TestAuditActorIgnoresUnverifiedEmail(t *testing.T) {
+	cases := []struct {
+		name string
+		p    *Principal
+		want string
+	}{
+		{"verified session email", &Principal{UserID: "u1", Username: "alice", Email: "[email protected]", EmailVerified: true, ViaSession: true}, "[email protected]"},
+		{"unverified session email", &Principal{UserID: "u2", Username: "mallory", Email: "[email protected]", ViaSession: true}, "mallory"},
+		{"access jwt email", &Principal{UserID: "sub", Email: "[email protected]"}, "[email protected]"},
+		{"no email", &Principal{UserID: "u3", Username: "bob", ViaSession: true}, "bob"},
+		{"id only", &Principal{UserID: "u4", ViaSession: true}, "u4"},
+		{"nobody", nil, anonymousActor},
+	}
+	for _, c := range cases {
+		if got := auditActor(c.p); got != c.want {
+			t.Errorf("%s: auditActor = %q, want %q", c.name, got, c.want)
+		}
+	}
+}
+
+// A player who sets their address to the owner's still signs every row as
+// themselves, by username and by id.
+func TestAuditCannotBeSignedWithAnotherPersonsEmail(t *testing.T) {
+	repo := newFakeRepo()
+	repo.settings[LocalAuthEnabledKey] = []byte("true")
+	repo.staff["owner"] = &StaffUser{ID: "u1", Username: "owner", Email: "[email protected]", Role: "owner", EmailVerified: true}
+	repo.staff["mallory"] = &StaffUser{ID: "u2", Username: "mallory", Email: "[email protected]", Role: "user", EmailVerified: true}
+	repo.sessions[hashCookie("tok")] = &fakeSession{userID: "u2", expiresAt: time.Unix(1_700_000_000, 0).Add(time.Hour)}
+	api := newTestAPI(repo, newFakeCluster())
+	api.External = SessionAuth{Repo: repo, RootDomain: testRoot, Now: api.now}
+	api.ClientIPHeader = "CF-Connecting-IP"
+	eh := api.ExternalHandler()
+	hdr := map[string]string{
+		"Content-Type": "application/json", "Cookie": sessionCookieName + "=tok",
+		"CF-Connecting-IP": "203.0.113.5", "User-Agent": "probe/1.0",
+	}
+	for _, email := range []string{"[email protected]", "[email protected]"} {
+		if w := do(eh, "POST", "/api/v1/account/email", `{"email":"`+email+`"}`, hdr); w.Code != http.StatusOK {
+			t.Fatalf("set email = %d (%s)", w.Code, w.Body.String())
+		}
+	}
+	// The first write ran while the address was still verified; the second
+	// ran with the owner's address set and unverified.
+	last := repo.audits[len(repo.audits)-1]
+	if last.Actor != "mallory" || last.ActorUserID != "u2" {
+		t.Fatalf("audit after spoofing = actor %q user %q, want mallory/u2", last.Actor, last.ActorUserID)
+	}
+	if last.ClientIP != "203.0.113.5" || last.UserAgent != "probe/1.0" || last.RequestID == "" {
+		t.Fatalf("audit request detail = %+v", last)
+	}
+}
+
+func TestSignInFailuresAreAuditedAndCounted(t *testing.T) {
+	api, repo, mailer := seedLoginEmailAPI(t)
+	eh := api.ExternalHandler()
+	noAccount := metrics.AuthFailuresTotal.WithLabelValues("login_email", "no_account")
+	badCode := metrics.AuthFailuresTotal.WithLabelValues("login_email", "bad_code")
+	n0, b0 := testutil.ToFloat64(noAccount), testutil.ToFloat64(badCode)
+
+	do(eh, "POST", "/api/v1/auth/email/verify", `{"email":"[email protected]","code":"123456"}`, jsonHeader)
+	if w := do(eh, "POST", "/api/v1/auth/email/start", `{"email":"[email protected]"}`, jsonHeader); w.Code != http.StatusAccepted {
+		t.Fatalf("start = %d", w.Code)
+	}
+	wrong := "000000"
+	if mailer.code == wrong {
+		wrong = "111111"
+	}
+	do(eh, "POST", "/api/v1/auth/email/verify", `{"email":"[email protected]","code":"`+wrong+`"}`, jsonHeader)
+
+	if got := testutil.ToFloat64(noAccount) - n0; got != 1 {
+		t.Errorf("no_account failures counted %v, want 1", got)
+	}
+	if got := testutil.ToFloat64(badCode) - b0; got != 1 {
+		t.Errorf("bad_code failures counted %v, want 1", got)
+	}
+	var failed []AuditEntry
+	for _, e := range repo.audits {
+		if e.Action == "auth.login_email.failed" {
+			failed = append(failed, e)
+		}
+	}
+	if len(failed) != 2 {
+		t.Fatalf("failure audits = %+v, want 2", failed)
+	}
+	if failed[0].Actor != anonymousActor || failed[0].ActorUserID != "" || !strings.Contains(string(failed[0].Payload), "no_account") {
+		t.Errorf("unknown-address failure = %+v", failed[0])
+	}
+	if failed[1].Actor != "player" || failed[1].ActorUserID != "u1" || !strings.Contains(string(failed[1].Payload), "bad_code") {
+		t.Errorf("wrong-code failure = %+v", failed[1])
+	}
+}
+
+func TestThrottleAuditsOncePerEpisode(t *testing.T) {
+	api, repo, _ := seedLoginEmailAPI(t)
+	api.AuthDoorLimit = RateLimit{Burst: 1, PerMinute: 1}
+	clock := time.Unix(1_700_000_000, 0)
+	api.Now = func() time.Time { return clock }
+	eh := api.ExternalHandler()
+	options := func() int {
+		return do(eh, "POST", "/api/v1/auth/options", `{"email":"[email protected]"}`, jsonHeader).Code
+	}
+	throttled := func() int {
+		n := 0
+		for _, e := range repo.audits {
+			if e.Action == "auth.rate_limited" {
+				n++
+			}
+		}
+		return n
+	}
+	options()
+	for i := 0; i < 5; i++ {
+		if c := options(); c != http.StatusTooManyRequests {
+			t.Fatalf("call %d = %d, want 429", i+2, c)
+		}
+	}
+	if n := throttled(); n != 1 {
+		t.Fatalf("5 refusals left %d audit rows, want 1", n)
+	}
+	clock = clock.Add(time.Minute)
+	options()
+	options()
+	if n := throttled(); n != 2 {
+		t.Fatalf("a second episode left %d rows in total, want 2", n)
+	}
+}
+
+func TestAuditWriteFailureIsCountedNotFatal(t *testing.T) {
+	api, repo, _ := seedLoginEmailAPI(t)
+	repo.failAudit = errors.New("db down")
+	before := testutil.ToFloat64(metrics.AuditWriteFailuresTotal)
+	if w := do(api.ExternalHandler(), "POST", "/api/v1/auth/email/start", `{"email":"[email protected]"}`, jsonHeader); w.Code != http.StatusAccepted {
+		t.Fatalf("start with the audit store down = %d, want 202", w.Code)
+	}
+	if got := testutil.ToFloat64(metrics.AuditWriteFailuresTotal) - before; got != 1 {
+		t.Fatalf("audit write failures counted %v, want 1", got)
+	}
+}
+
+func TestLogoutAuditsTheLiveSession(t *testing.T) {
+	api, repo, _ := seedLoginEmailAPI(t)
+	repo.sessions[hashCookie("tok")] = &fakeSession{userID: "u1", expiresAt: time.Unix(1_700_000_000, 0).Add(time.Hour)}
+	eh := api.ExternalHandler()
+	cookie := map[string]string{"Content-Type": "application/json", "Cookie": sessionCookieName + "=tok"}
+	do(eh, "POST", "/api/v1/auth/logout", "", cookie)
+	do(eh, "POST", "/api/v1/auth/logout", "", cookie) // already revoked: no second row
+	if len(repo.audits) != 1 || repo.audits[0].Action != "auth.logout" || repo.audits[0].ActorUserID != "u1" || repo.audits[0].Actor != "player" {
+		t.Fatalf("logout audits = %+v, want one auth.logout by player/u1", repo.audits)
+	}
+}
+
+func TestTruncateUTF8KeepsRunesWhole(t *testing.T) {
+	if got := truncateUTF8("ab\xffc", 10); got != "ab�c" {
+		t.Errorf("invalid byte = %q", got)
+	}
+	if got := truncateUTF8("猫猫", 4); got != "猫" {
+		t.Errorf("cut mid-rune = %q, want 猫", got)
+	}
+}

internal/api/auth.go

@@ -15,7 +15,10 @@ import (
 type Principal struct {
 	// UserID is the stable web identity (SSO subject → users.id).
 	UserID string
-	// Email is the audited actor identity (spec §14: audit actor = Access email).
+	// Username is the account's login name; empty for an Access-JWT caller.
+	Username string
+	// Email is the account's address. Only an Access JWT or EmailVerified vouches
+	// for it: a player can set any address before verifying it (auditActor).
 	Email string
 	// Role is "owner", "admin", or "user" (mirrors users.role).
 	Role string

internal/api/handlers_access.go

@@ -159,7 +159,7 @@ func (a *API) handleAccessWhitelist(w http.ResponseWriter, r *http.Request) {
 	if !ok {
 		return
 	}
-	a.audit(r, principalFromContext(r.Context()).Email, "access.whitelist."+body.Action, name)
+	a.audit(r, "access.whitelist."+body.Action, name)
 	writeJSON(w, http.StatusOK, map[string]any{
 		"name": name, "action": body.Action, "player": body.Player, "output": out,
 	})
@@ -249,7 +249,7 @@ func (a *API) handleAccessBan(w http.ResponseWriter, r *http.Request) {
 	if !ok {
 		return
 	}
-	a.audit(r, principalFromContext(r.Context()).Email, "access.ban."+body.Action, name)
+	a.audit(r, "access.ban."+body.Action, name)
 	writeJSON(w, http.StatusOK, map[string]any{
 		"name": name, "action": body.Action, "player": body.Player, "output": out,
 	})
@@ -282,7 +282,7 @@ func (a *API) handleAccessKick(w http.ResponseWriter, r *http.Request) {
 	if !ok {
 		return
 	}
-	a.audit(r, principalFromContext(r.Context()).Email, "access.kick", name)
+	a.audit(r, "access.kick", name)
 	writeJSON(w, http.StatusOK, map[string]any{
 		"name": name, "player": body.Player, "output": out,
 	})
@@ -354,7 +354,7 @@ func (a *API) handleAccessPermission(w http.ResponseWriter, r *http.Request) {
 	if !ok {
 		return
 	}
-	a.audit(r, principalFromContext(r.Context()).Email, "access.permission."+body.Action, name)
+	a.audit(r, "access.permission."+body.Action, name)
 	writeJSON(w, http.StatusOK, map[string]any{
 		"name": name, "action": body.Action, "player": body.Player,
 		"node": body.Node, "output": out,
@@ -397,7 +397,7 @@ func (a *API) handleAccessGroup(w http.ResponseWriter, r *http.Request) {
 	if !ok {
 		return
 	}
-	a.audit(r, principalFromContext(r.Context()).Email, "access.group."+body.Action, name)
+	a.audit(r, "access.group."+body.Action, name)
 	writeJSON(w, http.StatusOK, map[string]any{
 		"name": name, "action": body.Action, "player": body.Player, "group": body.Group, "output": out,
 	})

internal/api/handlers_account.go

@@ -229,7 +229,7 @@ func (a *API) handleLinkVerify(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "account.link", "")
+	a.audit(r, "account.link", "")
 	writeJSON(w, http.StatusOK, map[string]any{
 		"linked": true, "mc_uuid": mcUUID, "auth_source": authSource,
 	})

internal/api/handlers_account_migrate.go

@@ -114,11 +114,10 @@ func (a *API) handleMigrateStart(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	// Internal-face event: attribute to the in-game initiator, Source 'internal'.
-	_ = a.Repo.Audit(r.Context(), AuditEntry{
+	a.auditEntry(r, AuditEntry{
-		Actor:     "mc:" + mcUUID,
+		Actor:  "mc:" + mcUUID,
-		Source:    "internal",
+		Source: "internal",
-		Action:    "account.migrate.start",
+		Action: "account.migrate.start",
-		RequestID: requestIDFromContext(r.Context()),
 	})
 	writeJSON(w, http.StatusCreated, map[string]any{"started": true, "state": "initiated"})
 }
@@ -247,7 +246,7 @@ func (a *API) handleMigrateConfirmOTPStart(w http.ResponseWriter, r *http.Reques
 		return
 	}
 	committed = true
-	a.audit(r, auditActor(p), "account.migrate.confirm_otp_sent", "")
+	a.audit(r, "account.migrate.confirm_otp_sent", "")
 	writeJSON(w, http.StatusAccepted, map[string]any{"sent": true, "expires_at": expiresAt.UTC()})
 }
 
@@ -275,7 +274,11 @@ func (a *API) handleMigrateConfirmOTPVerify(w http.ResponseWriter, r *http.Reque
 		return
 	}
 	var lock *OTPAccountLockedError
-	switch err := a.Repo.ConsumeLoginEmailOTP(r.Context(), p.UserID, otpPurposeMigrate, otpCodeHash(code), a.now()); {
+	err := a.Repo.ConsumeLoginEmailOTP(r.Context(), p.UserID, otpPurposeMigrate, otpCodeHash(code), a.now())
+	if isOTPRefusal(err) {
+		a.authFailure(r, "migrate_confirm", otpFailureReason(err), nil)
+	}
+	switch {
 	case errors.As(err, &lock):
 		a.noteOTPLock(r, err, p.UserID, otpPurposeMigrate)
 		writeOTPAccountLocked(w, r, lock.Until, a.now())
@@ -300,7 +303,7 @@ func (a *API) handleMigrateConfirmOTPVerify(w http.ResponseWriter, r *http.Reque
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, auditActor(p), "account.migrate.confirmed", "")
+	a.audit(r, "account.migrate.confirmed", "")
 	writeJSON(w, http.StatusOK, map[string]any{"confirmed": true})
 }
 
@@ -387,6 +390,7 @@ func (a *API) handleMigrateConfirmPasskeyFinish(w http.ResponseWriter, r *http.R
 	sessionData, err := a.Repo.ConsumePasskeyChallengeByUser(r.Context(), p.UserID, passkeyPurposeMigrate, a.now())
 	if err != nil {
 		if errors.Is(err, ErrPasskeyChallengeInvalid) {
+			a.authFailure(r, "migrate_passkey", "challenge_invalid", nil)
 			writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 				"passkey confirmation could not be completed; begin again"))
 			return
@@ -401,6 +405,7 @@ func (a *API) handleMigrateConfirmPasskeyFinish(w http.ResponseWriter, r *http.R
 	}
 	va, err := a.Passkey.FinishLogin(migratePasskeyUser(p, creds), sessionData, bytes.NewReader(req.Assertion))
 	if err != nil {
+		a.authFailure(r, "migrate_passkey", "bad_assertion", nil)
 		writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 			"passkey confirmation could not be completed; begin again"))
 		return
@@ -412,7 +417,7 @@ func (a *API) handleMigrateConfirmPasskeyFinish(w http.ResponseWriter, r *http.R
 	// next login.
 	if err := a.applyAssertionCounter(r.Context(), va); err != nil {
 		if errors.Is(err, errPasskeyClonedAuthenticator) {
-			a.audit(r, auditActor(p), "auth.passkey_clone_rejected", va.CredentialID)
+			a.passkeyCloneRejected(r, "migrate_passkey", nil, va.CredentialID)
 			writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 				"passkey confirmation could not be completed; begin again"))
 			return
@@ -429,7 +434,7 @@ func (a *API) handleMigrateConfirmPasskeyFinish(w http.ResponseWriter, r *http.R
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, auditActor(p), "account.migrate.confirmed", "")
+	a.audit(r, "account.migrate.confirmed", "")
 	writeJSON(w, http.StatusOK, map[string]any{"confirmed": true})
 }
 
@@ -506,7 +511,7 @@ func (a *API) handleMigrateIssueCode(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, auditActor(p), "account.migrate.code_issued", targetID)
+	a.audit(r, "account.migrate.code_issued", targetID)
 	writeJSON(w, http.StatusCreated, map[string]any{"code": code, "expires_at": expiresAt.UTC()})
 }
 
@@ -544,7 +549,7 @@ func (a *API) handleMigrateRedeem(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, auditActor(p), "account.migrate.redeemed", sourceUserID)
+	a.audit(r, "account.migrate.redeemed", sourceUserID)
 	writeJSON(w, http.StatusOK, map[string]any{
 		"migrated":      true,
 		"servers_moved": len(moved),

internal/api/handlers_auth.go

@@ -1,6 +1,10 @@
 package api
 
-import "net/http"
+import (
+	"net/http"
+
+	"felis.lolicon.best/internal/metrics"
+)
 
 // Passwordless auth handlers (spec §B). Staff (Owner/Operator) authenticate via
 // email-OTP / passkey + in-game approve on op.console; players via bind code or
@@ -10,10 +14,16 @@ import "net/http"
 
 // handleLogout revokes the presented session and clears the cookie (spec §B). It
 // is mounted Public and idempotent: it reads the cookie directly, so it works even
-// when the session has already expired and never errors on a missing one.
+// when the session has already expired and never errors on a missing one. Ending
+// a live session is audited under its account; a dead cookie leaves no row.
 func (a *API) handleLogout(w http.ResponseWriter, r *http.Request) {
 	if c, err := r.Cookie(sessionCookieName); err == nil && c.Value != "" {
-		_ = a.Repo.RevokeSession(r.Context(), hashCookie(c.Value))
+		hash := hashCookie(c.Value)
+		u, uerr := a.Repo.SessionUser(r.Context(), hash, a.now())
+		if err := a.Repo.RevokeSession(r.Context(), hash); err == nil && uerr == nil {
+			metrics.SessionsRevokedTotal.WithLabelValues("logout").Inc()
+			a.auditEntry(r, AuditEntry{Actor: u.Username, ActorUserID: u.ID, Action: "auth.logout"})
+		}
 	}
 	clearSessionCookie(w)
 	writeJSON(w, http.StatusOK, map[string]any{"ok": true})

internal/api/handlers_auth_email.go

@@ -167,7 +167,7 @@ func (a *API) handleLoginEmailStart(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	committed = true
-	a.audit(r, u.Username, "auth.login_email.otp_sent", "")
+	a.auditAccount(r, u, "auth.login_email.otp_sent", "")
 	writeJSON(w, http.StatusAccepted, map[string]any{"sent": true, "expires_at": expiresAt.UTC()})
 }
 
@@ -219,6 +219,7 @@ func (a *API) handleLoginEmailVerify(w http.ResponseWriter, r *http.Request) {
 		// Uniform with a wrong code: a caller probing whether an address has an account
 		// gets the same invalid_code either way. (The /auth/options oracle is the
 		// sanctioned place to learn existence; this door does not double as one.)
+		a.authFailure(r, "login_email", "no_account", nil)
 		writeError(w, r, newError(http.StatusBadRequest, "invalid_code", "email code is invalid or expired"))
 		return
 	case err != nil:
@@ -240,6 +241,7 @@ func (a *API) handleLoginEmailVerify(w http.ResponseWriter, r *http.Request) {
 	case errors.Is(err, ErrOTPInvalid), errors.Is(err, ErrOTPLocked), errors.Is(err, ErrOTPAccountLocked):
 		// The account lock answers the same way; its owner hears about it by mail.
 		a.noteOTPLock(r, err, u.ID, otpPurposeLogin)
+		a.authFailure(r, "login_email", otpFailureReason(err), u)
 		// Both a wrong/expired code and an attempt-exhausted one return the SAME 400
 		// invalid_code, byte-identical to the unknown-account branch above. Surfacing
 		// otp_locked as a distinct 429 (as the authenticated onboarding door does) would
@@ -263,6 +265,7 @@ func (a *API) handleLoginEmailVerify(w http.ResponseWriter, r *http.Request) {
 	// Staff means anything above role=user: an admin OR the role=owner identity. The
 	// player door must yield only player sessions.
 	if u.Role != "user" {
+		a.authFailure(r, "login_email", "staff_account", u)
 		writeError(w, r, newError(http.StatusForbidden, "staff_account",
 			"that account is staff; sign in at the operator console"))
 		return
@@ -279,7 +282,7 @@ func (a *API) handleLoginEmailVerify(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	setSessionCookie(w, token, expires)
-	a.audit(r, u.Username, "auth.login_email", "")
+	a.auditAccount(r, u, "auth.login_email", "")
 	writeJSON(w, http.StatusOK, map[string]any{
 		"user_id": u.ID,
 		"role":    u.Role,

internal/api/handlers_backups.go

@@ -208,7 +208,7 @@ func (a *API) handleRestoreBackup(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "backup.restore", name)
+	a.audit(r, "backup.restore", name)
 	writeJSON(w, http.StatusAccepted, map[string]any{
 		"name":      name,
 		"status":    "restoring",
@@ -256,7 +256,7 @@ func (a *API) handleBackupNow(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.enqueueBackup(w, r, name, rec, p.Email, "external")
+	a.enqueueBackup(w, r, name, rec, auditActor(p), "external")
 }
 
 // handleInternalBackup is the internal-face backup trigger. The break-glass console
@@ -360,10 +360,11 @@ func (a *API) enqueueBackup(w http.ResponseWriter, r *http.Request, name string,
 		return
 	}
 
-	_ = a.Repo.Audit(r.Context(), AuditEntry{
+	e := AuditEntry{Actor: actor, Source: source, Action: "backup.create", ServerName: name}
-		Actor: actor, Source: source, Action: "backup.create",
+	if p := principalFromContext(r.Context()); p != nil {
-		ServerName: name, RequestID: requestIDFromContext(r.Context()),
+		e.ActorUserID = p.UserID
-	})
+	}
+	a.auditEntry(r, e)
 	writeJSON(w, http.StatusAccepted, map[string]any{
 		"name":   name,
 		"status": "backing_up",

internal/api/handlers_console.go

@@ -117,6 +117,6 @@ func (a *API) handleCommand(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "console.command", name)
+	a.audit(r, "console.command", name)
 	writeJSON(w, http.StatusOK, map[string]any{"name": name, "output": output})
 }

internal/api/handlers_email_otp.go

@@ -192,7 +192,7 @@ func (a *API) handleEmailOTPStart(w http.ResponseWriter, r *http.Request) {
 	// The send succeeded: keep both reservations (the deferred rollback becomes a
 	// no-op) so the cooldown windows stand.
 	committed = true
-	a.audit(r, auditActor(p), "account.email.otp_sent", "")
+	a.audit(r, "account.email.otp_sent", "")
 	writeJSON(w, http.StatusAccepted, map[string]any{
 		"sent":       true,
 		"expires_at": expiresAt.UTC(),
@@ -224,6 +224,9 @@ func (a *API) handleEmailOTPVerify(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	email, err := a.Repo.VerifyEmailOTP(r.Context(), p.UserID, otpPurposeOnboard, otpCodeHash(code), a.now())
+	if isOTPRefusal(err) {
+		a.authFailure(r, "onboard_email", otpFailureReason(err), nil)
+	}
 	var lock *OTPAccountLockedError
 	switch {
 	case errors.As(err, &lock):
@@ -245,7 +248,7 @@ func (a *API) handleEmailOTPVerify(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, auditActor(p), "account.email.verified", "")
+	a.audit(r, "account.email.verified", "")
 	writeJSON(w, http.StatusOK, map[string]any{"verified": true, "email": email})
 }
 
@@ -316,16 +319,6 @@ func (a *API) handleSetEmail(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, auditActor(p), "account.email.set", "")
+	a.audit(r, "account.email.set", "")
 	writeJSON(w, http.StatusOK, map[string]any{"email": email})
 }
-
-// auditActor picks the most identifying actor string for a principal: the audited
-// Access email when present, else the stable user id. A player mid-onboarding may
-// not have a verified email yet, so the id keeps the audit row attributable.
-func auditActor(p *Principal) string {
-	if p.Email != "" {
-		return p.Email
-	}
-	return p.UserID
-}

internal/api/handlers_files.go

@@ -164,8 +164,7 @@ func (a *API) handleWriteFile(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	p := principalFromContext(r.Context())
+	a.audit(r, "file.write", name+":"+path)
-	a.audit(r, p.Email, "file.write", name+":"+path)
 	writeJSON(w, http.StatusOK, map[string]any{"path": path, "status": "written"})
 }
 

internal/api/handlers_internal.go

@@ -51,9 +51,8 @@ func (a *API) handleReady(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, newError(http.StatusBadRequest, "bad_name", "invalid server name: %v", err))
 		return
 	}
-	_ = a.Repo.Audit(r.Context(), AuditEntry{
+	a.auditEntry(r, AuditEntry{
 		Actor: "backend", Source: "internal", Action: "ready", ServerName: name,
-		RequestID: requestIDFromContext(r.Context()),
 	})
 	w.WriteHeader(http.StatusNoContent)
 }
@@ -163,9 +162,8 @@ func (a *API) handleInternalWake(w http.ResponseWriter, r *http.Request) {
 	// the cap held with 503 (or a SetDesiredState error) leaves the cooldown
 	// untouched and the next join attempt is not also throttled.
 	a.limiter().record(name)
-	_ = a.Repo.Audit(r.Context(), AuditEntry{
+	a.auditEntry(r, AuditEntry{
 		Actor: "velocity", Source: "internal", Action: "wake", ServerName: name,
-		RequestID: requestIDFromContext(r.Context()),
 	})
 	writeJSON(w, http.StatusAccepted, map[string]any{
 		"name": name, "desiredState": "Running",
@@ -256,9 +254,8 @@ func (a *API) handleInternalClaim(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	_ = a.Repo.Audit(r.Context(), AuditEntry{
+	a.auditEntry(r, AuditEntry{
 		Actor: "velocity", Source: "internal", Action: "claim", ServerName: name,
-		RequestID: requestIDFromContext(r.Context()),
 	})
 	writeJSON(w, http.StatusOK, map[string]any{"name": name, "claimed": true})
 }

internal/api/handlers_logstream.go

@@ -98,6 +98,6 @@ func (a *API) handleServerConsole(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "console.attach", name)
+	a.audit(r, "console.attach", name)
 	relayLogStream(w, r, src)
 }

internal/api/handlers_onboard.go

@@ -103,13 +103,16 @@ func (a *API) handleBindRedeem(w http.ResponseWriter, r *http.Request) {
 	userID, mcUUID, authSource, err := a.Repo.RedeemPlayerBindCode(r.Context(), uid, code, a.now())
 	switch {
 	case errors.Is(err, ErrLinkCodeInvalid):
+		a.authFailure(r, "bind_redeem", "bad_code", nil)
 		writeError(w, r, newError(http.StatusBadRequest, "invalid_code", "bind code is invalid or expired"))
 		return
 	case errors.Is(err, ErrPlayerBindForbidden):
+		a.authFailure(r, "bind_redeem", "staff_account", nil)
 		writeError(w, r, newError(http.StatusForbidden, "staff_account",
 			"that Minecraft account belongs to staff; sign in at the operator console"))
 		return
 	case errors.Is(err, ErrPlayerAccountRetired):
+		a.authFailure(r, "bind_redeem", "account_retired", nil)
 		// The linked Felis account is disabled or soft-deleted: the door refuses to
 		// reuse it, because minting a session here would resurrect the account the
 		// owner just retired (audit #33). The code survives, so re-enabling the
@@ -133,7 +136,8 @@ func (a *API) handleBindRedeem(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	setSessionCookie(w, token, expires)
-	a.audit(r, userID, "account.bind_redeem", "")
+	// The in-game code proved the Minecraft account; it names the actor.
+	a.auditEntry(r, AuditEntry{Actor: "mc:" + mcUUID, ActorUserID: userID, Action: "account.bind_redeem"})
 	writeJSON(w, http.StatusOK, map[string]any{
 		"user_id": userID, "linked": true, "mc_uuid": mcUUID, "auth_source": authSource,
 	})

internal/api/handlers_op_login.go

@@ -136,6 +136,7 @@ func (a *API) handleOpLoginStart(w http.ResponseWriter, r *http.Request) {
 	u, err := a.Repo.UserByEmail(r.Context(), email)
 	switch {
 	case errors.Is(err, ErrNotFound):
+		a.authFailure(r, "op_login", "no_account", nil)
 		neutral()
 		return
 	case err != nil:
@@ -148,6 +149,7 @@ func (a *API) handleOpLoginStart(w http.ResponseWriter, r *http.Request) {
 	// on console.<root_domain>) gets the neutral response, never a request or a code.
 	// Staff means admin OR owner — the Owner is the primary op.console user.
 	if !staffRole(u.Role) {
+		a.authFailure(r, "op_login", "not_staff", u)
 		neutral()
 		return
 	}
@@ -191,7 +193,7 @@ func (a *API) handleOpLoginStart(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	committed = true
-	a.audit(r, u.Username, "auth.op_login.otp_sent", "")
+	a.auditAccount(r, u, "auth.op_login.otp_sent", "")
 	writeJSON(w, http.StatusAccepted, map[string]any{
 		"request_id": id, "expires_at": expiresAt.UTC(),
 	})
@@ -271,6 +273,7 @@ func (a *API) handleOpLoginFinish(w http.ResponseWriter, r *http.Request) {
 	loginReq, err := a.Repo.OpLoginRequestByID(r.Context(), requestID)
 	switch {
 	case errors.Is(err, ErrNotFound):
+		a.authFailure(r, "op_login", "unknown_request", nil)
 		writeError(w, r, invalid)
 		return
 	case err != nil:
@@ -281,6 +284,7 @@ func (a *API) handleOpLoginFinish(w http.ResponseWriter, r *http.Request) {
 	// code before an admin approved) must not consume the code. Not-approved collapses
 	// into the same uniform failure as a bad code, so the ordering leaks nothing.
 	if loginReq.Status != "approved" || loginReq.Consumed || !loginReq.ExpiresAt.After(now) {
+		a.authFailure(r, "op_login", "not_approved", a.opLoginAccount(r, loginReq.UserID))
 		writeError(w, r, invalid)
 		return
 	}
@@ -290,6 +294,7 @@ func (a *API) handleOpLoginFinish(w http.ResponseWriter, r *http.Request) {
 	switch err := a.Repo.ConsumeLoginEmailOTP(r.Context(), loginReq.UserID, otpPurposeOpLogin, otpCodeHash(code), now); {
 	case errors.Is(err, ErrOTPInvalid), errors.Is(err, ErrOTPLocked), errors.Is(err, ErrOTPAccountLocked):
 		a.noteOTPLock(r, err, loginReq.UserID, otpPurposeOpLogin)
+		a.authFailure(r, "op_login", otpFailureReason(err), a.opLoginAccount(r, loginReq.UserID))
 		writeError(w, r, invalid)
 		return
 	case err != nil:
@@ -317,6 +322,7 @@ func (a *API) handleOpLoginFinish(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	if !staffRole(u.Role) {
+		a.authFailure(r, "op_login", "not_staff", u)
 		writeError(w, r, newError(http.StatusForbidden, "staff_account", "that account is not an operator"))
 		return
 	}
@@ -331,10 +337,19 @@ func (a *API) handleOpLoginFinish(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	setSessionCookie(w, token, expires)
-	a.audit(r, u.Username, "auth.op_login", "")
+	a.auditAccount(r, u, "auth.op_login", "")
 	writeJSON(w, http.StatusOK, map[string]any{"user_id": u.ID, "role": u.Role})
 }
 
+// opLoginAccount loads the account a login request belongs to for a failure's
+// audit row, falling back to the bare id.
+func (a *API) opLoginAccount(r *http.Request, userID string) *StaffUser {
+	if u, err := a.Repo.UserByID(r.Context(), userID); err == nil {
+		return u
+	}
+	return &StaffUser{ID: userID}
+}
+
 // handleOpLoginPending lists live pending staff login requests, oldest first (internal
 // face). Today no plugin consumes it: the approver learns the request id out-of-band
 // (the op.console start screen shows it to the person logging in) and runs
@@ -421,9 +436,9 @@ func (a *API) handleOpLoginApprove(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	payload, _ := json.Marshal(map[string]string{"request_id": id, "approver_user_id": approverID})
-	_ = a.Repo.Audit(r.Context(), AuditEntry{
+	a.auditEntry(r, AuditEntry{
-		Actor: approver.Username, Source: "internal", Action: "auth.op_login.approved",
+		Actor: approver.Username, ActorUserID: approverID, Source: "internal",
-		RequestID: requestIDFromContext(r.Context()), Payload: payload,
+		Action: "auth.op_login.approved", Payload: payload,
 	})
 	writeJSON(w, http.StatusOK, map[string]any{"approved": true})
 }

internal/api/handlers_op_login_test.go

@@ -3,6 +3,7 @@ package api
 import (
 	"net/http"
 	"net/http/httptest"
+	"strings"
 	"testing"
 	"time"
 )
@@ -149,13 +150,14 @@ func TestOpLoginVertical(t *testing.T) {
 		t.Fatalf("session row for the cookie = %+v (ok=%v), want userID a1", s, ok)
 	}
 
-	// Three audits by "op": otp_sent (start), approved (in-game vouch), op_login (finish).
+	// Four audits by "op": otp_sent (start), the early finish refused before
-	if n := len(repo.audits); n != 3 {
+	// approval, approved (in-game vouch), op_login (finish).
-		t.Fatalf("want 3 audits, got %d: %+v", n, repo.audits)
+	if n := len(repo.audits); n != 4 {
+		t.Fatalf("want 4 audits, got %d: %+v", n, repo.audits)
 	}
-	wantActions := []string{"auth.op_login.otp_sent", "auth.op_login.approved", "auth.op_login"}
+	wantActions := []string{"auth.op_login.otp_sent", "auth.op_login.failed", "auth.op_login.approved", "auth.op_login"}
 	for i, want := range wantActions {
-		if repo.audits[i].Action != want || repo.audits[i].Actor != "op" {
+		if repo.audits[i].Action != want || repo.audits[i].Actor != "op" || repo.audits[i].ActorUserID != "a1" {
 			t.Errorf("audit[%d] = %+v, want action %q by op", i, repo.audits[i], want)
 		}
 	}
@@ -213,7 +215,7 @@ func TestOpLoginOwnerAdmitted(t *testing.T) {
 // a request_id + expires_at, mint/mail nothing, and still burn the per-recipient
 // cooldown — so neither the response nor the throttle tells a caller who is staff.
 func TestOpLoginStartNeutral(t *testing.T) {
-	check := func(t *testing.T, seed func(*fakeRepo), email string) {
+	check := func(t *testing.T, seed func(*fakeRepo), email, wantReason, wantUser string) {
 		t.Helper()
 		repo := newFakeRepo()
 		repo.settings[LocalAuthEnabledKey] = []byte("true")
@@ -236,9 +238,15 @@ func TestOpLoginStartNeutral(t *testing.T) {
 		if s, _ := b["expires_at"].(string); s == "" {
 			t.Error("neutral start must still return expires_at")
 		}
-		if len(repo.opLogins) != 0 || len(repo.otps) != 0 || mailer.calls != 0 || len(repo.audits) != 0 {
+		if len(repo.opLogins) != 0 || len(repo.otps) != 0 || mailer.calls != 0 {
-			t.Errorf("neutral start must mint/mail/audit nothing: reqs=%d otps=%d mails=%d audits=%d",
+			t.Errorf("neutral start must mint/mail nothing: reqs=%d otps=%d mails=%d",
-				len(repo.opLogins), len(repo.otps), mailer.calls, len(repo.audits))
+				len(repo.opLogins), len(repo.otps), mailer.calls)
+		}
+		// The response is neutral; the operator's record is not.
+		if len(repo.audits) != 1 || repo.audits[0].Action != "auth.op_login.failed" ||
+			!strings.Contains(string(repo.audits[0].Payload), `"reason":"`+wantReason+`"`) ||
+			repo.audits[0].ActorUserID != wantUser {
+			t.Errorf("neutral start audits = %+v, want one auth.op_login.failed %s by %q", repo.audits, wantReason, wantUser)
 		}
 		// The reservation is KEPT: re-probing the same address is throttled like a resend.
 		if w := startOp(eh, email); w.Code != http.StatusTooManyRequests || decodeErr(t, w) != "otp_resend_cooldown" {
@@ -247,12 +255,12 @@ func TestOpLoginStartNeutral(t *testing.T) {
 	}
 
 	t.Run("unknown address", func(t *testing.T) {
-		check(t, nil, "[email protected]")
+		check(t, nil, "[email protected]", "no_account", "")
 	})
 	t.Run("non-staff (role=user) address is ignored by the staff door", func(t *testing.T) {
 		check(t, func(repo *fakeRepo) {
 			repo.staff["p"] = &StaffUser{ID: "u9", Username: "p", Email: "[email protected]", Role: "user", EmailVerified: true}
-		}, "[email protected]")
+		}, "[email protected]", "not_staff", "u9")
 	})
 }
 

internal/api/handlers_passkey.go

@@ -355,7 +355,7 @@ func (a *API) handlePasskeyRegisterFinish(w http.ResponseWriter, r *http.Request
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, auditActor(p), "account.passkey.registered", cred.ID)
+	a.audit(r, "account.passkey.registered", cred.ID)
 	writeJSON(w, http.StatusCreated, passkeyView(cred))
 }
 
@@ -415,7 +415,7 @@ func (a *API) handlePasskeyDelete(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, auditActor(p), "account.passkey.removed", id)
+	a.audit(r, "account.passkey.removed", id)
 	w.WriteHeader(http.StatusNoContent)
 }
 
@@ -593,6 +593,7 @@ func (a *API) handlePasskeyLoginFinish(w http.ResponseWriter, r *http.Request) {
 	u, err := a.Repo.UserByEmail(r.Context(), email)
 	if err != nil {
 		if errors.Is(err, ErrNotFound) {
+			a.authFailure(r, "passkey", "no_account", nil)
 			writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 				"passkey login could not be completed; begin again"))
 			return
@@ -604,6 +605,7 @@ func (a *API) handlePasskeyLoginFinish(w http.ResponseWriter, r *http.Request) {
 	sessionData, err := a.Repo.ConsumePasskeyChallengeByUser(r.Context(), u.ID, passkeyPurposeLogin, a.now())
 	if err != nil {
 		if errors.Is(err, ErrPasskeyChallengeInvalid) {
+			a.authFailure(r, "passkey", "challenge_invalid", u)
 			writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 				"passkey login could not be completed; begin again"))
 			return
@@ -625,6 +627,7 @@ func (a *API) handlePasskeyLoginFinish(w http.ResponseWriter, r *http.Request) {
 	}
 	va, err := a.Passkey.FinishLogin(user, sessionData, bytes.NewReader(req.Assertion))
 	if err != nil {
+		a.authFailure(r, "passkey", "bad_assertion", u)
 		writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 			"passkey login could not be completed; begin again"))
 		return
@@ -634,7 +637,7 @@ func (a *API) handlePasskeyLoginFinish(w http.ResponseWriter, r *http.Request) {
 	// distinctly; a successful assertion advances the stored counter and stamps last_used_at.
 	if err := a.applyAssertionCounter(r.Context(), va); err != nil {
 		if errors.Is(err, errPasskeyClonedAuthenticator) {
-			a.audit(r, u.Username, "auth.passkey_clone_rejected", va.CredentialID)
+			a.passkeyCloneRejected(r, "passkey", u, va.CredentialID)
 			writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 				"passkey login could not be completed; begin again"))
 			return
@@ -654,7 +657,7 @@ func (a *API) handlePasskeyLoginFinish(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	setSessionCookie(w, token, expires)
-	a.audit(r, u.Username, "auth.passkey_login", "")
+	a.auditAccount(r, u, "auth.passkey_login", "")
 	writeJSON(w, http.StatusOK, map[string]any{
 		"user_id": u.ID,
 		"role":    u.Role,

internal/api/handlers_passkey_discoverable.go

@@ -128,6 +128,7 @@ func (a *API) handlePasskeyLoginDiscoverableFinish(w http.ResponseWriter, r *htt
 	sessionData, err := a.Repo.ConsumeDiscoverableChallenge(r.Context(), req.LoginID, a.now())
 	if err != nil {
 		if errors.Is(err, ErrPasskeyChallengeInvalid) {
+			a.authFailure(r, "passkey_discoverable", "challenge_invalid", nil)
 			writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 				"passkey login could not be completed; begin again"))
 			return
@@ -166,6 +167,9 @@ func (a *API) handlePasskeyLoginDiscoverableFinish(w http.ResponseWriter, r *htt
 	}
 	va, err := a.Passkey.FinishDiscoverableLogin(resolve, sessionData, bytes.NewReader(req.Assertion))
 	if err != nil {
+		// resolved is set when the credential named a live account and only the
+		// signature (or the credential's binding) failed.
+		a.authFailure(r, "passkey_discoverable", "bad_assertion", resolved)
 		writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 			"passkey login could not be completed; begin again"))
 		return
@@ -184,7 +188,7 @@ func (a *API) handlePasskeyLoginDiscoverableFinish(w http.ResponseWriter, r *htt
 	// resolved account; a successful assertion advances the stored counter and stamps last_used_at.
 	if err := a.applyAssertionCounter(r.Context(), va); err != nil {
 		if errors.Is(err, errPasskeyClonedAuthenticator) {
-			a.audit(r, resolved.Username, "auth.passkey_clone_rejected", va.CredentialID)
+			a.passkeyCloneRejected(r, "passkey_discoverable", resolved, va.CredentialID)
 			writeError(w, r, newError(http.StatusBadRequest, "passkey_login_invalid",
 				"passkey login could not be completed; begin again"))
 			return
@@ -204,7 +208,7 @@ func (a *API) handlePasskeyLoginDiscoverableFinish(w http.ResponseWriter, r *htt
 		return
 	}
 	setSessionCookie(w, token, expires)
-	a.audit(r, resolved.Username, "auth.passkey_login_discoverable", "")
+	a.auditAccount(r, resolved, "auth.passkey_login_discoverable", "")
 	writeJSON(w, http.StatusOK, map[string]any{
 		"user_id": resolved.ID,
 		"role":    resolved.Role,

internal/api/handlers_player_reclaim.go

@@ -98,9 +98,8 @@ func (a *API) handleReclaimUsername(w http.ResponseWriter, r *http.Request) {
 		// accountability record shows the reclaim was declined, and why.
 		payload, _ := json.Marshal(map[string]string{
 			"username": req.Username, "squatter_uuid": req.SquatterUUID, "reason": "protected_admin"})
-		_ = a.Repo.Audit(r.Context(), AuditEntry{
+		a.auditEntry(r, AuditEntry{
-			Actor: "velocity", Source: "internal", Action: "player.reclaim.refused",
+			Actor: "velocity", Source: "internal", Action: "player.reclaim.refused", Payload: payload,
-			RequestID: requestIDFromContext(r.Context()), Payload: payload,
 		})
 		writeError(w, r, newError(http.StatusConflict, "protected_admin",
 			"that username belongs to a linked administrator on the login server and cannot be reclaimed"))
@@ -126,9 +125,8 @@ func (a *API) handleReclaimUsername(w http.ResponseWriter, r *http.Request) {
 	// payload (the flat columns model a server op, not this), keyed by Source
 	// internal since velocity, not a human, drives it.
 	payload, _ := json.Marshal(map[string]string{"username": req.Username, "squatter_uuid": req.SquatterUUID})
-	_ = a.Repo.Audit(r.Context(), AuditEntry{
+	a.auditEntry(r, AuditEntry{
-		Actor: "velocity", Source: "internal", Action: "player.reclaim",
+		Actor: "velocity", Source: "internal", Action: "player.reclaim", Payload: payload,
-		RequestID: requestIDFromContext(r.Context()), Payload: payload,
 	})
 	writeJSON(w, http.StatusOK, map[string]any{
 		"blacklisted":     true,

internal/api/handlers_setup.go

@@ -67,6 +67,7 @@ func (a *API) handleSetupRedeem(w http.ResponseWriter, r *http.Request) {
 	if err != nil {
 		// Unknown, already-consumed, or expired — uniform 400 so the token cannot
 		// be used as an oracle.
+		a.authFailure(r, "setup_redeem", "bad_token", nil)
 		writeError(w, r, newError(http.StatusBadRequest, "setup_token_invalid",
 			"this setup link is invalid or has already been used"))
 		return
@@ -96,7 +97,7 @@ func (a *API) handleSetupRedeem(w http.ResponseWriter, r *http.Request) {
 	creds, _ := a.Repo.PasskeyCredentialsForUser(r.Context(), u.ID)
 	hasPasskey := len(creds) > 0
 
-	a.audit(r, u.Username, "auth.setup_redeem", "")
+	a.auditAccount(r, u, "auth.setup_redeem", "")
 	writeJSON(w, http.StatusOK, map[string]any{
 		"user_id":        u.ID,
 		"username":       u.Username,

internal/api/handlers_updates.go

@@ -113,6 +113,6 @@ func (a *API) handleSetUpdateWindow(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, principalFromContext(r.Context()).Email, "updates.window_set", "")
+	a.audit(r, "updates.window_set", "")
 	writeJSON(w, http.StatusOK, body)
 }

internal/api/handlers_user.go

@@ -67,7 +67,7 @@ func (a *API) handleWake(w http.ResponseWriter, r *http.Request) {
 	// held at capacity should retry the instant a slot frees, not wait out a
 	// cooldown their refused wake never earned).
 	a.limiter().record(name)
-	a.audit(r, p.Email, "wake", name)
+	a.audit(r, "wake", name)
 	writeJSON(w, http.StatusAccepted, map[string]any{"name": name, "desiredState": "Running"})
 }
 
@@ -95,7 +95,7 @@ func (a *API) handleStop(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "stop", name)
+	a.audit(r, "stop", name)
 	writeJSON(w, http.StatusAccepted, map[string]any{"name": name, "desiredState": "Stopped"})
 }
 
@@ -160,7 +160,7 @@ func (a *API) handleClaim(w http.ResponseWriter, r *http.Request) {
 	}
 
 	// ④ audit. Allowlist population happens on first successful join (spec §9.4).
-	a.audit(r, p.Email, "claim", name)
+	a.audit(r, "claim", name)
 	writeJSON(w, http.StatusOK, map[string]any{"name": name, "claimed": true})
 }
 
@@ -321,7 +321,6 @@ func (a *API) handleCreateServer(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, errBuildUnavailable)
 		return
 	}
-	p := principalFromContext(r.Context())
 
 	var body createServerRequest
 	if err := decodeJSON(w, r, &body); err != nil {
@@ -449,7 +448,7 @@ func (a *API) handleCreateServer(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "server.create", body.Name)
+	a.audit(r, "server.create", body.Name)
 	writeJSON(w, http.StatusCreated, map[string]any{
 		"name":         body.Name,
 		"subdomain":    body.Subdomain,
@@ -634,7 +633,6 @@ type patchServerRequest struct {
 // (Postgres) is untouched, so the two never desync (spec §22). The admin gate is
 // the adminOnly wrapper in routing — every caller here is already an admin.
 func (a *API) handlePatchServer(w http.ResponseWriter, r *http.Request) {
-	p := principalFromContext(r.Context())
 	name := r.PathValue("name")
 	if err := naming.ValidateServerName(name); err != nil {
 		writeError(w, r, newError(http.StatusBadRequest, "bad_name", "invalid server name: %v", err))
@@ -794,7 +792,7 @@ func (a *API) handlePatchServer(w http.ResponseWriter, r *http.Request) {
 		}
 	}
 
-	a.audit(r, p.Email, "server.patch", name)
+	a.audit(r, "server.patch", name)
 	writeJSON(w, http.StatusOK, map[string]any{
 		"name":    name,
 		"patched": changed,
@@ -838,18 +836,6 @@ func (a *API) isOwnerOrAdmin(p *Principal, rec *ServerRecord) bool {
 	return rec != nil && rec.OwnerID != "" && rec.OwnerID == p.UserID
 }
 
-// audit writes a best-effort audit row; a logging failure must not fail the
-// underlying operation, which already succeeded.
-func (a *API) audit(r *http.Request, actor, action, server string) {
-	_ = a.Repo.Audit(r.Context(), AuditEntry{
-		Actor:      actor,
-		Source:     "external",
-		Action:     action,
-		ServerName: server,
-		RequestID:  requestIDFromContext(r.Context()),
-	})
-}
-
 // quantityToMilli converts a K8s resource.Quantity to millicores (e.g. "2"→2000,
 // "500m"→500). A zero/unset quantity returns 0.
 func quantityToMilli(q resource.Quantity) int {

internal/api/handlers_users.go

@@ -5,6 +5,8 @@ import (
 	"net/http"
 	"strconv"
 	"strings"
+
+	"felis.lolicon.best/internal/metrics"
 )
 
 // ---- user CRUD ----
@@ -99,7 +101,7 @@ func (a *API) handleCreateUser(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.create", u.ID)
+	a.audit(r, "user.create", u.ID)
 	writeJSON(w, http.StatusCreated, u)
 }
 
@@ -179,7 +181,7 @@ func (a *API) handlePatchUser(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.patch", id)
+	a.audit(r, "user.patch", id)
 	writeJSON(w, http.StatusOK, u)
 }
 
@@ -215,7 +217,7 @@ func (a *API) handleDeleteUser(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.delete", id)
+	a.audit(r, "user.delete", id)
 	writeJSON(w, http.StatusOK, map[string]any{"deleted": true})
 }
 
@@ -266,7 +268,7 @@ func (a *API) handleDisableUser(w http.ResponseWriter, r *http.Request) {
 	if body.Disabled {
 		action = "user.disable"
 	}
-	a.audit(r, p.Email, action, id)
+	a.audit(r, action, id)
 	writeJSON(w, http.StatusOK, map[string]any{"id": id, "disabled": body.Disabled})
 }
 
@@ -323,7 +325,7 @@ func (a *API) handleSetQuotas(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.set_quotas", id)
+	a.audit(r, "user.set_quotas", id)
 	writeJSON(w, http.StatusOK, v)
 }
 
@@ -350,7 +352,6 @@ func (a *API) handleListUserSessions(w http.ResponseWriter, r *http.Request) {
 // handleRevokeUserSessions revokes every live session of a user
 // (DELETE /users/{id}/sessions).
 func (a *API) handleRevokeUserSessions(w http.ResponseWriter, r *http.Request) {
-	p := principalFromContext(r.Context())
 	id := r.PathValue("id")
 	if id == "" {
 		writeError(w, r, errBadRequest)
@@ -362,14 +363,14 @@ func (a *API) handleRevokeUserSessions(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.revoke_sessions", id)
+	metrics.SessionsRevokedTotal.WithLabelValues("admin").Inc()
+	a.audit(r, "user.revoke_sessions", id)
 	writeJSON(w, http.StatusOK, map[string]any{"ok": true})
 }
 
 // handleRevokeUserSession revokes a single session of a user
 // (DELETE /users/{id}/sessions/{hash}).
 func (a *API) handleRevokeUserSession(w http.ResponseWriter, r *http.Request) {
-	p := principalFromContext(r.Context())
 	id := r.PathValue("id")
 	tokenHash := r.PathValue("hash")
 	if id == "" || tokenHash == "" {
@@ -382,7 +383,8 @@ func (a *API) handleRevokeUserSession(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.revoke_session", id)
+	metrics.SessionsRevokedTotal.WithLabelValues("admin").Inc()
+	a.audit(r, "user.revoke_session", id)
 	writeJSON(w, http.StatusOK, map[string]any{"ok": true})
 }
 
@@ -397,7 +399,6 @@ func (a *API) handleRevokeUserSession(w http.ResponseWriter, r *http.Request) {
 // DeleteAllPasskeyCredentialsForUser treats removing zero rows as success, so
 // unbinding an account that holds no passkeys is a 200 no-op, not a 404.
 func (a *API) handleUnbindUserPasskeys(w http.ResponseWriter, r *http.Request) {
-	p := principalFromContext(r.Context())
 	id := r.PathValue("id")
 	if id == "" {
 		writeError(w, r, errBadRequest)
@@ -409,7 +410,7 @@ func (a *API) handleUnbindUserPasskeys(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.unbind_passkeys", id)
+	a.audit(r, "user.unbind_passkeys", id)
 	writeJSON(w, http.StatusOK, map[string]any{"ok": true})
 }
 
@@ -418,7 +419,6 @@ func (a *API) handleUnbindUserPasskeys(w http.ResponseWriter, r *http.Request) {
 // handleUnlinkAccount removes a single (user_id, mc_uuid) binding
 // (DELETE /users/{id}/links/{mc_uuid}).
 func (a *API) handleUnlinkAccount(w http.ResponseWriter, r *http.Request) {
-	p := principalFromContext(r.Context())
 	userID := r.PathValue("id")
 	mcUUID := r.PathValue("mc_uuid")
 	if userID == "" || mcUUID == "" {
@@ -436,14 +436,13 @@ func (a *API) handleUnlinkAccount(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.unlink_account", userID)
+	a.audit(r, "user.unlink_account", userID)
 	writeJSON(w, http.StatusOK, map[string]any{"ok": true, "mc_uuid": mcUUID})
 }
 
 // handleLinkAccount force-binds a UUID to a user
 // (POST /users/{id}/links).
 func (a *API) handleLinkAccount(w http.ResponseWriter, r *http.Request) {
-	p := principalFromContext(r.Context())
 	userID := r.PathValue("id")
 	if userID == "" {
 		writeError(w, r, errBadRequest)
@@ -489,7 +488,7 @@ func (a *API) handleLinkAccount(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	a.audit(r, p.Email, "user.link_account", userID)
+	a.audit(r, "user.link_account", userID)
 	writeJSON(w, http.StatusOK, map[string]any{
 		"ok":          true,
 		"mc_uuid":     body.MCUUID,

internal/api/images.go

@@ -73,7 +73,7 @@ func (a *API) handleBuildImage(w http.ResponseWriter, r *http.Request) {
 		writeBuildError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "image.build", bld.ImageRef)
+	a.audit(r, "image.build", bld.ImageRef)
 	writeJSON(w, http.StatusAccepted, bld)
 }
 
@@ -151,7 +151,7 @@ func (a *API) handleBuildLogs(w http.ResponseWriter, r *http.Request) {
 			"could not open build logs"))
 		return
 	}
-	a.audit(r, p.Email, "image.build.logs", id)
+	a.audit(r, "image.build.logs", id)
 	relayLogStream(w, r, src)
 }
 
@@ -162,14 +162,13 @@ func (a *API) handleCancelBuild(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, errBuildUnavailable)
 		return
 	}
-	p := principalFromContext(r.Context())
 	id := r.PathValue("id")
 	bld, err := a.Builder.Cancel(r.Context(), id)
 	if err != nil {
 		writeBuildError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "image.build.cancel", bld.ImageRef)
+	a.audit(r, "image.build.cancel", bld.ImageRef)
 	writeJSON(w, http.StatusOK, bld)
 }
 
@@ -206,7 +205,7 @@ func (a *API) handleAddImage(w http.ResponseWriter, r *http.Request) {
 		writeBuildError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "image.admit", img.ImageRef)
+	a.audit(r, "image.admit", img.ImageRef)
 	writeJSON(w, http.StatusCreated, img)
 }
 
@@ -218,7 +217,6 @@ func (a *API) handleRemoveImage(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, errBuildUnavailable)
 		return
 	}
-	p := principalFromContext(r.Context())
 	ref := r.URL.Query().Get("ref")
 	if ref == "" {
 		writeError(w, r, newError(http.StatusBadRequest, "bad_request",
@@ -229,7 +227,7 @@ func (a *API) handleRemoveImage(w http.ResponseWriter, r *http.Request) {
 		writeBuildError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "image.remove", ref)
+	a.audit(r, "image.remove", ref)
 	w.WriteHeader(http.StatusNoContent)
 }
 

internal/api/otp_lock.go

@@ -61,12 +61,7 @@ func (a *API) noteOTPLock(r *http.Request, err error, userID, purpose string) {
 	payload, _ := json.Marshal(map[string]any{
 		"user_id": userID, "purpose": purpose, "until": lock.Until.UTC(), "failures": otpFailureBudget,
 	})
-	if aerr := a.Repo.Audit(ctx, AuditEntry{
+	a.auditEntry(r, AuditEntry{Actor: actor, ActorUserID: userID, Action: "auth.otp.locked", Payload: payload})
-		Actor: actor, Source: "external", Action: "auth.otp.locked",
-		RequestID: requestIDFromContext(ctx), Payload: payload,
-	}); aerr != nil {
-		log.Printf("auth: audit of otp lock for user %s failed: %v", userID, aerr)
-	}
 
 	door, notify := otpDoorName[purpose]
 	if !notify || uerr != nil || u.Email == "" {

internal/api/pgrepo.go

@@ -747,10 +747,16 @@ func (p *PGRepo) Audit(ctx context.Context, e AuditEntry) error {
 	if len(e.Payload) > 0 {
 		payload = string(e.Payload)
 	}
+	// actor_user_id goes through a lookup so an id with no users row (an
+	// Access-JWT subject, a purged account) lands as NULL instead of failing
+	// the foreign key and losing the row.
 	_, err := p.db.ExecContext(ctx,
-		`INSERT INTO audit_logs (actor, source, action, server_name, request_id, payload)
+		`INSERT INTO audit_logs (actor, source, action, server_name, request_id, payload,
-		 VALUES ($1, $2, $3, NULLIF($4, ''), NULLIF($5, ''), $6)`,
+		                         actor_user_id, client_ip, user_agent)
-		e.Actor, e.Source, e.Action, e.ServerName, e.RequestID, payload)
+		 VALUES ($1, $2, $3, NULLIF($4, ''), NULLIF($5, ''), $6,
+		         (SELECT id FROM users WHERE id = NULLIF($7, '')), NULLIF($8, '')::inet, NULLIF($9, ''))`,
+		e.Actor, e.Source, e.Action, e.ServerName, e.RequestID, payload,
+		e.ActorUserID, e.ClientIP, e.UserAgent)
 	return err
 }
 
@@ -1086,13 +1092,13 @@ func (p *PGRepo) SessionUser(ctx context.Context, tokenHash string, now time.Tim
 	// minted for an account that was alive a moment ago stops authenticating the
 	// instant the account is disabled or soft-deleted, so every authenticated route
 	// is fail-closed regardless of which door minted the cookie (audit #33).
-	const q = `SELECT u.id, COALESCE(u.email, ''), u.role::text, COALESCE(u.email_verified, false)
+	const q = `SELECT u.id, u.username, COALESCE(u.email, ''), u.role::text, COALESCE(u.email_verified, false)
 		FROM sessions s JOIN users u ON u.id = s.user_id
 		WHERE s.token_hash = $1 AND s.revoked_at IS NULL AND s.expires_at > $2
 		  AND u.disabled = false AND u.deleted_at IS NULL`
 	var u SessionedUser
 	switch err := p.db.QueryRowContext(ctx, q, tokenHash, now).Scan(
-		&u.ID, &u.Email, &u.Role, &u.EmailVerified); {
+		&u.ID, &u.Username, &u.Email, &u.Role, &u.EmailVerified); {
 	case errors.Is(err, sql.ErrNoRows):
 		return nil, ErrNotFound
 	case err != nil:

internal/api/ratelimit.go

@@ -54,6 +54,9 @@ const (
 type tokenBucket struct {
 	tokens float64
 	at     time.Time
+	// refusing is set from a refusal until the next admission, so one episode
+	// of refusals can be recorded once.
+	refusing bool
 }
 
 // bucketSet is a set of token buckets keyed by caller. A missing key is a full
@@ -121,8 +124,16 @@ func (s *bucketSet) bucket(key string, now time.Time) *tokenBucket {
 // take spends one token from key's bucket. When none is left it reports how
 // long until one is. A disabled limit always admits.
 func (s *bucketSet) take(key string) (bool, time.Duration) {
+	ok, wait, _ := s.admit(key)
+	return ok, wait
+}
+
+// admit is take that also reports whether a refusal is the first since key was
+// last admitted, so a flood leaves one audit row per episode instead of one
+// per refused request.
+func (s *bucketSet) admit(key string) (ok bool, wait time.Duration, first bool) {
 	if s == nil || !s.limit.enabled() {
-		return true, 0
+		return true, 0, false
 	}
 	s.mu.Lock()
 	defer s.mu.Unlock()
@@ -130,9 +141,12 @@ func (s *bucketSet) take(key string) (bool, time.Duration) {
 	b := s.bucket(key, now)
 	if b.tokens >= 1 {
 		b.tokens--
-		return true, 0
+		b.refusing = false
+		return true, 0, false
 	}
-	return false, s.wait(b)
+	first = !b.refusing
+	b.refusing = true
+	return false, s.wait(b), first
 }
 
 // peek reports whether key's bucket holds a token, without spending it.
@@ -176,9 +190,14 @@ const mailGateKey = "mail"
 // throttleAuthDoor applies the per-source bucket to one public auth door.
 func (a *API) throttleAuthDoor(h http.HandlerFunc) http.HandlerFunc {
 	return func(w http.ResponseWriter, r *http.Request) {
-		ok, wait := a.authDoorGate().take(sourceKey(a.clientIP(r)))
+		key := sourceKey(a.clientIP(r))
+		ok, wait, first := a.authDoorGate().admit(key)
 		if !ok {
 			metrics.RateLimitedTotal.WithLabelValues("auth_door").Inc()
+			if first {
+				a.auditEntry(r, AuditEntry{Actor: anonymousActor, Action: "auth.rate_limited",
+					Payload: auditPayload(map[string]any{"source": key, "door": r.URL.Path})})
+			}
 			writeError(w, r, newError(http.StatusTooManyRequests, "rate_limited",
 				"too many sign-in requests from this network; try again shortly").retryAfter(wait))
 			return

internal/api/repo.go

@@ -32,14 +32,21 @@ type MyServerView struct {
 	PlayersMax    int32  `json:"playersMax"`
 }
 
-// AuditEntry is one row written to audit_logs (spec §6). The actor is the Access
+// AuditEntry is one row written to audit_logs (spec §6). Actor is display text:
-// email for human callers and the component name for internal callers.
+// a verified email or the username for people (auditActor), the component name
+// for internal callers. ActorUserID is the account that acted, the column to
+// attribute by: an unverified email proves nothing, so only the id is binding.
 type AuditEntry struct {
-	Actor      string
+	Actor       string
-	Source     string
+	ActorUserID string
-	Action     string
+	Source      string
-	ServerName string
+	Action      string
-	RequestID  string
+	ServerName  string
+	RequestID   string
+	// ClientIP and UserAgent say where an external call came from; empty for
+	// internal callers. ClientIP is the address the sign-in limit keys on.
+	ClientIP  string
+	UserAgent string
 	// Payload is an optional structured detail blob stored in the audit_logs.payload
 	// jsonb column. It MUST be valid JSON or nil; nil (the zero value) is stored as
 	// SQL NULL, so existing callers that leave it unset are unaffected. The
@@ -125,6 +132,7 @@ type PasskeyCredential struct {
 // accounts without a second DB read.
 type SessionedUser struct {
 	ID            string
+	Username      string
 	Email         string
 	Role          string
 	EmailVerified bool

internal/api/session.go

@@ -167,6 +167,7 @@ func (s SessionAuth) Authenticate(r *http.Request) (*Principal, error) {
 	}
 	return &Principal{
 		UserID:         u.ID,
+		Username:       u.Username,
 		Email:          u.Email,
 		Role:           u.Role,
 		ViaAdminAccess: staffRole(u.Role) && hostIsAdminConsole(r, s.RootDomain, s.AdminHostname),

internal/api/submissions.go

@@ -124,7 +124,7 @@ func (a *API) handleCreateSubmission(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	committed = true
-	a.audit(r, p.Email, "submission.create", sub.ID)
+	a.audit(r, "submission.create", sub.ID)
 	writeJSON(w, http.StatusCreated, sub)
 }
 
@@ -172,7 +172,7 @@ func (a *API) handleUploadSubmissionContext(w http.ResponseWriter, r *http.Reque
 		return
 	}
 	committed = true
-	a.audit(r, p.Email, "submission.upload", sub.ID)
+	a.audit(r, "submission.upload", sub.ID)
 	writeJSON(w, http.StatusOK, sub)
 }
 
@@ -274,7 +274,7 @@ func (a *API) handleApproveSubmission(w http.ResponseWriter, r *http.Request) {
 		writeSubmitError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "submission.approve", sub.ID)
+	a.audit(r, "submission.approve", sub.ID)
 	writeJSON(w, http.StatusOK, sub)
 }
 
@@ -297,7 +297,7 @@ func (a *API) handleRejectSubmission(w http.ResponseWriter, r *http.Request) {
 		writeSubmitError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "submission.reject", sub.ID)
+	a.audit(r, "submission.reject", sub.ID)
 	writeJSON(w, http.StatusOK, sub)
 }
 
@@ -318,7 +318,7 @@ func (a *API) handleWithdrawSubmission(w http.ResponseWriter, r *http.Request) {
 		writeSubmitError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "submission.withdraw", sub.ID)
+	a.audit(r, "submission.withdraw", sub.ID)
 	writeJSON(w, http.StatusOK, sub)
 }
 
@@ -333,13 +333,12 @@ func (a *API) handleDeleteSubmission(w http.ResponseWriter, r *http.Request) {
 		writeError(w, r, errSubmissionsUnavailable)
 		return
 	}
-	p := principalFromContext(r.Context())
 	sub, err := a.Submissions.Delete(r.Context(), r.PathValue("id"))
 	if err != nil {
 		writeSubmitError(w, r, err)
 		return
 	}
-	a.audit(r, p.Email, "submission.delete", sub.ID)
+	a.audit(r, "submission.delete", sub.ID)
 	writeJSON(w, http.StatusOK, sub)
 }
 
@@ -412,7 +411,7 @@ func (a *API) handleAdminSubmissionContext(w http.ResponseWriter, r *http.Reques
 	}
 	w.Header().Set("Content-Disposition", `attachment; filename="context.tar.gz"`)
 	w.Header().Set("X-Content-Type-Options", "nosniff")
-	a.audit(r, principalFromContext(r.Context()).Email, "submission.context.download", r.PathValue("id"))
+	a.audit(r, "submission.context.download", r.PathValue("id"))
 	streamSubmissionContext(w, rc)
 }
 

internal/metrics/metrics.go

@@ -81,6 +81,32 @@ var (
 		Name:      "rate_limited_total",
 		Help:      "Requests refused by a volumetric rate limit, by scope.",
 	}, []string{"scope"})
+
+	// AuthFailuresTotal counts refused sign-in attempts by door (login_email,
+	// op_login, passkey, passkey_discoverable, setup_redeem, bind_redeem) and
+	// reason (bad_code, no_account, staff_account, bad_credential, ...). A few a
+	// day is people mistyping; a steady stream is guessing or enumeration.
+	AuthFailuresTotal = prometheus.NewCounterVec(prometheus.CounterOpts{
+		Namespace: namespace,
+		Name:      "auth_failures_total",
+		Help:      "Refused sign-in attempts, by door and reason.",
+	}, []string{"door", "reason"})
+
+	// SessionsRevokedTotal counts sessions ended before expiry, by who ended
+	// them: logout (the holder) or admin (the owner revoking a user's sessions).
+	SessionsRevokedTotal = prometheus.NewCounterVec(prometheus.CounterOpts{
+		Namespace: namespace,
+		Name:      "sessions_revoked_total",
+		Help:      "Sessions revoked before expiry, by who revoked them.",
+	}, []string{"by"})
+
+	// AuditWriteFailuresTotal counts audit rows the API failed to write. The
+	// action went through; only its record was lost.
+	AuditWriteFailuresTotal = prometheus.NewCounter(prometheus.CounterOpts{
+		Namespace: namespace,
+		Name:      "audit_write_failures_total",
+		Help:      "Audit rows the API failed to write.",
+	})
 )
 
 // OTPPurposes are the email-code doors OTPLockoutsTotal is labelled by.
@@ -135,6 +161,9 @@ func Collectors() []prometheus.Collector {
 		OTPLockoutsTotal,
 		MailTotal,
 		RateLimitedTotal,
+		AuthFailuresTotal,
+		SessionsRevokedTotal,
+		AuditWriteFailuresTotal,
 	}
 }
 

internal/pgint/pgint_test.go

@@ -327,6 +327,57 @@ func TestConsumeLoginEmailOTPContract(t *testing.T) {
 // The account-level wrong-code budget must survive supersede: minting a fresh
 // code resets the per-code attempts, and the public login door can mint one a
 // minute, so only a counter outside email_otps bounds guessing per account.
+// TestAuditAttributionContract pins migration 0023: actor_user_id is filled
+// from a real account id and falls to NULL (never a failed insert) for an id
+// with no users row; client_ip and user_agent land when given.
+func TestAuditAttributionContract(t *testing.T) {
+	ctx := context.Background()
+	u := newUser(t, "user", "audit")
+	action := "pgint.audit." + suffix(t)
+	for _, e := range []api.AuditEntry{
+		{Actor: u.Username, ActorUserID: u.ID, Action: action, ClientIP: "2001:db8::7", UserAgent: "pgint/1"},
+		{Actor: "sso-subject", ActorUserID: "not-a-user-" + suffix(t), Action: action},
+		{Actor: "anonymous", Action: action, ClientIP: "203.0.113.9"},
+	} {
+		e.Source = "external"
+		if err := repo.Audit(ctx, e); err != nil {
+			t.Fatalf("Audit(%s): %v", e.Actor, err)
+		}
+	}
+	rows, err := db.QueryContext(ctx, `SELECT actor, COALESCE(actor_user_id, ''), COALESCE(host(client_ip), ''), COALESCE(user_agent, '')
+		FROM audit_logs WHERE action = $1 ORDER BY id`, action)
+	if err != nil {
+		t.Fatalf("select: %v", err)
+	}
+	defer rows.Close()
+	var got []string
+	for rows.Next() {
+		var actor, uid, ip, ua string
+		if err := rows.Scan(&actor, &uid, &ip, &ua); err != nil {
+			t.Fatalf("scan: %v", err)
+		}
+		got = append(got, strings.Join([]string{actor, uid, ip, ua}, "|"))
+	}
+	want := []string{
+		u.Username + "|" + u.ID + "|2001:db8::7|pgint/1",
+		"sso-subject|||",
+		"anonymous||203.0.113.9|",
+	}
+	if strings.Join(got, "\n") != strings.Join(want, "\n") {
+		t.Fatalf("audit rows:\n%s\nwant:\n%s", strings.Join(got, "\n"), strings.Join(want, "\n"))
+	}
+
+	// The session principal carries the username the rows are signed with.
+	hash := "audit-sess-" + suffix(t)
+	if err := repo.CreateSession(ctx, hash, u.ID, mustNow().Add(time.Hour)); err != nil {
+		t.Fatalf("CreateSession: %v", err)
+	}
+	su, err := repo.SessionUser(ctx, hash, mustNow())
+	if err != nil || su.Username != u.Username {
+		t.Fatalf("SessionUser = %+v, %v; want username %q", su, err, u.Username)
+	}
+}
+
 func TestOTPFailureBudgetContract(t *testing.T) {
 	ctx := context.Background()
 	u := newUser(t, "user", "otp-budget")

internal/store/migrations/0023_audit_attribution.sql

@@ -0,0 +1,16 @@
+-- Audit attribution. actor is display text, and for a signed-in caller it used
+-- to be the account's email, which a player can set to any unverified address,
+-- so a row could name someone else. actor_user_id is the account that acted,
+-- taken from the session (NULL for component actors and anonymous callers), and
+-- client_ip / user_agent say where the call came from (client_ip is the
+-- address the sign-in rate limit keys on: the edge's header when configured).
+-- Users are soft-deleted, so the SET NULL only runs on a hard purge; actor
+-- still names the account then.
+ALTER TABLE audit_logs
+  ADD COLUMN actor_user_id text REFERENCES users(id) ON DELETE SET NULL,
+  ADD COLUMN client_ip     inet,
+  ADD COLUMN user_agent    text;
+
+CREATE INDEX audit_logs_actor_user_id_idx ON audit_logs (actor_user_id, created_at DESC)
+  WHERE actor_user_id IS NOT NULL;
+CREATE INDEX audit_logs_created_at_idx ON audit_logs (created_at DESC);