feat: log all audit events separately to prevent missing events (#2086)

## Problem
The `observability.LogEntrySetFields()` 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.

## Example log output:

```sh
{"auth_audit_event":{"action":"token_refreshed","actor_id":"2670aa55-6f6f-465b-a749-2e75f61e1e8a","actor_username":"","actor_via_sso":false,"audit_log_id":"3e07849b-1784-451b-af99-1fbd455681e7","created_at":"2025-07-23T13:34:29.88400603Z","ip_address":"","log_type":"token","request_id":"3bd2f2fd-8b2a-434f-93da-656c9083762b","user_agent":"insomnia/11.1.0"},"level":"info","msg":"audit_event","time":"2025-07-23T13:34:29Z"}
{"auth_audit_event":{"action":"token_revoked","actor_id":"2670aa55-6f6f-465b-a749-2e75f61e1e8a","actor_username":"","actor_via_sso":false,"audit_log_id":"9dd3621b-9fd2-4e1d-a3a6-2236a16653c8","created_at":"2025-07-23T13:34:29.886232214Z","ip_address":"","log_type":"token","request_id":"3bd2f2fd-8b2a-434f-93da-656c9083762b","user_agent":"insomnia/11.1.0"},"level":"info","msg":"audit_event","time":"2025-07-23T13:34:29Z"}
{"action":"login","instance_id":"00000000-0000-0000-0000-000000000000","level":"info","login_method":"token","metering":true,"msg":"Login","time":"2025-07-23T13:34:29Z","user_id":"2670aa55-6f6f-465b-a749-2e75f61e1e8a"}
{"auth_event":{"action":"token_revoked","actor_id":"2670aa55-6f6f-465b-a749-2e75f61e1e8a","actor_username":"","actor_via_sso":false,"log_type":"token"},"component":"api","duration":21772353,"grant_type":"refresh_token","level":"info","method":"POST","msg":"request completed","path":"/token","referer":"http://localhost:3000","remote_addr":"192.168.117.1","request_id":"3bd2f2fd-8b2a-434f-93da-656c9083762b","status":200,"time":"2025-07-23T13:34:29Z"}
```

The first two are the _new_ audit events(added with this PR), the third
is the login metric and the last one was the request logging (containing
the only last audit event). Eventually, we're going to remove the audit
event from the request log (the last one)

Author: cemalkilic

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
 	}