diff --git a/log/format.go b/log/format.go index 54c071b908..e55bea47f2 100644 --- a/log/format.go +++ b/log/format.go @@ -30,70 +30,42 @@ type TerminalStringer interface { TerminalString() string } +// format formats the log record for terminal output func (h *TerminalHandler) format(buf []byte, r slog.Record, usecolor bool) []byte { msg := escapeMessage(r.Message) - var color = "" - if usecolor { - switch r.Level { - case LevelCrit: - color = "\x1b[35m" - case slog.LevelError: - color = "\x1b[31m" - case slog.LevelWarn: - color = "\x1b[33m" - case slog.LevelInfo: - color = "\x1b[32m" - case slog.LevelDebug: - color = "\x1b[36m" - case LevelTrace: - color = "\x1b[34m" - } - } + color := determineColor(usecolor, r.Level) + if buf == nil { buf = make([]byte, 0, 30+termMsgJust) } b := bytes.NewBuffer(buf) - if color != "" { // Start color - b.WriteString(color) - b.WriteString(LevelAlignedString(r.Level)) - b.WriteString("\x1b[0m") - } else { - b.WriteString(LevelAlignedString(r.Level)) - } + b.WriteString(color) + b.WriteString(LevelAlignedString(r.Level)) + b.WriteString("\x1b[0m") b.WriteString("[") writeTimeTermFormat(b, r.Time) b.WriteString("] ") b.WriteString(msg) - // try to justify the log output for short messages - //length := utf8.RuneCountInString(msg) length := len(msg) if (r.NumAttrs()+len(h.attrs)) > 0 && length < termMsgJust { b.Write(spaces[:termMsgJust-length]) } - // print the attributes h.formatAttributes(b, r, color) return b.Bytes() } +// formatAttributes formats the attributes of the log record func (h *TerminalHandler) formatAttributes(buf *bytes.Buffer, r slog.Record, color string) { writeAttr := func(attr slog.Attr, first, last bool) { buf.WriteByte(' ') - - if color != "" { - buf.WriteString(color) - buf.Write(appendEscapeString(buf.AvailableBuffer(), attr.Key)) - buf.WriteString("\x1b[0m=") - } else { - buf.Write(appendEscapeString(buf.AvailableBuffer(), attr.Key)) - buf.WriteByte('=') - } + buf.WriteString(color) + buf.Write(appendEscapeString(buf.AvailableBuffer(), attr.Key)) + buf.WriteString("\x1b[0m=") val := FormatSlogValue(attr.Value, buf.AvailableBuffer()) - padding := h.fieldPadding[attr.Key] - length := utf8.RuneCount(val) if padding < length && length <= termCtxMaxPadding { padding = length @@ -104,6 +76,7 @@ func (h *TerminalHandler) formatAttributes(buf *bytes.Buffer, r slog.Record, col buf.Write(spaces[:padding-length]) } } + var n = 0 var nAttrs = len(h.attrs) + r.NumAttrs() for _, attr := range h.attrs { @@ -118,6 +91,29 @@ func (h *TerminalHandler) formatAttributes(buf *bytes.Buffer, r slog.Record, col buf.WriteByte('\n') } +// determineColor determines the color code for the log level +func determineColor(usecolor bool, level slog.Level) string { + if !usecolor { + return "" + } + switch level { + case LevelCrit: + return "\x1b[35m" + case slog.LevelError: + return "\x1b[31m" + case slog.LevelWarn: + return "\x1b[33m" + case slog.LevelInfo: + return "\x1b[32m" + case slog.LevelDebug: + return "\x1b[36m" + case LevelTrace: + return "\x1b[34m" + default: + return "" + } +} + // FormatSlogValue formats a slog.Value for serialization to terminal. func FormatSlogValue(v slog.Value, tmp []byte) (result []byte) { var value any @@ -188,9 +184,8 @@ func appendUint64(dst []byte, n uint64, neg bool) []byte { if n < 100000 { if neg { return strconv.AppendInt(dst, -int64(n), 10) - } else { - return strconv.AppendInt(dst, int64(n), 10) } + return strconv.AppendInt(dst, int64(n), 10) } // Large numbers should be split const maxLength = 26 @@ -268,8 +263,7 @@ func appendU256(dst []byte, n *uint256.Int) []byte { // appendEscapeString writes the string s to the given writer, with // escaping/quoting if needed. func appendEscapeString(dst []byte, s string) []byte { - needsQuoting := false - needsEscaping := false + needsQuoting, needsEscaping := false, false for _, r := range s { // If it contains spaces or equal-sign, we need to quote it. if r == ' ' || r == '=' { @@ -357,7 +351,6 @@ func writePosIntWidth(b *bytes.Buffer, i, width int) { bp-- i = q } - // i < 10 bb[bp] = byte('0' + i) b.Write(bb[bp:]) } diff --git a/log/format_test.go b/log/format_test.go index d4c1df4abc..4990bfbd87 100644 --- a/log/format_test.go +++ b/log/format_test.go @@ -7,6 +7,7 @@ import ( var sink []byte +// Benchmark for formatting int64 using logfmt func BenchmarkPrettyInt64Logfmt(b *testing.B) { buf := make([]byte, 100) b.ReportAllocs() @@ -15,6 +16,7 @@ func BenchmarkPrettyInt64Logfmt(b *testing.B) { } } +// Benchmark for formatting uint64 using logfmt func BenchmarkPrettyUint64Logfmt(b *testing.B) { buf := make([]byte, 100) b.ReportAllocs() diff --git a/log/handler_glog.go b/log/handler_glog.go index 625a036403..20861b24ea 100644 --- a/log/handler_glog.go +++ b/log/handler_glog.go @@ -37,22 +37,21 @@ var errVmoduleSyntax = errors.New("expect comma-separated list of filename=N") // glog logger: setting global log levels; overriding with callsite pattern // matches; and requesting backtraces at certain positions. type GlogHandler struct { - origin slog.Handler // The origin handler this wraps - - 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 + origin slog.Handler // The origin handler this wraps + 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 + 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, + origin: h, + siteCache: make(map[uintptr]slog.Level), } } @@ -96,13 +95,13 @@ func (h *GlogHandler) Vmodule(ruleset string) error { 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 { + pattern := strings.TrimSpace(parts[0]) + levelStr := strings.TrimSpace(parts[1]) + if len(pattern) == 0 || len(levelStr) == 0 { return errVmoduleSyntax } // Parse the level and if correct, assemble the filter rule - l, err := strconv.Atoi(parts[1]) + l, err := strconv.Atoi(levelStr) if err != nil { return errVmoduleSyntax } @@ -112,19 +111,7 @@ func (h *GlogHandler) Vmodule(ruleset string) error { 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 + "$" - + matcher := compilePattern(pattern) re, _ := regexp.Compile(matcher) filter = append(filter, pattern{re, level}) } @@ -139,8 +126,24 @@ func (h *GlogHandler) Vmodule(ruleset string) error { return nil } +// compilePattern converts a vmodule pattern to a regular expression string. +func compilePattern(pattern string) string { + matcher := ".*" + for _, comp := range strings.Split(pattern, "/") { + if comp == "*" { + matcher += "(/.*)?" + } else if comp != "" { + matcher += "/" + regexp.QuoteMeta(comp) + } + } + if !strings.HasSuffix(pattern, ".go") { + matcher += "/[^/]+\\.go" + } + return matcher + "$" +} + 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 override not enabled and the provided verbosity is above configured return h.override.Load() || slog.Level(h.level.Load()) <= lvl } @@ -149,8 +152,7 @@ func (h *GlogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { siteCache := maps.Clone(h.siteCache) h.lock.RUnlock() - patterns := []pattern{} - patterns = append(patterns, h.patterns...) + patterns := append([]pattern{}, h.patterns...) res := GlogHandler{ origin: h.origin.WithAttrs(attrs), @@ -168,7 +170,7 @@ func (h *GlogHandler) WithGroup(name string) slog.Handler { panic("not implemented") } -// Log implements Handler.Log, filtering a log record through the global, local +// Handle implements Handler.Handle, 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 @@ -184,6 +186,7 @@ func (h *GlogHandler) Handle(_ context.Context, r slog.Record) error { // If we didn't cache the callsite yet, calculate it if !ok { h.lock.Lock() + defer h.lock.Unlock() fs := runtime.CallersFrames([]uintptr{r.PC}) frame, _ := fs.Next() @@ -191,13 +194,13 @@ func (h *GlogHandler) Handle(_ context.Context, r slog.Record) error { 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 + break } } // If no rule matched, remember to drop log the next time if !ok { h.siteCache[r.PC] = 0 } - h.lock.Unlock() } if lvl <= r.Level { return h.origin.Handle(context.Background(), r)