made smarter logging of authentication context

ibetitsmike · ibetitsmike · commit d38277ffd105 · 2025-04-10T13:24:09.000Z
diff --git a/coderd/database/dbauthz/dbauthz.go b/coderd/database/dbauthz/dbauthz.go
@@ -476,7 +476,7 @@ func As(ctx context.Context, actor rbac.Subject) context.Context {
 
 func InjectActorToContext(ctx context.Context, actor rbac.Subject) context.Context {
 	if rlogger := loggermw.RequestLoggerFromContext(ctx); rlogger != nil {
-		rlogger.WithAuthContext(actor.ID, actor.FriendlyName, actor.Email)
+		rlogger.WithAuthContext(actor.ID, actor.FriendlyName, actor.Email, actor.Type)
 	}
 	return context.WithValue(ctx, authContextKey{}, actor)
 }
diff --git a/coderd/httpmw/loggermw/logger.go b/coderd/httpmw/loggermw/logger.go
@@ -8,6 +8,7 @@ import (
 
 	"cdr.dev/slog"
 	"github.com/coder/coder/v2/coderd/httpapi"
+	"github.com/coder/coder/v2/coderd/rbac"
 	"github.com/coder/coder/v2/coderd/tracing"
 )
 
@@ -62,48 +63,60 @@ func Logger(log slog.Logger) func(next http.Handler) http.Handler {
 type RequestLogger interface {
 	WithFields(fields ...slog.Field)
 	WriteLog(ctx context.Context, status int)
-	WithAuthContext(id string, name string, email string)
+	WithAuthContext(id string, name string, email string, subjectType rbac.SubjectType)
 }
 
 type SlogRequestLogger struct {
-	log            slog.Logger
-	written        bool
-	message        string
-	authCtxPresent bool
-	start          time.Time
+	log     slog.Logger
+	written bool
+	message string
+	start   time.Time
+	authCtx map[rbac.SubjectType]authContext
+}
+
+type authContext struct {
+	id          string
+	name        string
+	email       string
+	subjectType rbac.SubjectType
 }
 
 var _ RequestLogger = &SlogRequestLogger{}
 
 func NewRequestLogger(log slog.Logger, message string, start time.Time) RequestLogger {
 	return &SlogRequestLogger{
-		log:            log,
-		written:        false,
-		message:        message,
-		start:          start,
-		authCtxPresent: false,
+		log:     log,
+		written: false,
+		message: message,
+		start:   start,
+		authCtx: make(map[rbac.SubjectType]authContext),
 	}
 }
 
 func (c *SlogRequestLogger) WithFields(fields ...slog.Field) {
 	c.log = c.log.With(fields...)
 }
 
-func (c *SlogRequestLogger) WithAuthContext(id string, name string, email string) {
-	// If the email is empty, we don't want to log the requestor context,
-	// because it's an elevated privilege.
-	if email == "" || id == "" {
-		return
-	}
-	if c.authCtxPresent {
-		return
+func (c *SlogRequestLogger) WithAuthContext(id string, name string, email string, subjectType rbac.SubjectType) {
+	c.authCtx[subjectType] = authContext{id, name, email, subjectType}
+}
+
+func (c *SlogRequestLogger) addAuthContextFields() {
+	usr, ok := c.authCtx[rbac.SubjectTypeUser]
+	if ok {
+		c.log = c.log.With(
+			slog.F("requestor_id", usr.id),
+			slog.F("requestor_name", usr.name),
+			slog.F("requestor_email", usr.email),
+		)
+	} else if len(c.authCtx) > 0 {
+		for _, v := range c.authCtx {
+			c.log = c.log.With(
+				slog.F("requestor_name", v.name),
+			)
+			break
+		}
 	}
-	c.authCtxPresent = true
-	c.log = c.log.With(
-		slog.F("requestor_id", id),
-		slog.F("requestor_name", name),
-		slog.F("requestor_email", email),
-	)
 }
 
 func (c *SlogRequestLogger) WriteLog(ctx context.Context, status int) {
@@ -113,11 +126,16 @@ func (c *SlogRequestLogger) WriteLog(ctx context.Context, status int) {
 	c.written = true
 	end := time.Now()
 
+	// Right before we write the log, we try to find the user in the authCtx
+	// and add the fields to the log.
+	c.addAuthContextFields()
+
 	logger := c.log.With(
 		slog.F("took", end.Sub(c.start)),
 		slog.F("status_code", status),
 		slog.F("latency_ms", float64(end.Sub(c.start)/time.Millisecond)),
 	)
+
 	// We already capture most of this information in the span (minus
 	// the response body which we don't want to capture anyways).
 	tracing.RunWithoutSpan(ctx, func(ctx context.Context) {
diff --git a/coderd/httpmw/loggermw/loggermock/loggermock.go b/coderd/httpmw/loggermw/loggermock/loggermock.go

Original file line number	Diff line number	Diff line change
`@@ -476,7 +476,7 @@ func As(ctx context.Context, actor rbac.Subject) context.Context {`
`476`	`476`
`477`	`477`	`func InjectActorToContext(ctx context.Context, actor rbac.Subject) context.Context {`
`478`	`478`	`if rlogger := loggermw.RequestLoggerFromContext(ctx); rlogger != nil {`
`479`		`- rlogger.WithAuthContext(actor.ID, actor.FriendlyName, actor.Email)`
	`479`	`+ rlogger.WithAuthContext(actor.ID, actor.FriendlyName, actor.Email, actor.Type)`
`480`	`480`	`}`
`481`	`481`	`return context.WithValue(ctx, authContextKey{}, actor)`
`482`	`482`	`}`