From 47af53f9aaf9aa7b12cd976eb150ccf3d64da6fd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Szil=C3=A1gyi?= Date: Tue, 21 Feb 2017 17:26:05 +0200 Subject: [PATCH] log: implement a glog style pattern matching handler --- log/handler_glog.go | 227 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 227 insertions(+) create mode 100644 log/handler_glog.go diff --git a/log/handler_glog.go b/log/handler_glog.go new file mode 100644 index 0000000000..f8b932fd1b --- /dev/null +++ b/log/handler_glog.go @@ -0,0 +1,227 @@ +// Copyright 2017 The go-ethereum Authors +// This file is part of the go-ethereum library. +// +// The go-ethereum library is free software: you can redistribute it and/or modify +// it under the terms of the GNU Lesser General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// The go-ethereum library is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Lesser General Public License for more details. +// +// You should have received a copy of the GNU Lesser General Public License +// along with the go-ethereum library. If not, see . + +package log + +import ( + "errors" + "fmt" + "regexp" + "runtime" + "strconv" + "strings" + "sync" + "sync/atomic" +) + +// errVmoduleSyntax is returned when a user vmodule pattern is invalid. +var errVmoduleSyntax = errors.New("expect comma-separated list of filename=N") + +// errTraceSyntax is returned when a user backtrace pattern is invalid. +var errTraceSyntax = errors.New("expect file.go:234") + +// GlogHandler is a log handler that mimics the filtering features of Google's +// glog logger: setting global log levels; overriding with callsite pattern +// matches; and requesting backtraces at certain positions. +type GlogHandler struct { + origin Handler // The origin handler this wraps + + level uint32 // Current log level, atomically accessible + override uint32 // Flag whether overrides are used, atomically accessible + backtrace uint32 // Flag whether backtrace location is set + + patterns []pattern // Current list of patterns to override with + siteCache map[uintptr]Lvl // 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 +} + +// NewGlogHandler creates a new log handler with filtering functionality similar +// to Google's glog logger. The returned handler implements Handler. +func NewGlogHandler(h Handler) *GlogHandler { + return &GlogHandler{ + origin: h, + } +} + +// pattern contains a filter for the Vmodule option, holding a verbosity level +// and a file pattern to match. +type pattern struct { + pattern *regexp.Regexp + level Lvl +} + +// Verbosity sets the glog verbosity ceiling. The verbosity of individual packages +// and source files can be raised using Vmodule. +func (h *GlogHandler) Verbosity(level Lvl) { + atomic.StoreUint32(&h.level, uint32(level)) +} + +// Vmodule sets the glog verbosity pattern. +// +// The syntax of the argument is a comma-separated list of pattern=N, where the +// pattern is a literal file name or "glob" pattern matching and N is a V level. +// +// For instance: +// +// pattern="gopher.go=3" +// sets the V level to 3 in all Go files named "gopher.go" +// +// pattern="foo=3" +// sets V to 3 in all files of any packages whose import path ends in "foo" +// +// pattern="foo/*=3" +// sets V to 3 in all files of any packages whose import path contains "foo" +func (h *GlogHandler) Vmodule(ruleset string) error { + var filter []pattern + for _, rule := range strings.Split(ruleset, ",") { + // Empty strings such as from a trailing comma can be ignored + if len(rule) == 0 { + continue + } + // Ensure we have a pattern = level filter rule + parts := strings.Split(rule, "=") + if len(parts) != 2 { + return errVmoduleSyntax + } + parts[0] = strings.TrimSpace(parts[0]) + parts[1] = strings.TrimSpace(parts[1]) + if len(parts[0]) == 0 || len(parts[1]) == 0 { + return errVmoduleSyntax + } + // Parse the level and if correct, assemble the filter rule + level, err := strconv.Atoi(parts[1]) + if err != nil { + return errVmoduleSyntax + } + if level <= 0 { + continue // Ignore. It's harmless but no point in paying the overhead. + } + // Compile the rule pattern into a regular expression + matcher := ".*" + for _, comp := range strings.Split(parts[0], "/") { + if comp == "*" { + matcher += "(/.*)?" + } else if comp != "" { + matcher += "/" + regexp.QuoteMeta(comp) + } + } + if !strings.HasSuffix(parts[0], ".go") { + matcher += "/[^/]+\\.go" + } + matcher = matcher + "$" + + re, _ := regexp.Compile(matcher) + filter = append(filter, pattern{re, Lvl(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]Lvl) + atomic.StoreUint32(&h.override, uint32(len(filter))) + + return nil +} + +// BacktraceAt sets the glog backtrace location. When set to a file and line +// number holding a logging statement, a stack trace will be written to the Info +// log whenever execution hits that statement. +// +// Unlike with Vmodule, the ".go" must be present. +func (h *GlogHandler) BacktraceAt(location string) error { + // Ensure the backtrace location contains two non-empty elements + parts := strings.Split(location, ":") + if len(parts) != 2 { + return errTraceSyntax + } + parts[0] = strings.TrimSpace(parts[0]) + parts[1] = strings.TrimSpace(parts[1]) + if len(parts[0]) == 0 || len(parts[1]) == 0 { + return errTraceSyntax + } + // Ensure the .go prefix is present and the line is valid + if !strings.HasSuffix(parts[0], ".go") { + return errTraceSyntax + } + if _, err := strconv.Atoi(parts[1]); err != nil { + return errTraceSyntax + } + // All seems valid + h.lock.Lock() + defer h.lock.Unlock() + + h.location = location + atomic.StoreUint32(&h.backtrace, uint32(len(location))) + + return nil +} + +// Log implements Handler.Log, filtering a log record through the global, local +// and backtrace filters, finally emitting it if either allow it through. +func (h *GlogHandler) Log(r *Record) error { + // If backtracing is requested, check whether this is the callsite + if atomic.LoadUint32(&h.backtrace) > 0 { + // Everything below here is slow. Although we could cache the call sites the + // same way as for vmodule, backtracing is so rare it's not worth the extra + // complexity. + h.lock.RLock() + match := h.location == r.Call.String() + h.lock.RUnlock() + + if match { + // Callsite matched, raise the log level to info and gather the stacks + r.Lvl = LvlInfo + + buf := make([]byte, 1024*1024) + buf = buf[:runtime.Stack(buf, true)] + r.Msg += "\n\n" + string(buf) + } + } + // If the global log level allows, fast track logging + if atomic.LoadUint32(&h.level) >= uint32(r.Lvl) { + return h.origin.Log(r) + } + // If no local overrides are present, fast track skipping + if atomic.LoadUint32(&h.override) == 0 { + return nil + } + // Check callsite cache for previously calculated log levels + h.lock.RLock() + lvl, ok := h.siteCache[r.Call.PC()] + h.lock.RUnlock() + + // If we didn't cache the callsite yet, calculate it + if !ok { + h.lock.Lock() + for _, rule := range h.patterns { + if rule.pattern.MatchString(fmt.Sprintf("%+s", r.Call)) { + h.siteCache[r.Call.PC()], lvl, ok = rule.level, rule.level, true + break + } + } + // If no rule matched, remember to drop log the next time + if !ok { + h.siteCache[r.Call.PC()] = 0 + } + h.lock.Unlock() + } + if lvl >= r.Lvl { + return h.origin.Log(r) + } + return nil +}