forks/go-ethereum
1
0
Fork 1
mirror of https://github.com/ethereum/go-ethereum.git synced 2026-04-16 14:44:41 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions 1

log: allow –vmodule to downgrade log levels (#33111)

Browse source 
Changes the log handler to check for vmodule level overrides
even for messages above the current level. This enables the user to selectively
hide messages from certain packages, among other things.

Also fixes a bug where handler instances created by WithAttr would not follow
the level setting anymore. 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.

Closes: #30717

---------

Co-authored-by: Marius van der Wijden <m.vanderwijden@live.de>
Co-authored-by: Felix Lange <fjl@twurst.com>
This commit is contained in:
Jonny Rhea 2026-04-16 01:53:08 -05:00 committed by GitHub
parent 0b35ad95f5
commit d07a946a5b
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
2 changed files with 139 additions and 66 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

147
log/handler_glog.go
View file

@ -19,9 +19,7 @@ package log
import (
"context"
"errors"
"fmt"
"log/slog"
"maps"
"regexp"
"runtime"
"strconv"
@ -38,22 +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
override atomic.Bool // Flag whether overrides are used, atomically accessible
patterns []pattern // Current list of patterns to override with
siteCache map[uintptr]slog.Level // Cache of callsite pattern evaluations
location string // file:line location where to do a stackdump at
lock sync.RWMutex // Lock protecting the override pattern list
type glogConfig struct {
patterns []pattern
cache sync.Map
level slog.Level
}
// 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 {
return &GlogHandler{
origin: h,
}
func NewGlogHandler(origin slog.Handler) *GlogHandler {
h := &GlogHandler{origin: origin}
h.config.Store(new(glogConfig))
return h
}
// pattern contains a filter for the Vmodule option, holding a verbosity level
@ -66,7 +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()
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,13 +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()
defer h.lock.Unlock()
h.patterns = filter
h.siteCache = make(map[uintptr]slog.Level)
h.override.Store(len(filter) != 0)
cfg := h.config.Load()
newcfg := &glogConfig{level: cfg.level, patterns: filter}
h.config.Store(newcfg)
h.lock.Unlock()
return nil
}
@ -142,30 +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
return h.override.Load() || slog.Level(h.level.Load()) <= 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 {
h.lock.RLock()
siteCache := maps.Clone(h.siteCache)
h.lock.RUnlock()
patterns := []pattern{}
patterns = append(patterns, h.patterns...)
res := GlogHandler{
origin: h.origin.WithAttrs(attrs),
patterns: patterns,
siteCache: siteCache,
location: h.location,
}
res.level.Store(h.level.Load())
res.override.Store(h.override.Load())
return &res
// fast-track skipping logging if vmodule is not enabled or level too low
cfg := h.config.Load()
return len(cfg.patterns) > 0 || cfg.level <= lvl
}
// WithGroup implements slog.Handler, returning a new Handler with the given
@ -178,37 +160,70 @@ 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(_ context.Context, r slog.Record) error {
// If the global log level allows, fast track logging
if slog.Level(h.level.Load()) <= r.Level {
return h.origin.Handle(context.Background(), r)
}
func (h *GlogHandler) Handle(ctx context.Context, r slog.Record) error {
return h.handle(ctx, r, h.origin)
}
// Check callsite cache for previously calculated log levels
h.lock.RLock()
lvl, ok := h.siteCache[r.PC]
h.lock.RUnlock()
// If we didn't cache the callsite yet, calculate it
if !ok {
h.lock.Lock()
func (h *GlogHandler) handle(ctx context.Context, r slog.Record, origin slog.Handler) error {
cfg := h.config.Load()
var lvl slog.Level
cachedLvl, ok := cfg.cache.Load(r.PC)
if ok {
// Fast path: cache hit
lvl = cachedLvl.(slog.Level)
} else {
// Resolve the callsite file.
fs := runtime.CallersFrames([]uintptr{r.PC})
frame, _ := fs.Next()
for _, rule := range h.patterns {
if rule.pattern.MatchString(fmt.Sprintf("+%s", frame.File)) {
h.siteCache[r.PC], lvl, ok = rule.level, rule.level, true
file := frame.File
// Match against patterns and cache the level applied at this callsite.
lvl = cfg.level // default: use global level
for _, rule := range cfg.patterns {
if rule.pattern.MatchString("+" + file) {
lvl = rule.level
}
}
// If no rule matched, remember to drop log the next time
if !ok {
h.siteCache[r.PC] = 0
}
h.lock.Unlock()
cfg.cache.Store(r.PC, lvl)
}
// Handle the message.
if lvl <= r.Level {
return h.origin.Handle(context.Background(), r)
return 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 {
return &glogWithAttrs{base: h, origin: h.origin.WithAttrs(attrs)}
}
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")
}

58
log/logger_test.go
View file

@ -33,6 +33,64 @@ func TestLoggingWithVmodule(t *testing.T) {
}
}
// TestLoggingWithVmoduleDowngrade checks that vmodule can be downgraded.
func TestLoggingWithVmoduleDowngrade(t *testing.T) {
out := new(bytes.Buffer)
glog := NewGlogHandler(NewTerminalHandlerWithLevel(out, LevelTrace, false))
glog.Verbosity(LevelTrace) // Allow all logs globally
logger := NewLogger(glog)
// This should appear (global level allows it)
logger.Info("before vmodule downgrade, this should be logged")
if !bytes.Contains(out.Bytes(), []byte("before vmodule downgrade")) {
t.Fatal("expected 'before vmodule downgrade' to be logged")
}
out.Reset()
// Downgrade this file to only allow Warn and above
glog.Vmodule("logger_test.go=2")
// Info should now be filtered out
logger.Info("after vmodule downgrade, this should be filtered")
if bytes.Contains(out.Bytes(), []byte("after vmodule downgrade, this should be filtered")) {
t.Fatal("expected 'after vmodule downgrade, this should be filtered' to NOT be logged after vmodule downgrade")
}
// Warn should still appear
logger.Warn("after vmodule downgrade, this should be logged")
if !bytes.Contains(out.Bytes(), []byte("after vmodule downgrade, this should be logged")) {
t.Fatal("expected 'should appear' to be logged")
}
}
// TestWithAttrsVerbosityChange checks that verbosity changes affect child loggers.
func TestWithAttrsVerbosityChange(t *testing.T) {
out := new(bytes.Buffer)
glog := NewGlogHandler(NewTerminalHandlerWithLevel(out, LevelTrace, false))
glog.Verbosity(LevelInfo)
// Create a child logger with an extra attribute.
child := slog.New(glog.WithAttrs([]slog.Attr{slog.String("peer", "foo")}))
// Debug should be filtered at Info level.
child.Debug("this should be filtered")
if bytes.Contains(out.Bytes(), []byte("this should be filtered")) {
t.Fatal("expected debug message to be filtered at Info level")
}
// Change verbosity on the parent to allow Debug.
glog.Verbosity(LevelDebug)
// Child should pick up the new level and include its attributes.
child.Debug("this should be logged")
if !bytes.Contains(out.Bytes(), []byte("this should be logged")) {
t.Fatal("expected child logger to pick up verbosity change")
}
if !bytes.Contains(out.Bytes(), []byte("peer=foo")) {
t.Fatal("expected child logger to include WithAttrs attributes")
}
}
func TestTerminalHandlerWithAttrs(t *testing.T) {
out := new(bytes.Buffer)
glog := NewGlogHandler(NewTerminalHandlerWithLevel(out, LevelTrace, false).WithAttrs([]slog.Attr{slog.String("baz", "bat")}))