From b085815f7c1ad693b1bdae72e420d49a5c0ba7da Mon Sep 17 00:00:00 2001 From: Cemal Kilic Date: Wed, 23 Jul 2025 14:30:38 +0300 Subject: [PATCH] feat: log all audit events separately to prevent missing events --- internal/models/audit_log_entry.go | 34 ++++++++++++++++++++++++++++++ 1 file changed, 34 insertions(+) diff --git a/internal/models/audit_log_entry.go b/internal/models/audit_log_entry.go index 153a8345b2..22d1b8049b 100644 --- a/internal/models/audit_log_entry.go +++ b/internal/models/audit_log_entry.go @@ -6,12 +6,15 @@ import ( "net/http" "time" + "maps" + "github.com/gofrs/uuid" "github.com/pkg/errors" "github.com/sirupsen/logrus" "github.com/supabase/auth/internal/conf" "github.com/supabase/auth/internal/observability" "github.com/supabase/auth/internal/storage" + "github.com/supabase/auth/internal/utilities" ) type AuditAction string @@ -120,6 +123,37 @@ func NewAuditLogEntry(config conf.AuditLogConfiguration, r *http.Request, tx *st "auth_event": logrus.Fields(payload), }) + // AUDIT LOGGING FIX: Log each audit event immediately as a separate log entry + // + // BUG: The observability.LogEntrySetFields() above adds to request context, causing + // multiple audit events in the same request to overwrite each other. For example, + // refresh token requests call NewAuditLogEntry() twice (token_refreshed, then + // token_revoked) but only the last event (token_revoked) was logged. + // + // SOLUTION: Create immediate separate log entries with "auth_audit_event" key. + // This ensures all audit events are captured without overwriting. + // + // TRANSITION: We keep the existing "auth_event" for backward compatibility during + // the transition period. This fix may impact metrics that count audit events, + // as previously missing events (like token_refreshed) will now appear in logs. + // Eventually, we should remove the observability.LogEntrySetFields() call above + // once new logging is proven stable. + auditLogPayload := make(map[string]interface{}) + maps.Copy(auditLogPayload, payload) + auditLogPayload["audit_log_id"] = id + auditLogPayload["ip_address"] = ipAddress + auditLogPayload["created_at"] = time.Now().UTC() + + if requestID := utilities.GetRequestID(r.Context()); requestID != "" { + auditLogPayload["request_id"] = requestID + } + if userAgent := r.Header.Get("User-Agent"); userAgent != "" { + auditLogPayload["user_agent"] = userAgent + } + logrus.WithFields(logrus.Fields{ + "auth_audit_event": auditLogPayload, + }).Info("audit_event") + if config.DisablePostgres { return nil }