Skip to content

log/slog: Custom Handler breaks when using With() and loses parent attributes #71116

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
tamas-jozsa opened this issue Jan 3, 2025 · 6 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@tamas-jozsa
Copy link

tamas-jozsa commented Jan 3, 2025

Go version

go1.23.3 darwin/arm64

Output of go env in your module/workspace:

GO111MODULE='on'
GOARCH='arm64'
GOBIN=''
GOCACHE='/Users/tjozsa/Library/Caches/go-build'
GOENV='/Users/tjozsa/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='arm64'
GOHOSTOS='darwin'
GOINSECURE=''
GOMODCACHE='/Users/tjozsa/go/pkg/mod'
GONOPROXY=''
GONOSUMDB='code.cfops.it,github.com/cloudflare,go.cfdata.org'
GOOS='darwin'
GOPATH='/Users/tjozsa/go'
GOPRIVATE=''
GOPROXY='https://athens.cfdata.org,direct'
GOROOT='/opt/homebrew/opt/go/libexec'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='local'
GOTOOLDIR='/opt/homebrew/opt/go/libexec/pkg/tool/darwin_arm64'
GOVCS=''
GOVERSION='go1.23.4'
GODEBUG=''
GOTELEMETRY='local'
GOTELEMETRYDIR='/Users/tjozsa/Library/Application Support/go/telemetry'
GCCGO='gccgo'
GOARM64='v8.0'
AR='ar'
CC='cc'
CXX='c++'
CGO_ENABLED='1'
GOMOD='/Users/tjozsa/cf-repos/authnz-publisher/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -arch arm64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/81/zyf3xcqd6wv1nh70f4pspr900000gp/T/go-build1369939013=/tmp/go-build -gno-record-gcc-switches -fno-common'

What did you do?

When implementing a custom slog.Handler, the middleware pattern breaks in two significant ways. First, calling With() on a logger completely bypasses any custom Handle implementation, falling back to only the wrapped handler. This means any middleware logic in custom handlers stops working as soon as attributes are added via With().

Second, even if we try to work around the first issue by creating a new handler from the existing one, the attributes set through With() become inaccessible via Record.Attrs(). While these attributes still appear in the final log output through the wrapped handler, middleware can no longer access them programmatically.

These behaviors prevent proper implementation of logging middleware that needs to process all records with their complete context, such as forwarding logs to external services like Sentry.

What did you see happen?

To Reproduce

Here's a minimal example demonstrating both issues:

package main

import (
	"context"
	"fmt"
	"log/slog"
	"os"
)

type TestHandler struct {
	slog.Handler
}

func (h *TestHandler) Handle(ctx context.Context, r slog.Record) error {
	attrs := []string{}
	r.Attrs(func(a slog.Attr) bool {
		attrs = append(attrs, a.Key)
		return true
	})
	// Print captured attributes
	fmt.Printf("Custom Handle called! Captured attributes:%+v\n", attrs)
	return nil
}

func main() {
	h := &TestHandler{Handler: slog.NewTextHandler(os.Stdout, nil)}
	log := slog.New(h)

	// Case 1: Direct attributes
	log.Error("direct attributes", "key1", "value1")
	// Terminal output:
	// Custom Handle called! Captured attributes: [key1]
	// time=2025-01-03T11:39:52.504Z level=ERROR msg="with attributes" key2=value2

	logWithAttr := log.With("key2", "value2")
	logWithAttr.Error("with attributes")
	// Issue 1. The custom Handle implementation is no longer called
	// Terminal output:
	// time=2025-01-03T11:35:41.412Z level=ERROR msg="with attributes" key2=value2

	log = slog.New(&TestHandler{Handler: logWithAttr.Handler()})
	log.Error("missing attributes")
	// Issue 2. Attributes are not inherited between Handlers
	// Terminal output:
	// Custom Handle called! Captured attributes:[]

	log = log.With("key3", "value3")
	log.Error("correctly logging attributes")
	// Terminal output:
	//time=2025-01-03T13:28:21.189Z level=ERROR msg="correctly logging attributes" key2=value2 key3=value3
}

What did you expect to see?

These issues make it impossible to implement proper logging middleware that needs to:

Process all log records consistently, regardless of how they were created
Access the complete set of attributes for each record
Forward complete log context to external services

For example, when implementing Sentry integration, we cannot reliably capture all log records or their full context, leading to incomplete error reporting.

@dmitshur
Copy link
Contributor

dmitshur commented Jan 3, 2025

CC @jba.

@dmitshur dmitshur added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 3, 2025
@dmitshur dmitshur added this to the Backlog milestone Jan 3, 2025
@jba
Copy link
Contributor

jba commented Jan 3, 2025

Logger.With should call Handler.WithAttrs. It's doing that for TestHandler, but since TestHandler embeds another handler, it's the embedded handler's WithAttr method that's getting called. In other words, it's Go's embedding rule that is doing the bypassing here, not anything in slog.

Some suggestions before writing your own handler:

@jba jba closed this as completed Jan 3, 2025
@jba
Copy link
Contributor

jba commented Jan 3, 2025

One more thing: I would avoid embedding when writing a middleware handler; it is too confusing (as you've seen). Instead put the handler in a named field:

handler slog.Handler

and call it when you want to delegate to it.

@tamas-jozsa
Copy link
Author

Amazing! Thank you, @jba, for the quick answer! You are right. I got myself confused with this. I've applied your recommendation for my case which fixed my problem.

@andig
Copy link
Contributor

andig commented Mar 26, 2025

I've just hit the same wall in #73057: #73057 (comment)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

5 participants