| // 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) |
| } |
| } |