578 lines
16 KiB
Go
578 lines
16 KiB
Go
// Copyright 2022 The Go Authors. All rights reserved.
|
|
// Use of this source code is governed by a BSD-style
|
|
// license that can be found in the LICENSE file.
|
|
|
|
package slog
|
|
|
|
import (
|
|
"context"
|
|
"fmt"
|
|
"io"
|
|
"reflect"
|
|
"strconv"
|
|
"sync"
|
|
"time"
|
|
|
|
"golang.org/x/exp/slices"
|
|
"golang.org/x/exp/slog/internal/buffer"
|
|
)
|
|
|
|
// A Handler handles log records produced by a Logger..
|
|
//
|
|
// A typical handler may print log records to standard error,
|
|
// or write them to a file or database, or perhaps augment them
|
|
// with additional attributes and pass them on to another handler.
|
|
//
|
|
// Any of the Handler's methods may be called concurrently with itself
|
|
// or with other methods. It is the responsibility of the Handler to
|
|
// manage this concurrency.
|
|
//
|
|
// Users of the slog package should not invoke Handler methods directly.
|
|
// They should use the methods of [Logger] instead.
|
|
type Handler interface {
|
|
// Enabled reports whether the handler handles records at the given level.
|
|
// The handler ignores records whose level is lower.
|
|
// It is called early, before any arguments are processed,
|
|
// to save effort if the log event should be discarded.
|
|
// If called from a Logger method, the first argument is the context
|
|
// passed to that method, or context.Background() if nil was passed
|
|
// or the method does not take a context.
|
|
// The context is passed so Enabled can use its values
|
|
// to make a decision.
|
|
Enabled(context.Context, Level) bool
|
|
|
|
// Handle handles the Record.
|
|
// It will only be called when Enabled returns true.
|
|
// The Context argument is as for Enabled.
|
|
// It is present solely to provide Handlers access to the context's values.
|
|
// Canceling the context should not affect record processing.
|
|
// (Among other things, log messages may be necessary to debug a
|
|
// cancellation-related problem.)
|
|
//
|
|
// Handle methods that produce output should observe the following rules:
|
|
// - If r.Time is the zero time, ignore the time.
|
|
// - If r.PC is zero, ignore it.
|
|
// - Attr's values should be resolved.
|
|
// - If an Attr's key and value are both the zero value, ignore the Attr.
|
|
// This can be tested with attr.Equal(Attr{}).
|
|
// - If a group's key is empty, inline the group's Attrs.
|
|
// - If a group has no Attrs (even if it has a non-empty key),
|
|
// ignore it.
|
|
Handle(context.Context, Record) error
|
|
|
|
// WithAttrs returns a new Handler whose attributes consist of
|
|
// both the receiver's attributes and the arguments.
|
|
// The Handler owns the slice: it may retain, modify or discard it.
|
|
WithAttrs(attrs []Attr) Handler
|
|
|
|
// WithGroup returns a new Handler with the given group appended to
|
|
// the receiver's existing groups.
|
|
// The keys of all subsequent attributes, whether added by With or in a
|
|
// Record, should be qualified by the sequence of group names.
|
|
//
|
|
// How this qualification happens is up to the Handler, so long as
|
|
// this Handler's attribute keys differ from those of another Handler
|
|
// with a different sequence of group names.
|
|
//
|
|
// A Handler should treat WithGroup as starting a Group of Attrs that ends
|
|
// at the end of the log event. That is,
|
|
//
|
|
// logger.WithGroup("s").LogAttrs(level, msg, slog.Int("a", 1), slog.Int("b", 2))
|
|
//
|
|
// should behave like
|
|
//
|
|
// logger.LogAttrs(level, msg, slog.Group("s", slog.Int("a", 1), slog.Int("b", 2)))
|
|
//
|
|
// If the name is empty, WithGroup returns the receiver.
|
|
WithGroup(name string) Handler
|
|
}
|
|
|
|
type defaultHandler struct {
|
|
ch *commonHandler
|
|
// log.Output, except for testing
|
|
output func(calldepth int, message string) error
|
|
}
|
|
|
|
func newDefaultHandler(output func(int, string) error) *defaultHandler {
|
|
return &defaultHandler{
|
|
ch: &commonHandler{json: false},
|
|
output: output,
|
|
}
|
|
}
|
|
|
|
func (*defaultHandler) Enabled(_ context.Context, l Level) bool {
|
|
return l >= LevelInfo
|
|
}
|
|
|
|
// Collect the level, attributes and message in a string and
|
|
// write it with the default log.Logger.
|
|
// Let the log.Logger handle time and file/line.
|
|
func (h *defaultHandler) Handle(ctx context.Context, r Record) error {
|
|
buf := buffer.New()
|
|
buf.WriteString(r.Level.String())
|
|
buf.WriteByte(' ')
|
|
buf.WriteString(r.Message)
|
|
state := h.ch.newHandleState(buf, true, " ", nil)
|
|
defer state.free()
|
|
state.appendNonBuiltIns(r)
|
|
|
|
// skip [h.output, defaultHandler.Handle, handlerWriter.Write, log.Output]
|
|
return h.output(4, buf.String())
|
|
}
|
|
|
|
func (h *defaultHandler) WithAttrs(as []Attr) Handler {
|
|
return &defaultHandler{h.ch.withAttrs(as), h.output}
|
|
}
|
|
|
|
func (h *defaultHandler) WithGroup(name string) Handler {
|
|
return &defaultHandler{h.ch.withGroup(name), h.output}
|
|
}
|
|
|
|
// HandlerOptions are options for a TextHandler or JSONHandler.
|
|
// A zero HandlerOptions consists entirely of default values.
|
|
type HandlerOptions struct {
|
|
// AddSource causes the handler to compute the source code position
|
|
// of the log statement and add a SourceKey attribute to the output.
|
|
AddSource bool
|
|
|
|
// Level reports the minimum record level that will be logged.
|
|
// The handler discards records with lower levels.
|
|
// If Level is nil, the handler assumes LevelInfo.
|
|
// The handler calls Level.Level for each record processed;
|
|
// to adjust the minimum level dynamically, use a LevelVar.
|
|
Level Leveler
|
|
|
|
// ReplaceAttr is called to rewrite each non-group attribute before it is logged.
|
|
// The attribute's value has been resolved (see [Value.Resolve]).
|
|
// If ReplaceAttr returns an Attr with Key == "", the attribute is discarded.
|
|
//
|
|
// The built-in attributes with keys "time", "level", "source", and "msg"
|
|
// are passed to this function, except that time is omitted
|
|
// if zero, and source is omitted if AddSource is false.
|
|
//
|
|
// The first argument is a list of currently open groups that contain the
|
|
// Attr. It must not be retained or modified. ReplaceAttr is never called
|
|
// for Group attributes, only their contents. For example, the attribute
|
|
// list
|
|
//
|
|
// Int("a", 1), Group("g", Int("b", 2)), Int("c", 3)
|
|
//
|
|
// results in consecutive calls to ReplaceAttr with the following arguments:
|
|
//
|
|
// nil, Int("a", 1)
|
|
// []string{"g"}, Int("b", 2)
|
|
// nil, Int("c", 3)
|
|
//
|
|
// ReplaceAttr can be used to change the default keys of the built-in
|
|
// attributes, convert types (for example, to replace a `time.Time` with the
|
|
// integer seconds since the Unix epoch), sanitize personal information, or
|
|
// remove attributes from the output.
|
|
ReplaceAttr func(groups []string, a Attr) Attr
|
|
}
|
|
|
|
// Keys for "built-in" attributes.
|
|
const (
|
|
// TimeKey is the key used by the built-in handlers for the time
|
|
// when the log method is called. The associated Value is a [time.Time].
|
|
TimeKey = "time"
|
|
// LevelKey is the key used by the built-in handlers for the level
|
|
// of the log call. The associated value is a [Level].
|
|
LevelKey = "level"
|
|
// MessageKey is the key used by the built-in handlers for the
|
|
// message of the log call. The associated value is a string.
|
|
MessageKey = "msg"
|
|
// SourceKey is the key used by the built-in handlers for the source file
|
|
// and line of the log call. The associated value is a string.
|
|
SourceKey = "source"
|
|
)
|
|
|
|
type commonHandler struct {
|
|
json bool // true => output JSON; false => output text
|
|
opts HandlerOptions
|
|
preformattedAttrs []byte
|
|
groupPrefix string // for text: prefix of groups opened in preformatting
|
|
groups []string // all groups started from WithGroup
|
|
nOpenGroups int // the number of groups opened in preformattedAttrs
|
|
mu sync.Mutex
|
|
w io.Writer
|
|
}
|
|
|
|
func (h *commonHandler) clone() *commonHandler {
|
|
// We can't use assignment because we can't copy the mutex.
|
|
return &commonHandler{
|
|
json: h.json,
|
|
opts: h.opts,
|
|
preformattedAttrs: slices.Clip(h.preformattedAttrs),
|
|
groupPrefix: h.groupPrefix,
|
|
groups: slices.Clip(h.groups),
|
|
nOpenGroups: h.nOpenGroups,
|
|
w: h.w,
|
|
}
|
|
}
|
|
|
|
// enabled reports whether l is greater than or equal to the
|
|
// minimum level.
|
|
func (h *commonHandler) enabled(l Level) bool {
|
|
minLevel := LevelInfo
|
|
if h.opts.Level != nil {
|
|
minLevel = h.opts.Level.Level()
|
|
}
|
|
return l >= minLevel
|
|
}
|
|
|
|
func (h *commonHandler) withAttrs(as []Attr) *commonHandler {
|
|
h2 := h.clone()
|
|
// Pre-format the attributes as an optimization.
|
|
prefix := buffer.New()
|
|
defer prefix.Free()
|
|
prefix.WriteString(h.groupPrefix)
|
|
state := h2.newHandleState((*buffer.Buffer)(&h2.preformattedAttrs), false, "", prefix)
|
|
defer state.free()
|
|
if len(h2.preformattedAttrs) > 0 {
|
|
state.sep = h.attrSep()
|
|
}
|
|
state.openGroups()
|
|
for _, a := range as {
|
|
state.appendAttr(a)
|
|
}
|
|
// Remember the new prefix for later keys.
|
|
h2.groupPrefix = state.prefix.String()
|
|
// Remember how many opened groups are in preformattedAttrs,
|
|
// so we don't open them again when we handle a Record.
|
|
h2.nOpenGroups = len(h2.groups)
|
|
return h2
|
|
}
|
|
|
|
func (h *commonHandler) withGroup(name string) *commonHandler {
|
|
if name == "" {
|
|
return h
|
|
}
|
|
h2 := h.clone()
|
|
h2.groups = append(h2.groups, name)
|
|
return h2
|
|
}
|
|
|
|
func (h *commonHandler) handle(r Record) error {
|
|
state := h.newHandleState(buffer.New(), true, "", nil)
|
|
defer state.free()
|
|
if h.json {
|
|
state.buf.WriteByte('{')
|
|
}
|
|
// Built-in attributes. They are not in a group.
|
|
stateGroups := state.groups
|
|
state.groups = nil // So ReplaceAttrs sees no groups instead of the pre groups.
|
|
rep := h.opts.ReplaceAttr
|
|
// time
|
|
if !r.Time.IsZero() {
|
|
key := TimeKey
|
|
val := r.Time.Round(0) // strip monotonic to match Attr behavior
|
|
if rep == nil {
|
|
state.appendKey(key)
|
|
state.appendTime(val)
|
|
} else {
|
|
state.appendAttr(Time(key, val))
|
|
}
|
|
}
|
|
// level
|
|
key := LevelKey
|
|
val := r.Level
|
|
if rep == nil {
|
|
state.appendKey(key)
|
|
state.appendString(val.String())
|
|
} else {
|
|
state.appendAttr(Any(key, val))
|
|
}
|
|
// source
|
|
if h.opts.AddSource {
|
|
state.appendAttr(Any(SourceKey, r.source()))
|
|
}
|
|
key = MessageKey
|
|
msg := r.Message
|
|
if rep == nil {
|
|
state.appendKey(key)
|
|
state.appendString(msg)
|
|
} else {
|
|
state.appendAttr(String(key, msg))
|
|
}
|
|
state.groups = stateGroups // Restore groups passed to ReplaceAttrs.
|
|
state.appendNonBuiltIns(r)
|
|
state.buf.WriteByte('\n')
|
|
|
|
h.mu.Lock()
|
|
defer h.mu.Unlock()
|
|
_, err := h.w.Write(*state.buf)
|
|
return err
|
|
}
|
|
|
|
func (s *handleState) appendNonBuiltIns(r Record) {
|
|
// preformatted Attrs
|
|
if len(s.h.preformattedAttrs) > 0 {
|
|
s.buf.WriteString(s.sep)
|
|
s.buf.Write(s.h.preformattedAttrs)
|
|
s.sep = s.h.attrSep()
|
|
}
|
|
// Attrs in Record -- unlike the built-in ones, they are in groups started
|
|
// from WithGroup.
|
|
s.prefix = buffer.New()
|
|
defer s.prefix.Free()
|
|
s.prefix.WriteString(s.h.groupPrefix)
|
|
s.openGroups()
|
|
r.Attrs(func(a Attr) bool {
|
|
s.appendAttr(a)
|
|
return true
|
|
})
|
|
if s.h.json {
|
|
// Close all open groups.
|
|
for range s.h.groups {
|
|
s.buf.WriteByte('}')
|
|
}
|
|
// Close the top-level object.
|
|
s.buf.WriteByte('}')
|
|
}
|
|
}
|
|
|
|
// attrSep returns the separator between attributes.
|
|
func (h *commonHandler) attrSep() string {
|
|
if h.json {
|
|
return ","
|
|
}
|
|
return " "
|
|
}
|
|
|
|
// handleState holds state for a single call to commonHandler.handle.
|
|
// The initial value of sep determines whether to emit a separator
|
|
// before the next key, after which it stays true.
|
|
type handleState struct {
|
|
h *commonHandler
|
|
buf *buffer.Buffer
|
|
freeBuf bool // should buf be freed?
|
|
sep string // separator to write before next key
|
|
prefix *buffer.Buffer // for text: key prefix
|
|
groups *[]string // pool-allocated slice of active groups, for ReplaceAttr
|
|
}
|
|
|
|
var groupPool = sync.Pool{New: func() any {
|
|
s := make([]string, 0, 10)
|
|
return &s
|
|
}}
|
|
|
|
func (h *commonHandler) newHandleState(buf *buffer.Buffer, freeBuf bool, sep string, prefix *buffer.Buffer) handleState {
|
|
s := handleState{
|
|
h: h,
|
|
buf: buf,
|
|
freeBuf: freeBuf,
|
|
sep: sep,
|
|
prefix: prefix,
|
|
}
|
|
if h.opts.ReplaceAttr != nil {
|
|
s.groups = groupPool.Get().(*[]string)
|
|
*s.groups = append(*s.groups, h.groups[:h.nOpenGroups]...)
|
|
}
|
|
return s
|
|
}
|
|
|
|
func (s *handleState) free() {
|
|
if s.freeBuf {
|
|
s.buf.Free()
|
|
}
|
|
if gs := s.groups; gs != nil {
|
|
*gs = (*gs)[:0]
|
|
groupPool.Put(gs)
|
|
}
|
|
}
|
|
|
|
func (s *handleState) openGroups() {
|
|
for _, n := range s.h.groups[s.h.nOpenGroups:] {
|
|
s.openGroup(n)
|
|
}
|
|
}
|
|
|
|
// Separator for group names and keys.
|
|
const keyComponentSep = '.'
|
|
|
|
// openGroup starts a new group of attributes
|
|
// with the given name.
|
|
func (s *handleState) openGroup(name string) {
|
|
if s.h.json {
|
|
s.appendKey(name)
|
|
s.buf.WriteByte('{')
|
|
s.sep = ""
|
|
} else {
|
|
s.prefix.WriteString(name)
|
|
s.prefix.WriteByte(keyComponentSep)
|
|
}
|
|
// Collect group names for ReplaceAttr.
|
|
if s.groups != nil {
|
|
*s.groups = append(*s.groups, name)
|
|
}
|
|
}
|
|
|
|
// closeGroup ends the group with the given name.
|
|
func (s *handleState) closeGroup(name string) {
|
|
if s.h.json {
|
|
s.buf.WriteByte('}')
|
|
} else {
|
|
(*s.prefix) = (*s.prefix)[:len(*s.prefix)-len(name)-1 /* for keyComponentSep */]
|
|
}
|
|
s.sep = s.h.attrSep()
|
|
if s.groups != nil {
|
|
*s.groups = (*s.groups)[:len(*s.groups)-1]
|
|
}
|
|
}
|
|
|
|
// appendAttr appends the Attr's key and value using app.
|
|
// It handles replacement and checking for an empty key.
|
|
// after replacement).
|
|
func (s *handleState) appendAttr(a Attr) {
|
|
if rep := s.h.opts.ReplaceAttr; rep != nil && a.Value.Kind() != KindGroup {
|
|
var gs []string
|
|
if s.groups != nil {
|
|
gs = *s.groups
|
|
}
|
|
// Resolve before calling ReplaceAttr, so the user doesn't have to.
|
|
a.Value = a.Value.Resolve()
|
|
a = rep(gs, a)
|
|
}
|
|
a.Value = a.Value.Resolve()
|
|
// Elide empty Attrs.
|
|
if a.isEmpty() {
|
|
return
|
|
}
|
|
// Special case: Source.
|
|
if v := a.Value; v.Kind() == KindAny {
|
|
if src, ok := v.Any().(*Source); ok {
|
|
if s.h.json {
|
|
a.Value = src.group()
|
|
} else {
|
|
a.Value = StringValue(fmt.Sprintf("%s:%d", src.File, src.Line))
|
|
}
|
|
}
|
|
}
|
|
if a.Value.Kind() == KindGroup {
|
|
attrs := a.Value.Group()
|
|
// Output only non-empty groups.
|
|
if len(attrs) > 0 {
|
|
// Inline a group with an empty key.
|
|
if a.Key != "" {
|
|
s.openGroup(a.Key)
|
|
}
|
|
for _, aa := range attrs {
|
|
s.appendAttr(aa)
|
|
}
|
|
if a.Key != "" {
|
|
s.closeGroup(a.Key)
|
|
}
|
|
}
|
|
} else {
|
|
s.appendKey(a.Key)
|
|
s.appendValue(a.Value)
|
|
}
|
|
}
|
|
|
|
func (s *handleState) appendError(err error) {
|
|
s.appendString(fmt.Sprintf("!ERROR:%v", err))
|
|
}
|
|
|
|
func (s *handleState) appendKey(key string) {
|
|
s.buf.WriteString(s.sep)
|
|
if s.prefix != nil {
|
|
// TODO: optimize by avoiding allocation.
|
|
s.appendString(string(*s.prefix) + key)
|
|
} else {
|
|
s.appendString(key)
|
|
}
|
|
if s.h.json {
|
|
s.buf.WriteByte(':')
|
|
} else {
|
|
s.buf.WriteByte('=')
|
|
}
|
|
s.sep = s.h.attrSep()
|
|
}
|
|
|
|
func (s *handleState) appendString(str string) {
|
|
if s.h.json {
|
|
s.buf.WriteByte('"')
|
|
*s.buf = appendEscapedJSONString(*s.buf, str)
|
|
s.buf.WriteByte('"')
|
|
} else {
|
|
// text
|
|
if needsQuoting(str) {
|
|
*s.buf = strconv.AppendQuote(*s.buf, str)
|
|
} else {
|
|
s.buf.WriteString(str)
|
|
}
|
|
}
|
|
}
|
|
|
|
func (s *handleState) appendValue(v Value) {
|
|
defer func() {
|
|
if r := recover(); r != nil {
|
|
// If it panics with a nil pointer, the most likely cases are
|
|
// an encoding.TextMarshaler or error fails to guard against nil,
|
|
// in which case "<nil>" seems to be the feasible choice.
|
|
//
|
|
// Adapted from the code in fmt/print.go.
|
|
if v := reflect.ValueOf(v.any); v.Kind() == reflect.Pointer && v.IsNil() {
|
|
s.appendString("<nil>")
|
|
return
|
|
}
|
|
|
|
// Otherwise just print the original panic message.
|
|
s.appendString(fmt.Sprintf("!PANIC: %v", r))
|
|
}
|
|
}()
|
|
|
|
var err error
|
|
if s.h.json {
|
|
err = appendJSONValue(s, v)
|
|
} else {
|
|
err = appendTextValue(s, v)
|
|
}
|
|
if err != nil {
|
|
s.appendError(err)
|
|
}
|
|
}
|
|
|
|
func (s *handleState) appendTime(t time.Time) {
|
|
if s.h.json {
|
|
appendJSONTime(s, t)
|
|
} else {
|
|
writeTimeRFC3339Millis(s.buf, t)
|
|
}
|
|
}
|
|
|
|
// This takes half the time of Time.AppendFormat.
|
|
func writeTimeRFC3339Millis(buf *buffer.Buffer, t time.Time) {
|
|
year, month, day := t.Date()
|
|
buf.WritePosIntWidth(year, 4)
|
|
buf.WriteByte('-')
|
|
buf.WritePosIntWidth(int(month), 2)
|
|
buf.WriteByte('-')
|
|
buf.WritePosIntWidth(day, 2)
|
|
buf.WriteByte('T')
|
|
hour, min, sec := t.Clock()
|
|
buf.WritePosIntWidth(hour, 2)
|
|
buf.WriteByte(':')
|
|
buf.WritePosIntWidth(min, 2)
|
|
buf.WriteByte(':')
|
|
buf.WritePosIntWidth(sec, 2)
|
|
ns := t.Nanosecond()
|
|
buf.WriteByte('.')
|
|
buf.WritePosIntWidth(ns/1e6, 3)
|
|
_, offsetSeconds := t.Zone()
|
|
if offsetSeconds == 0 {
|
|
buf.WriteByte('Z')
|
|
} else {
|
|
offsetMinutes := offsetSeconds / 60
|
|
if offsetMinutes < 0 {
|
|
buf.WriteByte('-')
|
|
offsetMinutes = -offsetMinutes
|
|
} else {
|
|
buf.WriteByte('+')
|
|
}
|
|
buf.WritePosIntWidth(offsetMinutes/60, 2)
|
|
buf.WriteByte(':')
|
|
buf.WritePosIntWidth(offsetMinutes%60, 2)
|
|
}
|
|
}
|