log: simplify pc level cache and fix bug in WithAttrs

Updates the Handle path to perform a single atomic load and no locking.
This is done by storing all state required for level matching into a single
struct and replacing that struct entirely whenever patterns or the global level
change.

Also fixes an issue with the current implementation where WithAttrs would return a fully
independent copy of the handler, with its own level. The WithAttrs method is calledd by
slog.Logger.With, which we also use in go-ethereum to create context specific loggers with
pre-filled attributes. Under the previous implementation of WithAttrs, if the application
created a long-lived logger (for example, for a specific peer), then that logger would not
be affected by later level changes done on the top-level logger, leading to potentially
missed events.

log/handler_glog.go

@@ -36,23 +36,22 @@ var errVmoduleSyntax = errors.New("expect comma-separated list of filename=N")
 // matches; and requesting backtraces at certain positions.
 type GlogHandler struct {
 	origin slog.Handler // The origin handler this wraps
+	lock   sync.Mutex   // synchronizes writes to config
+	config atomic.Pointer[glogConfig]
+}
 
-	level    atomic.Int32 // Current log level, atomically accessible
+type glogConfig struct {
-	override atomic.Bool  // Flag whether overrides are used, atomically accessible
+	patterns []pattern
-
+	cache    sync.Map
-	patterns []pattern                // Current list of patterns to override with
+	level    slog.Level
-	cachePtr atomic.Pointer[sync.Map] // Pointer to cache of callsite pattern evaluations, maps uintptr -> slog.Level
-	location string                   // file:line location where to do a stackdump at
-	lock     sync.Mutex               // Lock protecting the override pattern list
 }
 
 // NewGlogHandler creates a new log handler with filtering functionality similar
 // to Google's glog logger. The returned handler implements Handler.
-func NewGlogHandler(h slog.Handler) *GlogHandler {
+func NewGlogHandler(origin slog.Handler) *GlogHandler {
-	g := &GlogHandler{origin: h}
+	h := &GlogHandler{origin: origin}
-	m := new(sync.Map)
+	h.config.Store(new(glogConfig))
-	g.cachePtr.Store(m)
+	return h
-	return g
 }
 
 // pattern contains a filter for the Vmodule option, holding a verbosity level
@@ -65,8 +64,12 @@ type pattern struct {
 // Verbosity sets the glog verbosity ceiling. The verbosity of individual packages
 // and source files can be raised using Vmodule.
 func (h *GlogHandler) Verbosity(level slog.Level) {
-	h.level.Store(int32(level))
+	h.lock.Lock()
-	h.cachePtr.Store(new(sync.Map)) // atomic swap of cache instead of Clear
+	defer h.lock.Unlock()
+
+	cfg := h.config.Load()
+	newcfg := &glogConfig{level: level, patterns: cfg.patterns}
+	h.config.Store(newcfg)
 }
 
 // Vmodule sets the glog verbosity pattern.
@@ -128,12 +131,13 @@ func (h *GlogHandler) Vmodule(ruleset string) error {
 		re, _ := regexp.Compile(matcher)
 		filter = append(filter, pattern{re, level})
 	}
+
 	// Swap out the vmodule pattern for the new filter system
 	h.lock.Lock()
-	h.patterns = filter
+	cfg := h.config.Load()
+	newcfg := &glogConfig{level: cfg.level, patterns: filter}
+	h.config.Store(newcfg)
 	h.lock.Unlock()
-	h.cachePtr.Store(new(sync.Map)) // atomic swap of cache instead of Clear
-	h.override.Store(len(filter) != 0)
 
 	return nil
 }
@@ -141,28 +145,9 @@ func (h *GlogHandler) Vmodule(ruleset string) error {
 // Enabled implements slog.Handler, reporting whether the handler handles records
 // at the given level.
 func (h *GlogHandler) Enabled(ctx context.Context, lvl slog.Level) bool {
-	// fast-track skipping logging if override not enabled and the provided verbosity is above configured
+	// fast-track skipping logging if vmodule is not enabled or level too low
-	return h.override.Load() || slog.Level(h.level.Load()) <= lvl
+	cfg := h.config.Load()
-}
+	return len(cfg.patterns) > 0 || cfg.level <= lvl
-
-// WithAttrs implements slog.Handler, returning a new Handler whose attributes
-// consist of both the receiver's attributes and the arguments.
-func (h *GlogHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
-	patterns := []pattern{}
-	h.lock.Lock()
-	patterns = append(patterns, h.patterns...)
-	h.lock.Unlock()
-
-	res := GlogHandler{
-		origin:   h.origin.WithAttrs(attrs),
-		patterns: patterns,
-		location: h.location,
-	}
-
-	res.level.Store(h.level.Load())
-	res.override.Store(h.override.Load())
-	res.cachePtr.Store(h.cachePtr.Load())
-	return &res
 }
 
 // WithGroup implements slog.Handler, returning a new Handler with the given
@@ -176,11 +161,14 @@ func (h *GlogHandler) WithGroup(name string) slog.Handler {
 // Handle implements slog.Handler, filtering a log record through the global,
 // local and backtrace filters, finally emitting it if either allow it through.
 func (h *GlogHandler) Handle(ctx context.Context, r slog.Record) error {
-	// Get current cache
+	return h.handle(ctx, r, h.origin)
-	cache := h.cachePtr.Load()
+}
+
+func (h *GlogHandler) handle(ctx context.Context, r slog.Record, origin slog.Handler) error {
+	cfg := h.config.Load()
 
 	// Fast path: cache hit
-	if lvl, ok := cache.Load(r.PC); ok {
+	if lvl, ok := cfg.cache.Load(r.PC); ok {
 		if lvl.(slog.Level) <= r.Level {
 			return h.origin.Handle(ctx, r)
 		}
@@ -192,47 +180,59 @@ func (h *GlogHandler) Handle(ctx context.Context, r slog.Record) error {
 	frame, _ := fs.Next()
 	file := frame.File
 
-	// Snapshot the current pattern slice under lock.
+	// Match against patterns and cache the level applied at this callsitte
-	h.lock.Lock()
+	lvl := cfg.level // default: use global level
-	curPatterns := h.patterns
+	for _, rule := range cfg.patterns {
-	h.lock.Unlock()
-
-	// Match without holding the lock.
-	var (
-		lvl slog.Level
-		ok  bool
-	)
-	for _, rule := range curPatterns {
 		if rule.pattern.MatchString("+" + file) {
-			lvl, ok = rule.level, true
+			lvl = rule.level
-			// Not breaking allows the last match to win.
 		}
 	}
-	if !ok {
+	cfg.cache.Store(r.PC, lvl)
-		// No rule matched: use the current global/default level.
-		lvl = slog.Level(h.level.Load())
-	}
-
-	// Check if we should cache this result
-	h.lock.Lock()
-	shouldCache := false
-	switch {
-	case len(curPatterns) == 0 && len(h.patterns) == 0:
-		// Cache the default/global level to avoid re-evaluating the callsite each time.
-		shouldCache = true
-	case len(h.patterns) > 0 && len(curPatterns) > 0:
-		// Only cache the result if the vmodule patterns have not changed since we
-		// snapshotted them. This avoids inserting stale entries if Vmodule() updates
-		// the pattern list concurrently with Handle().
-		shouldCache = (&h.patterns[0] == &curPatterns[0])
-	}
-	if shouldCache {
-		cache.Store(r.PC, lvl)
-	}
-	h.lock.Unlock()
 
+	// Handle the message.
 	if lvl <= r.Level {
 		return h.origin.Handle(ctx, r)
 	}
 	return nil
 }
+
+// WithAttrs implements slog.Handler, returning a new Handler whose attributes
+// consist of both the receiver's attributes and the arguments.
+//
+// Note the handler created here will still listen to Verbosity and Vmodule settings
+// done on the original handler.
+func (h *GlogHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	// fork the log config at this point
+	cfg := h.config.Load()
+	newcfg := &glogConfig{level: cfg.level, patterns: cfg.patterns}
+
+	sub := GlogHandler{origin: h.origin.WithAttrs(attrs)}
+	sub.config.Store(newcfg)
+	return &sub
+}
+
+type glogWithAttrs struct{
+	base *GlogHandler
+	origin slog.Handler
+}
+
+func (wh *glogWithAttrs) Enabled(ctx context.Context, lvl slog.Level) bool {
+	return wh.base.Enabled(ctx, lvl)
+}
+
+func (wh *glogWithAttrs) Handle(ctx context.Context, r slog.Record) error {
+	return wh.base.handle(ctx, r, wh.origin)
+}
+
+func (wh *glogWithAttrs) WithAttrs(attrs []slog.Attr) slog.Handler {
+	return &glogWithAttrs{base: wh.base, origin: wh.origin.WithAttrs(attrs)}
+}
+
+// WithGroup implements slog.Handler, returning a new Handler with the given
+// group appended to the receiver's existing groups.
+//
+// Note, this function is not implemented.
+func (wh *glogWithAttrs) WithGroup(name string) slog.Handler {
+	panic("not implemented")
+}
+