Merge pull request #1195 from J3vb/feat/logaudit-no-silent-discard

feat(audit): no-silent-discard LogAudit policy via shared best-effort helper
This commit is contained in:
J3vb
2026-07-20 12:39:49 +02:00
committed by GitHub
16 changed files with 142 additions and 37 deletions
+3 -7
View File
@@ -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)
})
+2 -2
View File
@@ -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 {
+3 -3
View File
@@ -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)
+1 -1
View File
@@ -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))
}
+2 -2
View File
@@ -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)
}
}
+1 -1
View File
@@ -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{
+5 -5
View File
@@ -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)
+3 -3
View File
@@ -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)
+32
View File
@@ -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,
)
}
}
+79
View File
@@ -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)
}
}
+1 -1
View File
@@ -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{
+3 -6
View File
@@ -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
+3 -3
View File
@@ -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
View File
@@ -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
+1 -1
View File
@@ -53,7 +53,7 @@ audit's table; details stay in [audit-2026-04-07.md](audit-2026-04-07.md).
| 6 | HIGH | `Server/store/` untested | **RESOLVED 2026-07-19 (D3)** — the `store/` package is deleted rather than tested. `SQLiteStore` was a pure pass-through to `*db.DB`; its event/plugin methods moved into `db` (`event_queries.go`, `plugin_queries.go`). Consumers now depend on narrow interfaces `*db.DB` satisfies (`service.Store`, `ws.EventStore`, `plugin.PluginStore`), and the former `MemStore`-based unit tests run against a real in-memory SQLite `db` — so the code paths that were untested through the seam are now exercised directly |
| 7 | HIGH | Client unit coverage | Suite is large (157 test files) and green; flipping `client-tests` to blocking is backlog #10 — see A-2026-07-04 |
| 9 | MEDIUM | auth_handler bypasses service layer | **Confirmed open**`Server/api/router.go:101` passes `database *db.DB` to `MountAuthRoutes` while sibling mounts receive `svc` |
| 10 | MEDIUM | Audit-trail write failures silently ignored | **Fixed 2026-07-19** at the two flagged backup-handler sites (errors now logged). Wider scope discovered: the `_ = LogAudit` pattern exists at 23 call sites across admin/api/ws/service — appears to be a deliberate best-effort convention; policy decision tracked in the decisions doc (D8 note) |
| 10 | MEDIUM | Audit-trail write failures silently ignored | **RESOLVED 2026-07-20 (D9)** — best-effort audit writes are kept as the convention, but no longer silently discarded: every `LogAudit` call site now routes through the shared `db.WriteAudit` helper (`db/audit.go`), which logs a failed write with actor/action/target context without failing the request. All ~26 call sites across admin/api/ws/service converted from `_ = LogAudit(...)`; pinned by `db/audit_test.go` |
| 11 | MEDIUM | E2E not in CI | **Confirmed open** — no Playwright job exists in `.github/workflows/ci.yml` |
| W3-4 (remediation plan) | LOW | Contradictory upload cache header | **Fixed 2026-07-19** — now `private, no-cache` per the remediation plan's prescription |
+2 -1
View File
@@ -2,7 +2,7 @@
**Date decided:** 2026-07-19
**Decided by:** J3vb
**Status:** decisions recorded; greenlit items (D4, D7, D8) implemented 2026-07-19 — see per-row Status
**Status:** decisions recorded; greenlit items (D4, D7, D8) implemented 2026-07-19; D9 (repo-wide `LogAudit` policy, flagged by the D8 note) decided + implemented 2026-07-20 — see per-row Status
**Source:** decision points raised by [docs/audit-2026-07-19.md](../audit-2026-07-19.md)
This document records the maintainer's answers to the open decision points from
@@ -22,6 +22,7 @@ here (and the audit's closure table) as items land.
| D6 | Abandoned SolidJS beachhead + stale `docs/client-architecture.md` | A-2026-07-12 | **Delete it all**: remove `src/components/solid/`, `solidMount`/`solidAdapter`, `vite-plugin-solid`, and Solid test deps; retire `client-architecture.md` in favor of [docs/architecture/client.md](../architecture/client.md). | **Implemented 2026-07-19** — solid/ dir, solidMount/solidAdapter, setup-solid tests, vite-plugin-solid, jsx tsconfig settings, and solid-js/@solidjs deps all removed; client-architecture.md is now a pointer. |
| D7 | Spec refresh strategy for api.md / protocol.md / schema.md | A-2026-07-03 | **One refresh PR first**, using the audit's §2 conformance matrix as the checklist; afterwards specs are kept current per-PR (see the maintenance rule in [docs/architecture/README.md](../architecture/README.md)). Announcement channels (D1) later update the *fresh* specs. | **Implemented 2026-07-19** — all three specs refreshed against the code (incl. E2EE protocol section, migrations 001015, profile/blocks/plugin-admin endpoints); reference tables now point at `protocol-schema.json`. |
| D8 | What to implement first | backlog §6 | **Greenlit now: Protocol codegen (D4) + the quick-wins batch**`LogAudit` error handling (`admin/handlers_backup.go`), contradictory upload `Cache-Control` (`upload_handler.go`), hub inline settings SQL through the data layer (`ws/hub.go`), Hub constructor cleanup (required collaborators into `NewHub`). | **Implemented 2026-07-19** (all four quick wins + D4). Hub cleanup shipped as: race fix — `eventPersister`/`eventStore`/`pluginSink` are now atomic (they were plain fields written by `main.go` after `NewRouter` had already started `Run`); remaining pre-Run setters now reject late calls with an error log instead of racing silently. Note discovered during the work: the discarded-`LogAudit` pattern is repo-wide (23 call sites) — the two tracker-flagged backup handlers are fixed; whether best-effort audit writes stay the convention elsewhere needs a policy decision. |
| D9 | Repo-wide `LogAudit` error-handling policy (the open question the D8 note flagged) | backlog §6 / D8 | **Decided 2026-07-20:** audit writes stay **best-effort** — a `LogAudit` failure must never fail or abort the request — but a failed write must never be silently discarded either. Every call site routes through one small shared helper that logs the failure with request context (actor/action/target). Not a blanket "make audit failures fatal": the request path is unchanged, only the silent `_ =` discard is removed. | **Implemented 2026-07-20:** `db.WriteAudit(auditor, actor, action, targetType, targetID, detail)` helper added in `db/audit.go` (structural `Auditor` interface — both `*db.DB` and the service-layer `Store` satisfy it, so api/admin/ws/service all reach it without an import cycle). All ~26 `LogAudit` call sites converted from `_ = LogAudit(...)` (and the two backup handlers' inline `if err` blocks) to `db.WriteAudit`; the `detail` string is deliberately not logged (may be sensitive). Pinned by `db/audit_test.go`: failure is logged and never propagated, success logs nothing, detail never leaks. |
## Suggested sequencing