refactor: emit structured json logs

integrations/jikan/client.go

@@ -5,7 +5,6 @@ import (
 	"encoding/json"
 	"errors"
 	"fmt"
-	"log"
 	"net"
 	"net/http"
 	"os"
@@ -156,17 +155,22 @@ func logJikanCache(cacheKey string, source string, startedAt time.Time, err erro
 		return
 	}
 
-	errorValue := ""
+	level := observability.LogLevelInfo
 	if err != nil {
-		errorValue = err.Error()
+		level = observability.LogLevelError
 	}
 
-	log.Printf(
+	observability.LogJSON(
-		"jikan_cache key=%s source=%s duration_ms=%.2f error=%s",
+		level,
-		strconv.Quote(cacheKey),
+		"jikan_cache",
-		source,
+		"jikan",
-		float64(duration.Microseconds())/1000,
+		"",
-		strconv.Quote(errorValue),
+		map[string]any{
+			"cache_key":   cacheKey,
+			"source":      source,
+			"duration_ms": float64(duration.Microseconds()) / 1000,
+		},
+		err,
 	)
 }
 
@@ -176,18 +180,24 @@ func logJikanUpstream(urlStr string, statusCode int, attempts int, startedAt tim
 		return
 	}
 
-	errorValue := ""
+	level := observability.LogLevelInfo
-	if err != nil {
+	if err != nil || statusCode >= http.StatusBadRequest {
-		errorValue = err.Error()
+		level = observability.LogLevelError
 	}
 
-	log.Printf(
+	observability.LogJSON(
-		"jikan_upstream url=%s status=%d attempts=%d duration_ms=%.2f error=%s",
+		level,
-		strconv.Quote(urlStr),
+		"jikan_upstream",
-		statusCode,
+		"jikan",
-		attempts,
+		"",
-		float64(duration.Microseconds())/1000,
+		map[string]any{
-		strconv.Quote(errorValue),
+			"url":         urlStr,
+			"endpoint":    metricsEndpoint(urlStr),
+			"status":      statusCode,
+			"attempts":    attempts,
+			"duration_ms": float64(duration.Microseconds()) / 1000,
+		},
+		err,
 	)
 }
 

internal/observability/log.go

@@ -0,0 +1,51 @@
+package observability
+
+import (
+	"encoding/json"
+	"log"
+	"time"
+)
+
+type LogLevel string
+
+const (
+	LogLevelInfo  LogLevel = "info"
+	LogLevelWarn  LogLevel = "warn"
+	LogLevelError LogLevel = "error"
+)
+
+type LogEvent struct {
+	TS        string         `json:"ts"`
+	Level     LogLevel       `json:"level"`
+	Event     string         `json:"event"`
+	Message   string         `json:"message,omitempty"`
+	Fields    map[string]any `json:"fields,omitempty"`
+	Error     string         `json:"error,omitempty"`
+	Component string         `json:"component,omitempty"`
+}
+
+func LogJSON(level LogLevel, event string, component string, message string, fields map[string]any, err error) {
+	errorValue := ""
+	if err != nil {
+		errorValue = err.Error()
+	}
+
+	entry := LogEvent{
+		TS:        time.Now().UTC().Format(time.RFC3339Nano),
+		Level:     level,
+		Event:     event,
+		Message:   message,
+		Fields:    fields,
+		Error:     errorValue,
+		Component: component,
+	}
+
+	// Best-effort. If encoding fails, fall back to a minimal line.
+	bytes, marshalErr := json.Marshal(entry)
+	if marshalErr != nil {
+		log.Printf("level=%s event=%s component=%s error=%q", level, event, component, marshalErr.Error())
+		return
+	}
+
+	log.Print(string(bytes))
+}

internal/server/observability.go

@@ -1,9 +1,7 @@
 package server
 
 import (
-	"log"
 	"mal/internal/observability"
-	"strconv"
 	"time"
 
 	"github.com/gin-gonic/gin"
@@ -25,17 +23,23 @@ func RequestLogger(metrics *observability.Metrics) gin.HandlerFunc {
 		duration := time.Since(start)
 		metrics.ObserveHTTPRequest(c.Request.Method, route, c.Writer.Status(), duration)
 
-		log.Printf(
+		observability.LogJSON(
-			"http_request method=%s route=%s path=%s query=%s status=%d duration_ms=%.2f bytes=%d client_ip=%s errors=%s",
+			observability.LogLevelInfo,
-			c.Request.Method,
+			"http_request",
-			strconv.Quote(route),
+			"http",
-			strconv.Quote(path),
+			"",
-			strconv.Quote(query),
+			map[string]any{
-			c.Writer.Status(),
+				"method":      c.Request.Method,
-			float64(duration.Microseconds())/1000,
+				"route":       route,
-			c.Writer.Size(),
+				"path":        path,
-			strconv.Quote(c.ClientIP()),
+				"query":       query,
-			strconv.Quote(c.Errors.ByType(gin.ErrorTypePrivate).String()),
+				"status":      c.Writer.Status(),
+				"duration_ms": float64(duration.Microseconds()) / 1000,
+				"bytes":       c.Writer.Size(),
+				"client_ip":   c.ClientIP(),
+				"errors":      c.Errors.ByType(gin.ErrorTypePrivate).String(),
+			},
+			nil,
 		)
 	}
 }

internal/server/server_test.go

@@ -58,10 +58,13 @@ func TestRequestLoggerUsesMatchedRoute(t *testing.T) {
 	}
 
 	logLine := string(output)
-	if !strings.Contains(logLine, `route="/anime/:id"`) {
+	if !strings.Contains(logLine, `"event":"http_request"`) {
+		t.Fatalf("log line missing event: %s", logLine)
+	}
+	if !strings.Contains(logLine, `"route":"/anime/:id"`) {
 		t.Fatalf("log line missing route: %s", logLine)
 	}
-	if !strings.Contains(logLine, `status=200`) {
+	if !strings.Contains(logLine, `"status":200`) {
 		t.Fatalf("log line missing status: %s", logLine)
 	}
 }