From 555c56a1ba58d60a6b28a01da6728f8eccf50f24 Mon Sep 17 00:00:00 2001 From: Marius van der Wijden Date: Tue, 1 Apr 2025 12:37:00 +0200 Subject: [PATCH 1/5] log: allow --vmodule to downgrade the log level --- log/handler_glog.go | 5 ----- 1 file changed, 5 deletions(-) diff --git a/log/handler_glog.go b/log/handler_glog.go index 739f8c5b427d..d88e6ba64c73 100644 --- a/log/handler_glog.go +++ b/log/handler_glog.go @@ -179,11 +179,6 @@ 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) - } - // Check callsite cache for previously calculated log levels h.lock.RLock() lvl, ok := h.siteCache[r.PC] From d2baaed90ab04a21e024a80dfd0b751c8a28fb82 Mon Sep 17 00:00:00 2001 From: Marius van der Wijden Date: Tue, 1 Apr 2025 12:48:51 +0200 Subject: [PATCH 2/5] log: allow --vmodule to downgrade the log level --- log/handler_glog.go | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/log/handler_glog.go b/log/handler_glog.go index d88e6ba64c73..0534d1bbb260 100644 --- a/log/handler_glog.go +++ b/log/handler_glog.go @@ -52,7 +52,8 @@ type GlogHandler struct { // to Google's glog logger. The returned handler implements Handler. func NewGlogHandler(h slog.Handler) *GlogHandler { return &GlogHandler{ - origin: h, + origin: h, + siteCache: make(map[uintptr]slog.Level), } } @@ -196,9 +197,10 @@ func (h *GlogHandler) Handle(_ context.Context, r slog.Record) error { h.siteCache[r.PC], lvl, ok = rule.level, rule.level, true } } - // If no rule matched, remember to drop log the next time + // If no rule matched, use the default log lvl if !ok { - h.siteCache[r.PC] = 0 + lvl = slog.Level(h.level.Load()) + h.siteCache[r.PC] = lvl } h.lock.Unlock() } From 5e9224bca863af4fe7483bf0b506bf1066434027 Mon Sep 17 00:00:00 2001 From: Marius van der Wijden Date: Sun, 6 Apr 2025 14:52:14 +0200 Subject: [PATCH 3/5] log: clear siteCache on setting the verbosity --- log/handler_glog.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/log/handler_glog.go b/log/handler_glog.go index 0534d1bbb260..e3c670c2a7de 100644 --- a/log/handler_glog.go +++ b/log/handler_glog.go @@ -68,6 +68,8 @@ type pattern struct { // and source files can be raised using Vmodule. func (h *GlogHandler) Verbosity(level slog.Level) { h.level.Store(int32(level)) + // clear the cache to make sure the verbosity is applied correctly. + h.siteCache = make(map[uintptr]slog.Level) } // Vmodule sets the glog verbosity pattern. From 9069401d9493faedff819d561869b0b26b8da966 Mon Sep 17 00:00:00 2001 From: MariusVanDerWijden Date: Thu, 29 May 2025 11:21:13 +0200 Subject: [PATCH 4/5] log: use sync map --- log/handler_glog.go | 48 +++++++++++++++++++-------------------------- 1 file changed, 20 insertions(+), 28 deletions(-) diff --git a/log/handler_glog.go b/log/handler_glog.go index e3c670c2a7de..4694d04a5046 100644 --- a/log/handler_glog.go +++ b/log/handler_glog.go @@ -21,7 +21,6 @@ import ( "errors" "fmt" "log/slog" - "maps" "regexp" "runtime" "strconv" @@ -42,18 +41,17 @@ type GlogHandler struct { 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 + patterns []pattern // Current list of patterns to override with + siteCache sync.Map // Cache of callsite pattern evaluations, maps uintptr -> slog.Level + location string // file:line location where to do a stackdump at + lock sync.RWMutex // 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 { return &GlogHandler{ - origin: h, - siteCache: make(map[uintptr]slog.Level), + origin: h, } } @@ -69,7 +67,7 @@ type pattern struct { func (h *GlogHandler) Verbosity(level slog.Level) { h.level.Store(int32(level)) // clear the cache to make sure the verbosity is applied correctly. - h.siteCache = make(map[uintptr]slog.Level) + h.siteCache.Clear() } // Vmodule sets the glog verbosity pattern. @@ -133,10 +131,9 @@ func (h *GlogHandler) Vmodule(ruleset string) error { } // 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.lock.Unlock() + h.siteCache.Clear() h.override.Store(len(filter) != 0) return nil @@ -152,18 +149,15 @@ func (h *GlogHandler) Enabled(ctx context.Context, lvl slog.Level) bool { // 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{} + h.lock.RLock() patterns = append(patterns, h.patterns...) + h.lock.RUnlock() res := GlogHandler{ - origin: h.origin.WithAttrs(attrs), - patterns: patterns, - siteCache: siteCache, - location: h.location, + origin: h.origin.WithAttrs(attrs), + patterns: patterns, + location: h.location, } res.level.Store(h.level.Load()) @@ -183,30 +177,28 @@ func (h *GlogHandler) WithGroup(name string) slog.Handler { // local and backtrace filters, finally emitting it if either allow it through. func (h *GlogHandler) Handle(_ context.Context, r slog.Record) error { // Check callsite cache for previously calculated log levels - h.lock.RLock() - lvl, ok := h.siteCache[r.PC] - h.lock.RUnlock() + lvl, ok := h.siteCache.Load(r.PC) // If we didn't cache the callsite yet, calculate it if !ok { - h.lock.Lock() - fs := runtime.CallersFrames([]uintptr{r.PC}) frame, _ := fs.Next() + h.lock.RLock() 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 + h.siteCache.Store(r.PC, rule.level) + lvl, ok = rule.level, true } } + h.lock.RUnlock() // If no rule matched, use the default log lvl if !ok { lvl = slog.Level(h.level.Load()) - h.siteCache[r.PC] = lvl + h.siteCache.Store(r.PC, lvl) } - h.lock.Unlock() } - if lvl <= r.Level { + if lvl.(slog.Level) <= r.Level { return h.origin.Handle(context.Background(), r) } return nil From c089e3c1ad6ebce0d2e1ac9f688f944c6b966c73 Mon Sep 17 00:00:00 2001 From: jonny rhea Date: Wed, 5 Nov 2025 21:00:16 -0600 Subject: [PATCH 5/5] log/glog: replace siteCache with atomic pointer --- log/handler_glog.go | 92 ++++++++++++++++++++++++++++----------------- 1 file changed, 57 insertions(+), 35 deletions(-) diff --git a/log/handler_glog.go b/log/handler_glog.go index 4694d04a5046..de0456b5a36f 100644 --- a/log/handler_glog.go +++ b/log/handler_glog.go @@ -19,7 +19,6 @@ package log import ( "context" "errors" - "fmt" "log/slog" "regexp" "runtime" @@ -41,18 +40,19 @@ type GlogHandler struct { 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 sync.Map // Cache of callsite pattern evaluations, maps uintptr -> slog.Level - location string // file:line location where to do a stackdump at - lock sync.RWMutex // Lock protecting the override pattern list + patterns []pattern // Current list of patterns to override with + 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 { - return &GlogHandler{ - origin: h, - } + g := &GlogHandler{origin: h} + m := new(sync.Map) + g.cachePtr.Store(m) + return g } // pattern contains a filter for the Vmodule option, holding a verbosity level @@ -66,8 +66,7 @@ type pattern struct { // and source files can be raised using Vmodule. func (h *GlogHandler) Verbosity(level slog.Level) { h.level.Store(int32(level)) - // clear the cache to make sure the verbosity is applied correctly. - h.siteCache.Clear() + h.cachePtr.Store(new(sync.Map)) // atomic swap of cache instead of Clear } // Vmodule sets the glog verbosity pattern. @@ -133,7 +132,7 @@ func (h *GlogHandler) Vmodule(ruleset string) error { h.lock.Lock() h.patterns = filter h.lock.Unlock() - h.siteCache.Clear() + h.cachePtr.Store(new(sync.Map)) // atomic swap of cache instead of Clear h.override.Store(len(filter) != 0) return nil @@ -150,9 +149,9 @@ func (h *GlogHandler) Enabled(ctx context.Context, lvl slog.Level) bool { // consist of both the receiver's attributes and the arguments. func (h *GlogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { patterns := []pattern{} - h.lock.RLock() + h.lock.Lock() patterns = append(patterns, h.patterns...) - h.lock.RUnlock() + h.lock.Unlock() res := GlogHandler{ origin: h.origin.WithAttrs(attrs), @@ -162,6 +161,7 @@ func (h *GlogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { res.level.Store(h.level.Load()) res.override.Store(h.override.Load()) + res.cachePtr.Store(h.cachePtr.Load()) return &res } @@ -175,31 +175,53 @@ 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 { - // Check callsite cache for previously calculated log levels - lvl, ok := h.siteCache.Load(r.PC) - - // If we didn't cache the callsite yet, calculate it - if !ok { - fs := runtime.CallersFrames([]uintptr{r.PC}) - frame, _ := fs.Next() - - h.lock.RLock() - for _, rule := range h.patterns { - if rule.pattern.MatchString(fmt.Sprintf("+%s", frame.File)) { - h.siteCache.Store(r.PC, rule.level) - lvl, ok = rule.level, true - } +func (h *GlogHandler) Handle(ctx context.Context, r slog.Record) error { + // Get current cache + cache := h.cachePtr.Load() + + // Fast path: cache hit + if lvl, ok := cache.Load(r.PC); ok { + if lvl.(slog.Level) <= r.Level { + return h.origin.Handle(ctx, r) } - h.lock.RUnlock() - // If no rule matched, use the default log lvl - if !ok { - lvl = slog.Level(h.level.Load()) - h.siteCache.Store(r.PC, lvl) + return nil + } + + // Resolve the callsite file once. + fs := runtime.CallersFrames([]uintptr{r.PC}) + frame, _ := fs.Next() + file := frame.File + + // Snapshot the current pattern slice under lock. + h.lock.Lock() + curPatterns := h.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 + // TODO: Not breaking allows the last match to win. Is this what we want? } } - if lvl.(slog.Level) <= r.Level { - return h.origin.Handle(context.Background(), r) + if !ok { + // No rule matched: use the current global/default level. + lvl = slog.Level(h.level.Load()) + } + + // Store only if patterns are still the same slice (avoid caching stale results). + h.lock.Lock() + if len(h.patterns) > 0 && len(curPatterns) > 0 && &h.patterns[0] == &curPatterns[0] { + cache.Store(r.PC, lvl) + } + h.lock.Unlock() + + if lvl <= r.Level { + return h.origin.Handle(ctx, r) } return nil }