don't create slog.Record if logging is disabled at the requested level

consistent output formatting in `dumpLogHandlerError()`

internal/log/logger.go

@@ -2,6 +2,7 @@ package log
 
 import (
 	"context"
+	"encoding/json"
 	"fmt"
 	"log/slog"
 	"os"
@@ -39,9 +40,9 @@ type Logger struct {
 
 // Info logs a message at INFO level with the specified message and attributes.
 func (l *Logger) Info(msg string, kvs ...any) {
-	rec := getLogRecord(slog.LevelInfo, msg, kvs...)
 	ctx, h := context.Background(), l.logger.Handler()
-	if h.Enabled(ctx, rec.Level) {
+	if h.Enabled(ctx, slog.LevelInfo) {
+		rec := getLogRecord(slog.LevelInfo, msg, kvs...)
 		if err := h.Handle(context.Background(), rec); err != nil {
 			dumpLogHandlerError(err, rec)
 		}
@@ -50,9 +51,9 @@ func (l *Logger) Info(msg string, kvs ...any) {
 
 // Debug logs a message at DEBUG level with the specified message and attributes.
 func (l *Logger) Debug(msg string, kvs ...any) {
-	rec := getLogRecord(slog.LevelDebug, msg, kvs...)
 	ctx, h := context.Background(), l.logger.Handler()
-	if h.Enabled(ctx, rec.Level) {
+	if h.Enabled(ctx, slog.LevelDebug) {
+		rec := getLogRecord(slog.LevelDebug, msg, kvs...)
 		if err := h.Handle(context.Background(), rec); err != nil {
 			dumpLogHandlerError(err, rec)
 		}
@@ -62,12 +63,12 @@ func (l *Logger) Debug(msg string, kvs ...any) {
 // Error logs a message at ERROR level with the specified message and attributes.  If [err] is not nil,
 // it will be logged in an additional attribute called "err".
 func (l *Logger) Error(err error, msg string, kvs ...any) {
-	rec := getLogRecord(slog.LevelError, msg, kvs...)
-	if err != nil {
-		rec.Add(slog.String("err", err.Error()))
-	}
 	ctx, h := context.Background(), l.logger.Handler()
-	if h.Enabled(ctx, rec.Level) {
+	if h.Enabled(ctx, slog.LevelError) {
+		rec := getLogRecord(slog.LevelError, msg, kvs...)
+		if err != nil {
+			rec.Add(slog.String("err", err.Error()))
+		}
 		if err := h.Handle(context.Background(), rec); err != nil {
 			dumpLogHandlerError(err, rec)
 		}
@@ -140,15 +141,42 @@ func dumpLogHandlerError(err error, rec slog.Record) {
 		return true
 	})
 	// generate a JSON "log" if we're running in k8s, logfmt style k/v pairs otherwise
+	logData := map[string]string{
+		"time":        rec.Time.Format(time.RFC3339),
+		"level":       "ERROR",
+		"source":      source,
+		"msg":         "failure invoking slog.Handler.Handle()",
+		"originalMsg": rec.Message,
+		"error":       err.Error(),
+	}
 	if inK8S() {
-		_, _ = fmt.Fprintf(
-			os.Stderr,
-			`{"time":%q, "level":"ERROR","source":%q,"msg":"failure invoking slog.Handler.Handle()","originalMsg":%q,"error":%q}`,
-			rec.Time.Format(time.RFC3339), source, rec.Message, err.Error())
+		output, _ := json.Marshal(logData)
+		_, _ = os.Stderr.Write(output)
 	} else {
-		_, _ = fmt.Fprintf(
-			os.Stderr,
-			`time=%s level=ERROR source=%s msg="failure invoking slog.Handler.Handle()" original_msg=%q error=%q`,
-			rec.Time.Format(time.RFC3339), source, rec.Message, err.Error())
+		// output keys in an explicit order for consistency
+		var (
+			sb   strings.Builder
+			keys = []string{"time", "level", "source", "msg", "orginalMsg", "error"}
+		)
+		for i, k := range keys {
+			if i > 0 {
+				sb.WriteRune(' ')
+			}
+			v := logData[k]
+			// use snake-case instead of Pascal case for logfmt output
+			if k == "originalMsg" {
+				k = "original_msg"
+			}
+			sb.WriteString(k + "=")
+			switch k {
+			case "time", "level", "source":
+				// these keys won't have embedded quotes or backslashes
+				sb.WriteString(v)
+			default:
+				sb.WriteString("\"" + strings.ReplaceAll(v, "\"", "\\\"") + "\"")
+			}
+		}
+		_, _ = os.Stderr.WriteString(sb.String())
 	}
+	_, _ = os.Stderr.WriteString("\n")
 }