From f33c2e18af7108a9f7c33a59b34387921cab6634 Mon Sep 17 00:00:00 2001 From: mkelvers Date: Sat, 23 May 2026 18:06:35 +0200 Subject: [PATCH] refactor: emit structured json logs --- integrations/jikan/client.go | 48 ++++++++++++++++++------------ internal/observability/log.go | 51 ++++++++++++++++++++++++++++++++ internal/server/observability.go | 30 +++++++++++-------- internal/server/server_test.go | 7 +++-- 4 files changed, 102 insertions(+), 34 deletions(-) create mode 100644 internal/observability/log.go diff --git a/integrations/jikan/client.go b/integrations/jikan/client.go index 69a774f..c381127 100644 --- a/integrations/jikan/client.go +++ b/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( - "jikan_cache key=%s source=%s duration_ms=%.2f error=%s", - strconv.Quote(cacheKey), - source, - float64(duration.Microseconds())/1000, - strconv.Quote(errorValue), + observability.LogJSON( + level, + "jikan_cache", + "jikan", + "", + 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 := "" - if err != nil { - errorValue = err.Error() + level := observability.LogLevelInfo + if err != nil || statusCode >= http.StatusBadRequest { + level = observability.LogLevelError } - log.Printf( - "jikan_upstream url=%s status=%d attempts=%d duration_ms=%.2f error=%s", - strconv.Quote(urlStr), - statusCode, - attempts, - float64(duration.Microseconds())/1000, - strconv.Quote(errorValue), + observability.LogJSON( + level, + "jikan_upstream", + "jikan", + "", + map[string]any{ + "url": urlStr, + "endpoint": metricsEndpoint(urlStr), + "status": statusCode, + "attempts": attempts, + "duration_ms": float64(duration.Microseconds()) / 1000, + }, + err, ) } diff --git a/internal/observability/log.go b/internal/observability/log.go new file mode 100644 index 0000000..ab30209 --- /dev/null +++ b/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)) +} diff --git a/internal/server/observability.go b/internal/server/observability.go index 86d3fa4..13d726c 100644 --- a/internal/server/observability.go +++ b/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( - "http_request method=%s route=%s path=%s query=%s status=%d duration_ms=%.2f bytes=%d client_ip=%s errors=%s", - c.Request.Method, - strconv.Quote(route), - strconv.Quote(path), - strconv.Quote(query), - c.Writer.Status(), - float64(duration.Microseconds())/1000, - c.Writer.Size(), - strconv.Quote(c.ClientIP()), - strconv.Quote(c.Errors.ByType(gin.ErrorTypePrivate).String()), + observability.LogJSON( + observability.LogLevelInfo, + "http_request", + "http", + "", + map[string]any{ + "method": c.Request.Method, + "route": route, + "path": path, + "query": query, + "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, ) } } diff --git a/internal/server/server_test.go b/internal/server/server_test.go index 8b20078..76153ba 100644 --- a/internal/server/server_test.go +++ b/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) } }