refactor after code review

coder · ibetitsmike · Apr 8, 2025 · Apr 2, 2025 · Apr 2, 2025 · Apr 2, 2025
commit 81e15279c80e9e3e81bc22ebcc011500bc8aee07
diff --git a/coderd/httpmw/logger.go b/coderd/httpmw/logger.go
@@ -54,11 +54,7 @@ func Logger(log slog.Logger) func(next http.Handler) http.Handler {
 				)
 			}
 
-			// We already capture most of this information in the span (minus
-			// the response body which we don't want to capture anyways).
-			tracing.RunWithoutSpan(r.Context(), func(ctx context.Context) {
-				logContext.WriteLog(ctx, sw.Status)
-			})
+			logContext.WriteLog(r.Context(), sw.Status)
 		})
 	}
 }
@@ -68,27 +64,29 @@ type RequestLogger interface {
 	WriteLog(ctx context.Context, status int)
 }
 
-type RequestContextLogger struct {
+type SlogRequestLogger struct {
 	log     slog.Logger
 	written bool
 	message string
 	start   time.Time
 }
 
+var _ RequestLogger = &SlogRequestLogger{}
+
 func NewRequestLogger(log slog.Logger, message string, start time.Time) RequestLogger {
-	return &RequestContextLogger{
+	return &SlogRequestLogger{
 		log:     log,
 		written: false,
 		message: message,
 		start:   start,
 	}
 }
 
-func (c *RequestContextLogger) WithFields(fields ...slog.Field) {
+func (c *SlogRequestLogger) WithFields(fields ...slog.Field) {
 	c.log = c.log.With(fields...)
 }
 
-func (c *RequestContextLogger) WriteLog(ctx context.Context, status int) {
+func (c *SlogRequestLogger) WriteLog(ctx context.Context, status int) {
 	if c.written {
 		return
 	}
@@ -100,14 +98,18 @@ func (c *RequestContextLogger) WriteLog(ctx context.Context, status int) {
 		slog.F("status_code", status),
 		slog.F("latency_ms", float64(end.Sub(c.start)/time.Millisecond)),
 	)
-	// We should not log at level ERROR for 5xx status codes because 5xx
-	// includes proxy errors etc. It also causes slogtest to fail
-	// instantly without an error message by default.
-	if status >= http.StatusInternalServerError {
-		logger.Warn(ctx, c.message)
-	} else {
-		logger.Debug(ctx, c.message)
-	}
+	// 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) {
+		// We should not log at level ERROR for 5xx status codes because 5xx
+		// includes proxy errors etc. It also causes slogtest to fail
+		// instantly without an error message by default.
+		if status >= http.StatusInternalServerError {
+			logger.Warn(ctx, c.message)
+		} else {
+			logger.Debug(ctx, c.message)
+		}
+	})
 }
 
 type logContextKey struct{}

diff --git a/coderd/httpmw/logger_internal_test.go b/coderd/httpmw/logger_internal_test.go
@@ -8,6 +8,8 @@ import (
 	"testing"
 	"time"
 
+	"github.com/stretchr/testify/require"
+
 	"cdr.dev/slog"
 	"github.com/coder/coder/v2/coderd/tracing"
 	"github.com/coder/coder/v2/testutil"
@@ -31,24 +33,16 @@ func TestRequestLogger_WriteLog(t *testing.T) {
 	// Write log for 200 status
 	logCtx.WriteLog(ctx, http.StatusOK)
 
-	if len(sink.entries) != 1 {
-		t.Fatalf("expected 1 log entry, got %d", len(sink.entries))
-	}
+	require.Len(t, sink.entries, 1, "log was written twice")
 
-	if sink.entries[0].Message != "GET" {
-		t.Errorf("expected log message to be 'GET', got '%s'", sink.entries[0].Message)
-	}
+	require.Equal(t, sink.entries[0].Message, "GET", "log message should be GET")
 
-	if sink.entries[0].Fields[0].Value != "custom_value" {
-		t.Errorf("expected a custom_field with value custom_value, got '%s'", sink.entries[0].Fields[0].Value)
-	}
+	require.Equal(t, sink.entries[0].Fields[0].Value, "custom_value", "custom_field should be custom_value")
 
 	// Attempt to write again (should be skipped).
 	logCtx.WriteLog(ctx, http.StatusInternalServerError)
 
-	if len(sink.entries) != 1 {
-		t.Fatalf("expected 1 log entry after second write, got %d", len(sink.entries))
-	}
+	require.Len(t, sink.entries, 1, "log was written twice")
 }
 
 func TestLoggerMiddleware_SingleRequest(t *testing.T) {
@@ -79,13 +73,9 @@ func TestLoggerMiddleware_SingleRequest(t *testing.T) {
 	// Serve the request
 	wrappedHandler.ServeHTTP(sw, req)
 
-	if len(sink.entries) != 1 {
-		t.Fatalf("expected 1 log entry, got %d", len(sink.entries))
-	}
+	require.Len(t, sink.entries, 1, "log was written twice")
 
-	if sink.entries[0].Message != "GET" {
-		t.Errorf("expected log message to be 'GET', got '%s'", sink.entries[0].Message)
-	}
+	require.Equal(t, sink.entries[0].Message, "GET", "log message should be GET")
 }
 
 func TestLoggerMiddleware_WebSocket(t *testing.T) {
@@ -134,13 +124,9 @@ func TestLoggerMiddleware_WebSocket(t *testing.T) {
 	}
 	defer conn.Close(websocket.StatusNormalClosure, "")
 	wg.Wait()
-	if len(sink.entries) != 1 {
-		t.Fatalf("expected 1 log entry, got %d", len(sink.entries))
-	}
+	require.Len(t, sink.entries, 1, "log was written twice")
 
-	if sink.entries[0].Message != "GET" {
-		t.Errorf("expected log message to be 'GET', got '%s'", sink.entries[0].Message)
-	}
+	require.Equal(t, sink.entries[0].Message, "GET", "log message should be GET")
 }
 
 type fakeSink struct {