From b60bc8d04bc2ecc29a3fa09afbcf98ea1665a4e1 Mon Sep 17 00:00:00 2001 From: J3vb <192430104+J3vb@users.noreply.github.com> Date: Mon, 20 Jul 2026 10:48:05 +0200 Subject: [PATCH] feat(audit): route every LogAudit call through a best-effort WriteAudit helper MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Audit writes stay best-effort — a LogAudit failure must never fail or abort the request — but a failed write must no longer be silently discarded. Add db.WriteAudit(auditor, actor, action, targetType, targetID, detail), which logs a failed write with actor/action/target context (never the detail string, which may be sensitive) and never propagates the error. The Auditor interface is satisfied structurally by both *db.DB and the service-layer Store, so api/admin/ws/service all reach the helper without an import cycle. Converts all ~26 call sites from `_ = LogAudit(...)` (and the two backup handlers' inline `if err` blocks) to db.WriteAudit. Pinned by db/audit_test.go: failure logged and not propagated, success logs nothing, detail never leaks. Resolves the repo-wide LogAudit policy question flagged by the D8 note. Co-Authored-By: Claude Fable 5 --- Server/admin/handlers_backup.go | 10 +--- Server/admin/handlers_channel_perms.go | 4 +- Server/admin/handlers_channels.go | 6 +- Server/admin/handlers_settings.go | 2 +- Server/admin/handlers_users.go | 4 +- Server/admin/setup_handler.go | 2 +- Server/api/auth_handler.go | 10 ++-- Server/api/totp_handler.go | 6 +- Server/db/audit.go | 32 +++++++++++ Server/db/audit_test.go | 79 ++++++++++++++++++++++++++ Server/service/message.go | 2 +- Server/service/moderation.go | 9 +-- Server/service/user.go | 6 +- Server/ws/serve.go | 2 +- 14 files changed, 139 insertions(+), 35 deletions(-) create mode 100644 Server/db/audit.go create mode 100644 Server/db/audit_test.go diff --git a/Server/admin/handlers_backup.go b/Server/admin/handlers_backup.go index 578a3509..fbf11256 100644 --- a/Server/admin/handlers_backup.go +++ b/Server/admin/handlers_backup.go @@ -52,10 +52,8 @@ func handleBackup(database *db.DB) http.Handler { actor := actorFromContext(r) backupName := filepath.Base(backupPath) slog.Info("database backup created", "actor_id", actor, "name", backupName) - if err := database.LogAudit(actor, "backup_create", "server", 0, - fmt.Sprintf("backup saved: %s", backupName)); err != nil { - slog.Error("audit log write failed", "action", "backup_create", "actor_id", actor, "error", err) - } + db.WriteAudit(database, actor, "backup_create", "server", 0, + fmt.Sprintf("backup saved: %s", backupName)) writeJSON(w, http.StatusOK, map[string]string{ "path": filepath.Base(backupPath), @@ -138,9 +136,7 @@ func handleDeleteBackup(database *db.DB) http.Handler { actor := actorFromContext(r) slog.Info("backup deleted", "actor_id", actor, "name", name) - if err := database.LogAudit(actor, "backup_delete", "server", 0, "deleted backup "+name); err != nil { - slog.Error("audit log write failed", "action", "backup_delete", "actor_id", actor, "error", err) - } + db.WriteAudit(database, actor, "backup_delete", "server", 0, "deleted backup "+name) w.WriteHeader(http.StatusNoContent) }) diff --git a/Server/admin/handlers_channel_perms.go b/Server/admin/handlers_channel_perms.go index 0676f51c..9ae893db 100644 --- a/Server/admin/handlers_channel_perms.go +++ b/Server/admin/handlers_channel_perms.go @@ -108,7 +108,7 @@ func handlePutChannelPermission(database *db.DB, hub HubBroadcaster, permInvalid actor := actorFromContext(r) slog.Info("channel permissions updated", "actor_id", actor, "channel_id", ch.ID, "role_id", roleID, "allow", allow, "deny", deny) - _ = database.LogAudit(actor, "channel_perms_update", "channel", ch.ID, + db.WriteAudit(database, actor, "channel_perms_update", "channel", ch.ID, fmt.Sprintf("set overrides for role %s on #%s (allow=%#x deny=%#x)", role.Name, ch.Name, allow, deny)) if permInvalidator != nil { @@ -147,7 +147,7 @@ func handleDeleteChannelPermission(database *db.DB, hub HubBroadcaster, permInva actor := actorFromContext(r) slog.Info("channel permissions cleared", "actor_id", actor, "channel_id", ch.ID, "role_id", roleID) - _ = database.LogAudit(actor, "channel_perms_clear", "channel", ch.ID, + db.WriteAudit(database, actor, "channel_perms_clear", "channel", ch.ID, fmt.Sprintf("cleared overrides for role %d on #%s", roleID, ch.Name)) if permInvalidator != nil { diff --git a/Server/admin/handlers_channels.go b/Server/admin/handlers_channels.go index f25ce293..9b96978a 100644 --- a/Server/admin/handlers_channels.go +++ b/Server/admin/handlers_channels.go @@ -115,7 +115,7 @@ func handleCreateChannel(database *db.DB, hub HubBroadcaster) http.HandlerFunc { } actor := actorFromContext(r) slog.Info("channel created", "actor_id", actor, "channel", req.Name, "type", req.Type) - _ = database.LogAudit(actor, "channel_create", "channel", id, + db.WriteAudit(database, actor, "channel_create", "channel", id, fmt.Sprintf("created #%s (%s)", req.Name, req.Type)) if hub != nil { hub.BroadcastChannelCreate(ch) @@ -171,7 +171,7 @@ func handlePatchChannel(database *db.DB, hub HubBroadcaster) http.HandlerFunc { actor := actorFromContext(r) slog.Info("channel updated", "actor_id", actor, "channel_id", id, "name", req.Name) - _ = database.LogAudit(actor, "channel_update", "channel", id, + db.WriteAudit(database, actor, "channel_update", "channel", id, fmt.Sprintf("updated #%s", req.Name)) updated, err := database.GetChannel(id) @@ -210,7 +210,7 @@ func handleDeleteChannel(database *db.DB, hub HubBroadcaster) http.HandlerFunc { } actor := actorFromContext(r) slog.Warn("channel deleted", "actor_id", actor, "channel_id", id, "name", existing.Name) - _ = database.LogAudit(actor, "channel_delete", "channel", id, + db.WriteAudit(database, actor, "channel_delete", "channel", id, fmt.Sprintf("deleted #%s", existing.Name)) if hub != nil { hub.BroadcastChannelDelete(id) diff --git a/Server/admin/handlers_settings.go b/Server/admin/handlers_settings.go index bddf55b3..4dabe9be 100644 --- a/Server/admin/handlers_settings.go +++ b/Server/admin/handlers_settings.go @@ -79,7 +79,7 @@ func handlePatchSettings(database *db.DB) http.HandlerFunc { } for key := range normalizedUpdates { slog.Info("setting changed", "actor_id", actor, "key", key) - _ = database.LogAudit(actor, "setting_change", "setting", 0, + db.WriteAudit(database, actor, "setting_change", "setting", 0, fmt.Sprintf("%s updated", key)) } diff --git a/Server/admin/handlers_users.go b/Server/admin/handlers_users.go index f3e9d628..2f2eb0da 100644 --- a/Server/admin/handlers_users.go +++ b/Server/admin/handlers_users.go @@ -139,7 +139,7 @@ func handlePatchUser(database *db.DB, hub HubBroadcaster, permInvalidator Permis if permInvalidator != nil { permInvalidator.InvalidateUser(id) } - _ = database.LogAudit(actor, "role_change", "user", id, + db.WriteAudit(database, actor, "role_change", "user", id, fmt.Sprintf("changed %s role to %d", user.Username, *req.RoleID)) if role, err := database.GetRoleByID(*req.RoleID); err == nil && role != nil { if hub != nil { @@ -171,7 +171,7 @@ func handleForceLogout(database *db.DB) http.HandlerFunc { } actor := actorFromContext(r) slog.Info("force logout", "actor_id", actor, "target_user_id", id) - _ = database.LogAudit(actor, "force_logout", "user", id, "all sessions terminated") + db.WriteAudit(database, actor, "force_logout", "user", id, "all sessions terminated") w.WriteHeader(http.StatusNoContent) } } diff --git a/Server/admin/setup_handler.go b/Server/admin/setup_handler.go index 4d1f169c..0edbfc44 100644 --- a/Server/admin/setup_handler.go +++ b/Server/admin/setup_handler.go @@ -152,7 +152,7 @@ func handleSetup(database *db.DB, limiter *auth.RateLimiter, allowedOrigins []st } slog.Info("server setup completed", "owner", req.Username, "user_id", uid) - _ = database.LogAudit(uid, "server_setup", "server", 0, + db.WriteAudit(database, uid, "server_setup", "server", 0, "initial setup: owner account created, default channel and invite generated") writeJSON(w, http.StatusCreated, setupResponse{ diff --git a/Server/api/auth_handler.go b/Server/api/auth_handler.go index 48e021cc..9e9ca880 100644 --- a/Server/api/auth_handler.go +++ b/Server/api/auth_handler.go @@ -211,7 +211,7 @@ func handleRegister(database *db.DB) http.HandlerFunc { ip := clientIP(r) slog.Info("user registered", "username", req.Username, "user_id", uid, "ip", ip) - _ = database.LogAudit(uid, "user_register", "user", uid, + db.WriteAudit(database, uid, "user_register", "user", uid, "new account created via invite") // Issue session. @@ -350,7 +350,7 @@ func handleLogin(database *db.DB, limiter *auth.RateLimiter, partialStore *auth. if auth.IsEffectivelyBanned(user) { slog.Warn("banned user login attempt", "username", user.Username, "user_id", user.ID, "ip", ip) - _ = database.LogAudit(user.ID, "login_blocked_banned", "user", user.ID, + db.WriteAudit(database, user.ID, "login_blocked_banned", "user", user.ID, "banned user attempted login from "+ip) writeJSON(w, http.StatusForbidden, errorResponse{ Error: "FORBIDDEN", @@ -405,7 +405,7 @@ func handleLogin(database *db.DB, limiter *auth.RateLimiter, partialStore *auth. // would leave the user permanently "online" if they never open a WS // connection or if the client crashes before connecting. slog.Info("user logged in", "username", user.Username, "user_id", user.ID, "ip", ip) - _ = database.LogAudit(user.ID, "user_login", "user", user.ID, + db.WriteAudit(database, user.ID, "user_login", "user", user.ID, "logged in from "+ip) writeJSON(w, http.StatusOK, authSuccessResponse{ Token: token, @@ -436,7 +436,7 @@ func handleLogout(database *db.DB) http.HandlerFunc { } slog.Info("user logged out", "user_id", sess.UserID) - _ = database.LogAudit(sess.UserID, "user_logout", "user", sess.UserID, "") + db.WriteAudit(database, sess.UserID, "user_logout", "user", sess.UserID, "") w.WriteHeader(http.StatusNoContent) } @@ -535,7 +535,7 @@ func handleDeleteAccount(database *db.DB, limiter *auth.RateLimiter) http.Handle ip := clientIP(r) slog.Info("account deleted", "username", user.Username, "user_id", user.ID, "ip", ip) - _ = database.LogAudit(user.ID, "account_deleted", "user", user.ID, + db.WriteAudit(database, user.ID, "account_deleted", "user", user.ID, "account self-deleted from "+ip) w.WriteHeader(http.StatusNoContent) diff --git a/Server/api/totp_handler.go b/Server/api/totp_handler.go index e7730099..f108b11d 100644 --- a/Server/api/totp_handler.go +++ b/Server/api/totp_handler.go @@ -131,7 +131,7 @@ func handleVerifyTOTP(database *db.DB, partialStore *auth.PartialAuthStore, limi } slog.Info("totp verified", "user_id", user.ID, "ip", challenge.IP) - _ = database.LogAudit(user.ID, "totp_verified", "user", user.ID, + db.WriteAudit(database, user.ID, "totp_verified", "user", user.ID, "two-factor verification completed from "+challenge.IP) writeJSON(w, http.StatusOK, authSuccessResponse{ @@ -296,7 +296,7 @@ func handleConfirmTOTP(database *db.DB, pendingStore *auth.PendingTOTPStore, use } slog.Info("totp enabled", "user_id", user.ID) - _ = database.LogAudit(user.ID, "totp_enabled", "user", user.ID, + db.WriteAudit(database, user.ID, "totp_enabled", "user", user.ID, "two-factor authentication enrolled") w.WriteHeader(http.StatusNoContent) @@ -379,7 +379,7 @@ func handleDisableTOTP(database *db.DB, pendingStore *auth.PendingTOTPStore, lim } slog.Info("totp disabled", "user_id", user.ID) - _ = database.LogAudit(user.ID, "totp_disabled", "user", user.ID, + db.WriteAudit(database, user.ID, "totp_disabled", "user", user.ID, "two-factor authentication disabled") w.WriteHeader(http.StatusNoContent) diff --git a/Server/db/audit.go b/Server/db/audit.go new file mode 100644 index 00000000..025d287d --- /dev/null +++ b/Server/db/audit.go @@ -0,0 +1,32 @@ +package db + +import "log/slog" + +// Auditor is the minimal audit-write surface WriteAudit needs. *DB satisfies +// it directly, and the service layer's Store interface does too, so every +// caller — api, admin, ws, service — can route its audit writes through this +// one helper regardless of whether it holds a *DB or a narrower interface. +type Auditor interface { + LogAudit(actorID int64, action, targetType string, targetID int64, detail string) error +} + +// WriteAudit records an audit entry best-effort. +// +// Per the D8 policy decision (docs/plans/audit-2026-07-19-decisions.md), audit +// writes stay best-effort: a LogAudit failure must never fail or abort the +// caller's request. But a failed write must never be silently discarded +// either — this helper logs it with the actor/action/target context so the +// gap is visible in the logs. The detail string is intentionally not logged; +// it can carry request-specific or sensitive text and the structured fields +// already identify what was attempted. +func WriteAudit(a Auditor, actorID int64, action, targetType string, targetID int64, detail string) { + if err := a.LogAudit(actorID, action, targetType, targetID, detail); err != nil { + slog.Error("audit log write failed", + "action", action, + "actor_id", actorID, + "target_type", targetType, + "target_id", targetID, + "error", err, + ) + } +} diff --git a/Server/db/audit_test.go b/Server/db/audit_test.go new file mode 100644 index 00000000..d638a8f7 --- /dev/null +++ b/Server/db/audit_test.go @@ -0,0 +1,79 @@ +package db_test + +import ( + "errors" + "log/slog" + "strings" + "testing" + + "github.com/owncord/server/db" +) + +// fakeAuditor lets a test drive WriteAudit down either the success or the +// failure path without a real database. +type fakeAuditor struct { + err error + called bool +} + +func (f *fakeAuditor) LogAudit(_ int64, _, _ string, _ int64, _ string) error { + f.called = true + return f.err +} + +// captureLogs redirects the default slog logger to a buffer for the duration +// of fn and returns everything it wrote. +func captureLogs(t *testing.T, fn func()) string { + t.Helper() + var buf strings.Builder + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug}))) + defer slog.SetDefault(prev) + fn() + return buf.String() +} + +func TestWriteAudit_LogsFailureButDoesNotPropagate(t *testing.T) { + a := &fakeAuditor{err: errors.New("disk on fire")} + + // WriteAudit returns nothing, so "never propagated" is structural — the + // call simply must not panic and must record the failure. + out := captureLogs(t, func() { + db.WriteAudit(a, 7, "user_ban", "user", 42, "spam") + }) + + if !a.called { + t.Fatal("WriteAudit did not attempt the underlying LogAudit") + } + for _, want := range []string{ + "audit log write failed", + "action=user_ban", + "actor_id=7", + "target_type=user", + "target_id=42", + "disk on fire", + } { + if !strings.Contains(out, want) { + t.Errorf("failure log missing %q; got: %s", want, out) + } + } + // The detail string must not leak into logs. + if strings.Contains(out, "spam") { + t.Errorf("detail string leaked into audit failure log: %s", out) + } +} + +func TestWriteAudit_SuccessLogsNothing(t *testing.T) { + a := &fakeAuditor{err: nil} + + out := captureLogs(t, func() { + db.WriteAudit(a, 1, "user_login", "user", 1, "") + }) + + if !a.called { + t.Fatal("WriteAudit did not attempt the underlying LogAudit") + } + if strings.Contains(out, "audit log write failed") { + t.Errorf("successful audit write should not log a failure; got: %s", out) + } +} diff --git a/Server/service/message.go b/Server/service/message.go index ea559326..b45b562d 100644 --- a/Server/service/message.go +++ b/Server/service/message.go @@ -369,7 +369,7 @@ func (s *MessageService) DeleteMessage(userID, msgID int64) (*DeleteMessageResul } slog.Debug("message deleted", "user_id", userID, "msg_id", msgID, "channel_id", msg.ChannelID, "is_mod", isMod) - _ = s.st.LogAudit(userID, "message_delete", "message", msgID, + db.WriteAudit(s.st, userID, "message_delete", "message", msgID, fmt.Sprintf("channel %d, mod_action=%v", msg.ChannelID, isMod)) result := &DeleteMessageResult{ diff --git a/Server/service/moderation.go b/Server/service/moderation.go index 28d0efe5..1c7f44e0 100644 --- a/Server/service/moderation.go +++ b/Server/service/moderation.go @@ -6,6 +6,7 @@ import ( "log/slog" "time" + "github.com/owncord/server/db" "github.com/owncord/server/permissions" "github.com/owncord/server/telemetry" ) @@ -99,9 +100,7 @@ func (s *ModerationService) BanUser(ctx context.Context, actorID, targetID int64 return fmt.Errorf("%w: failed to ban user", ErrInternal) } - if err := s.st.LogAudit(actorID, "user_ban", "user", targetID, reason); err != nil { - slog.Error("failed to log audit entry", "error", err) - } + db.WriteAudit(s.st, actorID, "user_ban", "user", targetID, reason) slog.Info("user banned", "actor_id", actorID, "target_id", targetID, "reason", reason) return nil @@ -129,9 +128,7 @@ func (s *ModerationService) UnbanUser(_ context.Context, actorID, targetID int64 return fmt.Errorf("%w: failed to unban user", ErrInternal) } - if err := s.st.LogAudit(actorID, "user_unban", "user", targetID, ""); err != nil { - slog.Error("failed to log audit entry", "error", err) - } + db.WriteAudit(s.st, actorID, "user_unban", "user", targetID, "") slog.Info("user unbanned", "actor_id", actorID, "target_id", targetID) return nil diff --git a/Server/service/user.go b/Server/service/user.go index 76948726..70590c9a 100644 --- a/Server/service/user.go +++ b/Server/service/user.go @@ -44,7 +44,7 @@ func (s *UserService) UpdateProfile(ctx context.Context, userID int64, username if err != nil { return nil, fmt.Errorf("%w: failed to fetch updated user", ErrInternal) } - _ = s.st.LogAudit(userID, "profile_update", "user", userID, + db.WriteAudit(s.st, userID, "profile_update", "user", userID, fmt.Sprintf("username=%s", username)) slog.Info("profile updated", "user_id", userID, "username", username) return user, nil @@ -83,7 +83,7 @@ func (s *UserService) ChangePassword(userID int64, newPasswordHash string, keepS res.RevokeFailed = true } } - _ = s.st.LogAudit(userID, "password_change", "user", userID, "password changed") + db.WriteAudit(s.st, userID, "password_change", "user", userID, "password changed") slog.Info("password changed", "user_id", userID, "sessions_revoked", res.SessionsRevoked, "revoke_failed", res.RevokeFailed) return res, nil @@ -106,7 +106,7 @@ func (s *UserService) RevokeSession(userID, sessionID int64) error { } return fmt.Errorf("%w: failed to revoke session", ErrInternal) } - _ = s.st.LogAudit(userID, "session_revoke", "session", sessionID, "session revoked") + db.WriteAudit(s.st, userID, "session_revoke", "session", sessionID, "session revoked") slog.Info("session revoked", "user_id", userID, "session_id", sessionID) return nil } diff --git a/Server/ws/serve.go b/Server/ws/serve.go index 3740d5c6..262848f7 100644 --- a/Server/ws/serve.go +++ b/Server/ws/serve.go @@ -103,7 +103,7 @@ func (h *Hub) upgradeAndAuth( c.roleName = roleName slog.Info("websocket connected", "username", user.Username, "user_id", user.ID, "remote", r.RemoteAddr) - _ = database.LogAudit(user.ID, "ws_connect", "user", user.ID, + db.WriteAudit(database, user.ID, "ws_connect", "user", user.ID, "WebSocket connected from "+r.RemoteAddr) return c, lastSeq, nil