2017-02-20 17:39:36 +02:00
|
|
|
package log
|
|
|
|
|
|
|
|
import (
|
2023-11-29 15:33:50 +08:00
|
|
|
"context"
|
2017-02-20 17:39:36 +02:00
|
|
|
"fmt"
|
|
|
|
"io"
|
2023-11-29 15:33:50 +08:00
|
|
|
"math/big"
|
2017-02-20 17:39:36 +02:00
|
|
|
"os"
|
2020-05-20 11:47:42 +08:00
|
|
|
"path"
|
2017-02-20 17:39:36 +02:00
|
|
|
"reflect"
|
|
|
|
"sync"
|
2023-11-29 15:33:50 +08:00
|
|
|
"time"
|
2017-02-20 17:39:36 +02:00
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
"github.com/holiman/uint256"
|
|
|
|
"golang.org/x/exp/slog"
|
2017-02-20 17:39:36 +02:00
|
|
|
)
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
type discardHandler struct{}
|
2017-02-20 17:39:36 +02:00
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
// DiscardHandler returns a no-op handler
|
|
|
|
func DiscardHandler() slog.Handler {
|
|
|
|
return &discardHandler{}
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (h *discardHandler) Handle(_ context.Context, r slog.Record) error {
|
|
|
|
return nil
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (h *discardHandler) Enabled(_ context.Context, level slog.Level) bool {
|
|
|
|
return false
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (h *discardHandler) WithGroup(name string) slog.Handler {
|
|
|
|
panic("not implemented")
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (h *discardHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
|
|
|
|
return &discardHandler{}
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
type TerminalHandler struct {
|
|
|
|
mu sync.Mutex
|
|
|
|
wr io.Writer
|
|
|
|
lvl slog.Level
|
|
|
|
useColor bool
|
|
|
|
attrs []slog.Attr
|
|
|
|
// fieldPadding is a map with maximum field value lengths seen until now
|
|
|
|
// to allow padding log contexts in a bit smarter way.
|
|
|
|
fieldPadding map[string]int
|
2022-04-08 10:02:16 -04:00
|
|
|
|
slog: faster and less memory-consumption (#28621)
These changes improves the performance of the non-coloured terminal formatting, _quite a lot_.
```
name old time/op new time/op delta
TerminalHandler-8 10.2µs ±15% 5.4µs ± 9% -47.02% (p=0.008 n=5+5)
name old alloc/op new alloc/op delta
TerminalHandler-8 2.17kB ± 0% 0.40kB ± 0% -81.46% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
TerminalHandler-8 33.0 ± 0% 5.0 ± 0% -84.85% (p=0.008 n=5+5)
```
I tried to _somewhat_ organize the commits, but the it might still be a bit chaotic. Some core insights:
- The function `terminalHandler.Handl` uses a mutex, and writes all output immediately to 'upstream'. Thus, it can reuse a scratch-buffer every time.
- This buffer can be propagated internally, making all the internal formatters either write directly to it,
- OR, make use of the `tmp := buf.AvailableBuffer()` in some cases, where a byte buffer "extra capacity" can be temporarily used.
- The `slog` package uses `Attr` by value. It makes sense to minimize operating on them, since iterating / collecting into a new slice, iterating again etc causes copy-on-heap. Better to operate on them only once.
- If we want to do padding, it's better to copy from a constant `space`-buffer than to invoke `bytes.Repeat` every single time.
2023-12-01 13:28:20 +01:00
|
|
|
buf []byte
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
// NewTerminalHandler returns a handler which formats log records at all levels optimized for human readability on
|
|
|
|
// a terminal with color-coded level output and terser human friendly timestamp.
|
|
|
|
// This format should only be used for interactive programs or while developing.
|
2017-02-20 17:39:36 +02:00
|
|
|
//
|
2023-11-29 15:33:50 +08:00
|
|
|
// [LEVEL] [TIME] MESSAGE key=value key=value ...
|
2017-02-20 17:39:36 +02:00
|
|
|
//
|
2023-11-29 15:33:50 +08:00
|
|
|
// Example:
|
2017-02-20 17:39:36 +02:00
|
|
|
//
|
2023-11-29 15:33:50 +08:00
|
|
|
// [DBUG] [May 16 20:58:45] remove route ns=haproxy addr=127.0.0.1:50002
|
|
|
|
func NewTerminalHandler(wr io.Writer, useColor bool) *TerminalHandler {
|
|
|
|
return NewTerminalHandlerWithLevel(wr, levelMaxVerbosity, useColor)
|
|
|
|
}
|
|
|
|
|
|
|
|
// NewTerminalHandlerWithLevel returns the same handler as NewTerminalHandler but only outputs
|
|
|
|
// records which are less than or equal to the specified verbosity level.
|
|
|
|
func NewTerminalHandlerWithLevel(wr io.Writer, lvl slog.Level, useColor bool) *TerminalHandler {
|
|
|
|
return &TerminalHandler{
|
|
|
|
wr: wr,
|
|
|
|
lvl: lvl,
|
|
|
|
useColor: useColor,
|
|
|
|
fieldPadding: make(map[string]int),
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (h *TerminalHandler) Handle(_ context.Context, r slog.Record) error {
|
|
|
|
h.mu.Lock()
|
|
|
|
defer h.mu.Unlock()
|
log: remove lazy, remove unused interfaces, unexport methods (#28622)
This change
- Removes interface `log.Format`,
- Removes method `log.FormatFunc`,
- unexports `TerminalHandler.TerminalFormat` formatting methods (renamed to `TerminalHandler.format`)
- removes the notion of `log.Lazy` values
The lazy handler was useful in the old log package, since it
could defer the evaluation of costly attributes until later in the
log pipeline: thus, if the logging was done at 'Trace', we could
skip evaluation if logging only was set to 'Info'.
With the move to slog, this way of deferring evaluation is no longer
needed, since slog introduced 'Enabled': the caller can thus do
the evaluate-or-not decision at the callsite, which is much more
straight-forward than dealing with lazy reflect-based evaluation.
Also, lazy evaluation would not work with 'native' slog, as in, these
two statements would be evaluated differently:
```golang
log.Info("foo", "my lazy", lazyObj)
slog.Info("foo", "my lazy", lazyObj)
```
2023-12-05 11:54:44 +01:00
|
|
|
buf := h.format(h.buf, r, h.useColor)
|
slog: faster and less memory-consumption (#28621)
These changes improves the performance of the non-coloured terminal formatting, _quite a lot_.
```
name old time/op new time/op delta
TerminalHandler-8 10.2µs ±15% 5.4µs ± 9% -47.02% (p=0.008 n=5+5)
name old alloc/op new alloc/op delta
TerminalHandler-8 2.17kB ± 0% 0.40kB ± 0% -81.46% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
TerminalHandler-8 33.0 ± 0% 5.0 ± 0% -84.85% (p=0.008 n=5+5)
```
I tried to _somewhat_ organize the commits, but the it might still be a bit chaotic. Some core insights:
- The function `terminalHandler.Handl` uses a mutex, and writes all output immediately to 'upstream'. Thus, it can reuse a scratch-buffer every time.
- This buffer can be propagated internally, making all the internal formatters either write directly to it,
- OR, make use of the `tmp := buf.AvailableBuffer()` in some cases, where a byte buffer "extra capacity" can be temporarily used.
- The `slog` package uses `Attr` by value. It makes sense to minimize operating on them, since iterating / collecting into a new slice, iterating again etc causes copy-on-heap. Better to operate on them only once.
- If we want to do padding, it's better to copy from a constant `space`-buffer than to invoke `bytes.Repeat` every single time.
2023-12-01 13:28:20 +01:00
|
|
|
h.wr.Write(buf)
|
|
|
|
h.buf = buf[:0]
|
2023-11-29 15:33:50 +08:00
|
|
|
return nil
|
2020-05-20 11:47:42 +08:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (h *TerminalHandler) Enabled(_ context.Context, level slog.Level) bool {
|
|
|
|
return level >= h.lvl
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (h *TerminalHandler) WithGroup(name string) slog.Handler {
|
|
|
|
panic("not implemented")
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (h *TerminalHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
|
|
|
|
return &TerminalHandler{
|
|
|
|
wr: h.wr,
|
|
|
|
lvl: h.lvl,
|
|
|
|
useColor: h.useColor,
|
|
|
|
attrs: append(h.attrs, attrs...),
|
|
|
|
fieldPadding: make(map[string]int),
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
// ResetFieldPadding zeroes the field-padding for all attribute pairs.
|
|
|
|
func (t *TerminalHandler) ResetFieldPadding() {
|
|
|
|
t.mu.Lock()
|
|
|
|
t.fieldPadding = make(map[string]int)
|
|
|
|
t.mu.Unlock()
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
type leveler struct{ minLevel slog.Level }
|
2017-02-20 17:39:36 +02:00
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func (l *leveler) Level() slog.Level {
|
|
|
|
return l.minLevel
|
2017-03-23 15:48:30 +01:00
|
|
|
}
|
|
|
|
|
log: remove lazy, remove unused interfaces, unexport methods (#28622)
This change
- Removes interface `log.Format`,
- Removes method `log.FormatFunc`,
- unexports `TerminalHandler.TerminalFormat` formatting methods (renamed to `TerminalHandler.format`)
- removes the notion of `log.Lazy` values
The lazy handler was useful in the old log package, since it
could defer the evaluation of costly attributes until later in the
log pipeline: thus, if the logging was done at 'Trace', we could
skip evaluation if logging only was set to 'Info'.
With the move to slog, this way of deferring evaluation is no longer
needed, since slog introduced 'Enabled': the caller can thus do
the evaluate-or-not decision at the callsite, which is much more
straight-forward than dealing with lazy reflect-based evaluation.
Also, lazy evaluation would not work with 'native' slog, as in, these
two statements would be evaluated differently:
```golang
log.Info("foo", "my lazy", lazyObj)
slog.Info("foo", "my lazy", lazyObj)
```
2023-12-05 11:54:44 +01:00
|
|
|
// JSONHandler returns a handler which prints records in JSON format.
|
2023-11-29 15:33:50 +08:00
|
|
|
func JSONHandler(wr io.Writer) slog.Handler {
|
|
|
|
return slog.NewJSONHandler(wr, &slog.HandlerOptions{
|
|
|
|
ReplaceAttr: builtinReplaceJSON,
|
2017-02-20 17:39:36 +02:00
|
|
|
})
|
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
// LogfmtHandler returns a handler which prints records in logfmt format, an easy machine-parseable but human-readable
|
|
|
|
// format for key/value pairs.
|
2017-02-20 17:39:36 +02:00
|
|
|
//
|
2023-11-29 15:33:50 +08:00
|
|
|
// For more details see: http://godoc.org/github.com/kr/logfmt
|
|
|
|
func LogfmtHandler(wr io.Writer) slog.Handler {
|
|
|
|
return slog.NewTextHandler(wr, &slog.HandlerOptions{
|
|
|
|
ReplaceAttr: builtinReplaceLogfmt,
|
2017-02-20 17:39:36 +02:00
|
|
|
})
|
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
// LogfmtHandlerWithLevel returns the same handler as LogfmtHandler but it only outputs
|
|
|
|
// records which are less than or equal to the specified verbosity level.
|
|
|
|
func LogfmtHandlerWithLevel(wr io.Writer, level slog.Level) slog.Handler {
|
|
|
|
return slog.NewTextHandler(wr, &slog.HandlerOptions{
|
|
|
|
ReplaceAttr: builtinReplaceLogfmt,
|
|
|
|
Level: &leveler{level},
|
2017-02-20 17:39:36 +02:00
|
|
|
})
|
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func builtinReplaceLogfmt(_ []string, attr slog.Attr) slog.Attr {
|
|
|
|
return builtinReplace(nil, attr, true)
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func builtinReplaceJSON(_ []string, attr slog.Attr) slog.Attr {
|
|
|
|
return builtinReplace(nil, attr, false)
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
func builtinReplace(_ []string, attr slog.Attr, logfmt bool) slog.Attr {
|
|
|
|
switch attr.Key {
|
|
|
|
case slog.TimeKey:
|
|
|
|
if attr.Value.Kind() == slog.KindTime {
|
|
|
|
if logfmt {
|
|
|
|
return slog.String("t", attr.Value.Time().Format(timeFormat))
|
|
|
|
} else {
|
|
|
|
return slog.Attr{Key: "t", Value: attr.Value}
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
}
|
2023-11-29 15:33:50 +08:00
|
|
|
case slog.LevelKey:
|
|
|
|
if l, ok := attr.Value.Any().(slog.Level); ok {
|
|
|
|
attr = slog.Any("lvl", LevelString(l))
|
|
|
|
return attr
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2023-11-29 15:33:50 +08:00
|
|
|
switch v := attr.Value.Any().(type) {
|
|
|
|
case time.Time:
|
|
|
|
if logfmt {
|
|
|
|
attr = slog.String(attr.Key, v.Format(timeFormat))
|
|
|
|
}
|
|
|
|
case *big.Int:
|
|
|
|
if v == nil {
|
|
|
|
attr.Value = slog.StringValue("<nil>")
|
|
|
|
} else {
|
|
|
|
attr.Value = slog.StringValue(v.String())
|
|
|
|
}
|
|
|
|
case *uint256.Int:
|
|
|
|
if v == nil {
|
|
|
|
attr.Value = slog.StringValue("<nil>")
|
|
|
|
} else {
|
|
|
|
attr.Value = slog.StringValue(v.Dec())
|
|
|
|
}
|
|
|
|
case fmt.Stringer:
|
|
|
|
if v == nil || (reflect.ValueOf(v).Kind() == reflect.Pointer && reflect.ValueOf(v).IsNil()) {
|
|
|
|
attr.Value = slog.StringValue("<nil>")
|
|
|
|
} else {
|
|
|
|
attr.Value = slog.StringValue(v.String())
|
|
|
|
}
|
2018-05-03 01:30:12 -07:00
|
|
|
}
|
2023-11-29 15:33:50 +08:00
|
|
|
return attr
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|
|
|
|
|
2024-02-02 15:43:33 +08:00
|
|
|
// RotatingFileHandler returns a handler which writes log records to file chunks
|
|
|
|
// at the given path. When a file's size reaches the limit, the handler creates
|
|
|
|
// a new file named after the timestamp of the first log record it will contain.
|
|
|
|
func RotatingFileHandler(filePath string, limit uint, maxBackups uint, level string, rotateHours uint) slog.Handler {
|
|
|
|
if _, err := os.Stat(path.Dir(filePath)); os.IsNotExist(err) {
|
|
|
|
err := os.MkdirAll(path.Dir(filePath), 0755)
|
|
|
|
if err != nil {
|
|
|
|
panic(fmt.Errorf("could not create directory %s, %v", path.Dir(filePath), err))
|
|
|
|
}
|
|
|
|
}
|
|
|
|
logLevel, err := LevelFromString(level)
|
2017-02-20 17:39:36 +02:00
|
|
|
if err != nil {
|
|
|
|
panic(err)
|
|
|
|
}
|
2024-02-02 15:43:33 +08:00
|
|
|
fileWriter := NewAsyncFileWriter(filePath, int64(limit), int(maxBackups), rotateHours)
|
|
|
|
fileWriter.Start()
|
|
|
|
return LogfmtHandlerWithLevel(fileWriter, logLevel)
|
2017-02-20 17:39:36 +02:00
|
|
|
}
|