mirror of
https://github.com/J3vb/OwnCord.git
synced 2026-09-03 03:50:00 +03:00
feat(audit): route every LogAudit call through a best-effort WriteAudit helper
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 <noreply@anthropic.com>
This commit is contained in:
@@ -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)
|
||||
})
|
||||
|
||||
@@ -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 {
|
||||
|
||||
@@ -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)
|
||||
|
||||
@@ -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))
|
||||
}
|
||||
|
||||
|
||||
@@ -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)
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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{
|
||||
|
||||
@@ -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)
|
||||
|
||||
@@ -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)
|
||||
|
||||
@@ -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,
|
||||
)
|
||||
}
|
||||
}
|
||||
@@ -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)
|
||||
}
|
||||
}
|
||||
@@ -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{
|
||||
|
||||
@@ -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
|
||||
|
||||
@@ -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
|
||||
}
|
||||
|
||||
+1
-1
@@ -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
|
||||
|
||||
Reference in New Issue
Block a user