Skip to content

Commit

Permalink
WIP feat: migrate from zerolog to slog
Browse files Browse the repository at this point in the history
  • Loading branch information
kernle32dll committed Apr 21, 2024
1 parent 8a74032 commit 5e02ffc
Show file tree
Hide file tree
Showing 8 changed files with 102 additions and 57 deletions.
25 changes: 19 additions & 6 deletions auth.go
Original file line number Diff line number Diff line change
@@ -1,16 +1,17 @@
package turtleware

import (
"github.com/go-logr/logr"
"github.com/kernle32dll/keybox-go"
"github.com/lestrrat-go/jwx/v2/jwa"
"github.com/lestrrat-go/jwx/v2/jwk"
"github.com/lestrrat-go/jwx/v2/jwt"
"github.com/rs/zerolog"

"context"
"crypto"
"errors"
"fmt"
"log/slog"
"net/http"
"os"
"path/filepath"
Expand Down Expand Up @@ -45,7 +46,7 @@ var (
func ReadKeySetFromFolder(ctx context.Context, path string) (jwk.Set, error) {
set := jwk.NewSet()

logger := zerolog.Ctx(ctx)
logger := slog.New(logr.ToSlogHandler(logr.FromContextOrDiscard(ctx)))

if err := filepath.Walk(path,
func(path string, info os.FileInfo, err error) error {
Expand All @@ -58,23 +59,35 @@ func ReadKeySetFromFolder(ctx context.Context, path string) (jwk.Set, error) {
}

if !info.IsDir() {
logger.Debug().Msgf("Reading %s for public key", path)
logger.DebugContext(ctx, fmt.Sprintf("Reading %q for public key", path))

parseResult, err := keybox.LoadPublicKey(path)
if err != nil {
logger.Error().Err(err).Msgf("Failed to load %s as public key", path)
logger.ErrorContext(
ctx,
fmt.Sprintf("Failed to load %q as public key", path),
slog.Any("error", err),
)
return nil
}

kid := strings.TrimRight(info.Name(), filepath.Ext(info.Name()))
key, err := JWKFromPublicKey(parseResult, kid)
if err != nil {
logger.Error().Err(err).Msgf("Failed to parse %s as JWK", path)
logger.ErrorContext(
ctx,
fmt.Sprintf("Failed to parse %q as JWK", path),
slog.Any("error", err),
)
return nil
}

if err := set.AddKey(key); err != nil {
logger.Error().Err(err).Msgf("Failed to add %s to key set", path)
logger.ErrorContext(
ctx,
fmt.Sprintf("Failed to add %q to key set", path),
slog.Any("error", err),
)
return nil
}
}
Expand Down
12 changes: 10 additions & 2 deletions cache.go
Original file line number Diff line number Diff line change
@@ -1,8 +1,10 @@
package turtleware

import (
"github.com/rs/zerolog"
"github.com/go-logr/logr"

"fmt"
"log/slog"
"net/http"
"time"
)
Expand All @@ -18,7 +20,13 @@ func ExtractCacheHeader(r *http.Request) (string, time.Time) {
if lastModifiedHeader != "" {
parsedTime, err := time.Parse(time.RFC1123, lastModifiedHeader)
if err != nil {
zerolog.Ctx(r.Context()).Warn().Err(err).Msgf("Received If-Modified-Since header in invalid format: %s", lastModifiedHeader)
ctx := r.Context()
log := slog.New(logr.ToSlogHandler(logr.FromContextOrDiscard(ctx)))
log.WarnContext(
ctx,
fmt.Sprintf("Received If-Modified-Since header in invalid format: %s", lastModifiedHeader),
slog.Any("error", err),
)

return "", lastModifiedHeaderTime
}
Expand Down
31 changes: 18 additions & 13 deletions errors.go
Original file line number Diff line number Diff line change
@@ -1,11 +1,13 @@
package turtleware

import (
"github.com/rs/zerolog"
"github.com/go-logr/logr"

"context"
"encoding/xml"
"log/slog"
"net/http"
"strings"
)

type errorList []string
Expand Down Expand Up @@ -52,6 +54,11 @@ func WriteError(
code int,
errors ...error,
) {
errList := make(errorList, len(errors))
for i, err := range errors {
errList[i] = err.Error()
}

for _, err := range errors {
// nolint errcheck: Returned error is not checked, as its just err as passed in
_ = TagContextSpanWithError(ctx, err)
Expand All @@ -60,17 +67,11 @@ func WriteError(
w.Header().Set("Cache-Control", "no-store")

if r.Method != http.MethodHead {
logger := zerolog.Ctx(ctx).With().
Errs("errors", errors).
Int("error_code", code).
Logger()

logger.Warn().Msg("Writing errors")

errList := make(errorList, len(errors))
for i, err := range errors {
errList[i] = err.Error()
}
logger := slog.New(logr.ToSlogHandler(logr.FromContextOrDiscard(ctx))).With(
slog.String("error", strings.Join(errList, ", ")),
slog.Int("error_code", code),
)
logger.WarnContext(ctx, "Writing errors")

errorMap := errorResponse{
Status: code,
Expand All @@ -81,7 +82,11 @@ func WriteError(
defer func() {
if r := recover(); r != nil {
w.WriteHeader(http.StatusInternalServerError)
logger.Error().Interface("error", r).Msg("Error while marshalling error message")
logger.ErrorContext(
ctx,
"Error while marshalling error message",
slog.Any("error", r),
)
}
}()
EmissioneWriter.Write(w, r, code, errorMap)
Expand Down
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ go 1.22
toolchain go1.22.0

require (
github.com/go-logr/logr v1.4.1
github.com/google/uuid v1.6.0
github.com/jmoiron/sqlx v1.3.5
github.com/json-iterator/go v1.1.12
Expand All @@ -21,7 +22,6 @@ require (
require (
github.com/davecgh/go-spew v1.1.1 // indirect
github.com/decred/dcrd/dcrec/secp256k1/v4 v4.2.0 // indirect
github.com/go-logr/logr v1.4.1 // indirect
github.com/go-logr/stdr v1.2.2 // indirect
github.com/goccy/go-json v0.10.2 // indirect
github.com/kr/text v0.2.0 // indirect
Expand Down
5 changes: 3 additions & 2 deletions go.work.sum
Original file line number Diff line number Diff line change
@@ -1,19 +1,20 @@
github.com/coreos/go-systemd/v22 v22.5.0 h1:RrqgGjYQKalulkV8NGVIfkXQf6YYmOyiJKk8iXXhfZs=
github.com/creack/pty v1.1.9 h1:uDmaGzcdjhF4i/plgjmEsriH11Y0o7RKapEf/LDaM3w=
github.com/decred/dcrd/crypto/blake256 v1.0.1 h1:7PltbUIQB7u/FfZ39+DGa/ShuMyJ5ilcvdfma9wOH6Y=
github.com/decred/dcrd/crypto/blake256 v1.0.1/go.mod h1:2OfgNZ5wDpcsFmHmCK5gZTPcCXqlm2ArzUIkw9czNJo=
github.com/godbus/dbus/v5 v5.0.4 h1:9349emZab16e7zQvpmsbtjc18ykshndd8y2PG3sgJbA=
github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI=
github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
github.com/google/gofuzz v1.0.0 h1:A8PeW59pxE9IoFRqBp37U+mSNaQoZ46F1f0f863XSXw=
github.com/kr/pty v1.1.1 h1:VkoXIwSboBpnk99O/KFauAEILuNHv5DVFKZMBN/gUgw=
github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
github.com/rs/xid v1.4.0 h1:qd7wPTDkN6KQx2VmMBLrpHkiyQwgFXRnkOLacUiaSNY=
github.com/rs/xid v1.5.0 h1:mKX4bl4iPYJtEIxp6CYiUuLQ/8DYMoz0PUdtGgMFRVc=
github.com/stretchr/objx v0.5.0 h1:1zr/of2m5FGMsad5YfcqgdqdWrIhu+EBEJRhR1U7z/c=
github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
github.com/yuin/goldmark v1.4.13 h1:fVcFKWvrslecOb/tg+Cc05dkeYx540o0FuFt3nUVDoE=
golang.org/x/crypto v0.17.0/go.mod h1:gCAAfMLgwOJRpTjQ2zCCt2OcSfYMTeZVSRtQlPC7Nq4=
golang.org/x/mod v0.8.0 h1:LUYupSeNrTNCGzR/hVBk2NHZO4hXcVaW1k4Qx7rjPx8=
golang.org/x/net v0.10.0 h1:X2//UzNDwYmtCLn7To6G58Wr6f5ahEAQgKNzv9Y951M=
golang.org/x/net v0.10.0/go.mod h1:0qNGK6F8kojg2nk9dLZ2mShWaEBan6FAoqfSigmmuDg=
golang.org/x/sync v0.1.0 h1:wsuoTGHzEhffawBOhz5CYhcrV4IdKZbEyZjBMuTp12o=
golang.org/x/sys v0.15.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
golang.org/x/term v0.9.0 h1:GRRCnKYhdQrD8kfRAdQ6Zcw1P0OcELxGLKJvtjVMZ28=
Expand Down
23 changes: 11 additions & 12 deletions middleware_common.go
Original file line number Diff line number Diff line change
@@ -1,14 +1,14 @@
package turtleware

import (
"context"
"errors"
"github.com/go-logr/logr"
"github.com/lestrrat-go/jwx/v2/jwk"
"github.com/rs/zerolog"
"go.opentelemetry.io/otel"
"go.opentelemetry.io/otel/propagation"
"go.opentelemetry.io/otel/trace"

"context"
"errors"
"log/slog"
"net/http"
)

Expand Down Expand Up @@ -201,27 +201,26 @@ func TracingMiddleware(name string, traceProvider trace.TracerProvider) func(htt

// Fetch a zerolog logger, if already set in the context, or a fresh one
// (will be injected into the context that is passed along later down below)
logger := zerolog.Ctx(r.Context()).With().Logger()

wireCtx := propagation.TraceContext{}.Extract(
ctx := propagation.TraceContext{}.Extract(
r.Context(),
propagation.HeaderCarrier(r.Header),
)
logger := slog.New(logr.ToSlogHandler(logr.FromContextOrDiscard(ctx)))

requireResponse := false
if spanContext := trace.SpanContextFromContext(wireCtx); !spanContext.HasTraceID() && !spanContext.HasSpanID() {
if spanContext := trace.SpanContextFromContext(ctx); !spanContext.HasTraceID() && !spanContext.HasSpanID() {
requireResponse = true
logger.Trace().Msg("Missing span context")
logger.DebugContext(ctx, "Missing span context")
}

locTracer := locTraceProvider.Tracer(TracerName)
spanCtx, span := locTracer.Start(wireCtx, name)
spanCtx, span := locTracer.Start(ctx, name)
defer span.End()

// Create a logger, which contains the root span and trace,
// and inject that back into the context for root level trace logging
logger = WrapZerologTracing(spanCtx)
spanCtx = logger.WithContext(spanCtx)
logger = WrapLogTracing(spanCtx)
spanCtx = logr.NewContextWithSlogLogger(spanCtx, logger)

// ---------------------

Expand Down
44 changes: 33 additions & 11 deletions middleware_logging.go
Original file line number Diff line number Diff line change
@@ -1,9 +1,12 @@
package turtleware

import (
"github.com/go-logr/logr"
"github.com/rs/zerolog"

"errors"
"fmt"
"log/slog"
"net/http"
"strings"
"time"
Expand Down Expand Up @@ -120,19 +123,28 @@ func RequestTimingMiddleware() func(next http.Handler) http.Handler {
sw := &statusWriter{ResponseWriter: w}
next.ServeHTTP(sw, r)

logger := zerolog.Ctx(r.Context())
if debugLevel := logger.Debug(); debugLevel.Enabled() {
ctx := r.Context()
logger := slog.New(logr.ToSlogHandler(logr.FromContextOrDiscard(ctx)))
logger.WarnContext(
ctx,
fmt.Sprintf("%s request for %s was not matched", r.Method, r.URL),
slog.String("reason", "url method not allowed"),
)

if logger.Enabled(ctx, slog.LevelDebug) {
duration := time.Since(start)

// Double division, so we get appropriate precision
micros := duration / time.Microsecond
millis := float64(micros) / float64(time.Microsecond)

logger.Info().
Float64("timemillis", millis).
Int("status", sw.status).
Int("length", sw.length).
Msgf("Request took %s", duration)
logger.InfoContext(
ctx,
fmt.Sprintf("Request took %s", duration),
slog.Float64("timemillis", millis),
slog.Int("status", sw.status),
slog.Int("length", sw.length),
)
}
})
}
Expand All @@ -146,8 +158,13 @@ func RequestNotFoundHandler(opts ...LoggingOption) http.Handler {
opts...,
)(
http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
logger := zerolog.Ctx(r.Context())
logger.Warn().Str("reason", "url unmatched").Msgf("%s request for %s was not matched", r.Method, r.URL)
ctx := r.Context()
logger := slog.New(logr.ToSlogHandler(logr.FromContextOrDiscard(ctx)))
logger.WarnContext(
ctx,
fmt.Sprintf("%s request for %s was not matched", r.Method, r.URL),
slog.String("reason", "url unmatched"),
)

WriteError(r.Context(), w, r, http.StatusNotFound, errors.New("request url and method was not matched"))
}),
Expand All @@ -164,8 +181,13 @@ func RequestNotAllowedHandler(opts ...LoggingOption) http.Handler {
opts...,
)(
http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
logger := zerolog.Ctx(r.Context())
logger.Warn().Str("reason", "url method not allowed").Msgf("%s request for %s was not matched", r.Method, r.URL)
ctx := r.Context()
logger := slog.New(logr.ToSlogHandler(logr.FromContextOrDiscard(ctx)))
logger.WarnContext(
ctx,
fmt.Sprintf("%s request for %s was not matched", r.Method, r.URL),
slog.String("reason", "url method not allowed"),
)

WriteError(r.Context(), w, r, http.StatusMethodNotAllowed, errors.New("request url was matched, but method was not allowed"))
}),
Expand Down
17 changes: 7 additions & 10 deletions tracing.go
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
package turtleware

import (
"github.com/rs/zerolog"
"github.com/go-logr/logr"
"go.opentelemetry.io/otel"
"go.opentelemetry.io/otel/attribute"
"go.opentelemetry.io/otel/codes"
Expand All @@ -11,6 +11,7 @@ import (
"context"
"errors"
"fmt"
"log/slog"
"net/http"
"strings"
)
Expand Down Expand Up @@ -98,11 +99,11 @@ func (c TracingTransport) RoundTrip(req *http.Request) (*http.Response, error) {
return resp, err
}

// WrapZerologTracing fetches the zerolog.Logger attached with the context
// WrapLogTracing fetches the slog.Logger attached with the context
// (if existing), and creates a new logger with the context's spanID and
// traceID fields set.
func WrapZerologTracing(ctx context.Context) zerolog.Logger {
logger := *zerolog.Ctx(ctx)
func WrapLogTracing(ctx context.Context) *slog.Logger {
logger := slog.New(logr.ToSlogHandler(logr.FromContextOrDiscard(ctx)))

// If there is no tracing data, we bail out directly
span := trace.SpanFromContext(ctx)
Expand All @@ -112,14 +113,10 @@ func WrapZerologTracing(ctx context.Context) zerolog.Logger {

spanContext := span.SpanContext()
if spanContext.HasTraceID() {
logger = logger.With().
Str("traceID", spanContext.TraceID().String()).
Logger()
logger = logger.With(slog.String("traceID", spanContext.TraceID().String()))
}
if spanContext.HasSpanID() {
logger = logger.With().
Str("spanID", spanContext.SpanID().String()).
Logger()
logger = logger.With(slog.String("spanID", spanContext.SpanID().String()))
}

return logger
Expand Down

0 comments on commit 5e02ffc

Please sign in to comment.