backend: format slog durations as human friendly string

Author: weeco

backend/pkg/logger/logger.go

@@ -90,25 +90,26 @@ func createHandler(cfg *config) slog.Handler {
 		Level: cfg.level,
 	}
 
-	// If custom timestamp format is specified, use ReplaceAttr to customize the time field
-	if cfg.timestampFormat != "" {
-		handlerOpts.ReplaceAttr = func(_ []string, a slog.Attr) slog.Attr {
-			if a.Key == slog.TimeKey {
-				return formatTimestamp(a, cfg.timestampFormat)
-			}
-			return a
+	// Use ReplaceAttr to customize attribute formatting:
+	// - Durations are formatted as human-readable strings (e.g., "6h0m0s")
+	// - Timestamps use custom format if specified
+	handlerOpts.ReplaceAttr = func(_ []string, a slog.Attr) slog.Attr {
+		// Format durations as human-readable strings instead of nanoseconds
+		if a.Value.Kind() == slog.KindDuration {
+			return slog.String(a.Key, a.Value.Duration().String())
 		}
+		// Format timestamps if custom format is specified
+		if cfg.timestampFormat != "" && a.Key == slog.TimeKey {
+			return formatTimestamp(a, cfg.timestampFormat)
+		}
+		return a
 	}
 
-	// Create handler based on format
-	switch cfg.format {
-	case FormatText:
+	// Create handler based on format (default is JSON)
+	if cfg.format == FormatText {
 		return slog.NewTextHandler(cfg.output, handlerOpts)
-	case FormatJSON:
-		return slog.NewJSONHandler(cfg.output, handlerOpts)
-	default:
-		return slog.NewJSONHandler(cfg.output, handlerOpts)
 	}
+	return slog.NewJSONHandler(cfg.output, handlerOpts)
 }
 
 // formatTimestamp formats a time attribute according to the specified format.

backend/pkg/logger/logger_test.go

@@ -16,6 +16,7 @@ import (
 	"log/slog"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
@@ -345,3 +346,66 @@ func TestFormatOverride(t *testing.T) {
 		})
 	}
 }
+
+func TestDurationFormatting(t *testing.T) {
+	tests := []struct {
+		name           string
+		duration       time.Duration
+		expectedString string
+	}{
+		{
+			name:           "hours",
+			duration:       6 * time.Hour,
+			expectedString: "6h0m0s",
+		},
+		{
+			name:           "minutes and seconds",
+			duration:       5*time.Minute + 30*time.Second,
+			expectedString: "5m30s",
+		},
+		{
+			name:           "milliseconds",
+			duration:       150 * time.Millisecond,
+			expectedString: "150ms",
+		},
+		{
+			name:           "complex duration",
+			duration:       2*time.Hour + 30*time.Minute + 45*time.Second,
+			expectedString: "2h30m45s",
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			var buf bytes.Buffer
+			logger := NewSlogLogger(
+				WithOutput(&buf),
+				WithFormat(FormatJSON),
+			)
+
+			logger.Info("test message", slog.Duration("duration", tt.duration))
+
+			// Parse the JSON output
+			var logEntry map[string]any
+			err := json.Unmarshal(buf.Bytes(), &logEntry)
+			require.NoError(t, err)
+
+			// Duration should be formatted as human-readable string, not nanoseconds
+			assert.Equal(t, tt.expectedString, logEntry["duration"], "duration should be human-readable")
+		})
+	}
+}
+
+func TestDurationFormattingTextFormat(t *testing.T) {
+	var buf bytes.Buffer
+	logger := NewSlogLogger(
+		WithOutput(&buf),
+		WithFormat(FormatText),
+	)
+
+	logger.Info("test message", slog.Duration("duration", 6*time.Hour))
+
+	output := buf.String()
+	// Text format should also show human-readable duration
+	assert.Contains(t, output, "duration=6h0m0s")
+}