github.com/AndrienkoAleksandr/go@v0.0.19/src/log/slog/handler.go (about)

     1  // Copyright 2022 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  package slog
     6  
     7  import (
     8  	"context"
     9  	"fmt"
    10  	"io"
    11  	"log/slog/internal/buffer"
    12  	"slices"
    13  	"strconv"
    14  	"sync"
    15  	"time"
    16  )
    17  
    18  // A Handler handles log records produced by a Logger..
    19  //
    20  // A typical handler may print log records to standard error,
    21  // or write them to a file or database, or perhaps augment them
    22  // with additional attributes and pass them on to another handler.
    23  //
    24  // Any of the Handler's methods may be called concurrently with itself
    25  // or with other methods. It is the responsibility of the Handler to
    26  // manage this concurrency.
    27  //
    28  // Users of the slog package should not invoke Handler methods directly.
    29  // They should use the methods of [Logger] instead.
    30  type Handler interface {
    31  	// Enabled reports whether the handler handles records at the given level.
    32  	// The handler ignores records whose level is lower.
    33  	// It is called early, before any arguments are processed,
    34  	// to save effort if the log event should be discarded.
    35  	// If called from a Logger method, the first argument is the context
    36  	// passed to that method, or context.Background() if nil was passed
    37  	// or the method does not take a context.
    38  	// The context is passed so Enabled can use its values
    39  	// to make a decision.
    40  	Enabled(context.Context, Level) bool
    41  
    42  	// Handle handles the Record.
    43  	// It will only be called when Enabled returns true.
    44  	// The Context argument is as for Enabled.
    45  	// It is present solely to provide Handlers access to the context's values.
    46  	// Canceling the context should not affect record processing.
    47  	// (Among other things, log messages may be necessary to debug a
    48  	// cancellation-related problem.)
    49  	//
    50  	// Handle methods that produce output should observe the following rules:
    51  	//   - If r.Time is the zero time, ignore the time.
    52  	//   - If r.PC is zero, ignore it.
    53  	//   - Attr's values should be resolved.
    54  	//   - If an Attr's key and value are both the zero value, ignore the Attr.
    55  	//     This can be tested with attr.Equal(Attr{}).
    56  	//   - If a group's key is empty, inline the group's Attrs.
    57  	//   - If a group has no Attrs (even if it has a non-empty key),
    58  	//     ignore it.
    59  	Handle(context.Context, Record) error
    60  
    61  	// WithAttrs returns a new Handler whose attributes consist of
    62  	// both the receiver's attributes and the arguments.
    63  	// The Handler owns the slice: it may retain, modify or discard it.
    64  	WithAttrs(attrs []Attr) Handler
    65  
    66  	// WithGroup returns a new Handler with the given group appended to
    67  	// the receiver's existing groups.
    68  	// The keys of all subsequent attributes, whether added by With or in a
    69  	// Record, should be qualified by the sequence of group names.
    70  	//
    71  	// How this qualification happens is up to the Handler, so long as
    72  	// this Handler's attribute keys differ from those of another Handler
    73  	// with a different sequence of group names.
    74  	//
    75  	// A Handler should treat WithGroup as starting a Group of Attrs that ends
    76  	// at the end of the log event. That is,
    77  	//
    78  	//     logger.WithGroup("s").LogAttrs(level, msg, slog.Int("a", 1), slog.Int("b", 2))
    79  	//
    80  	// should behave like
    81  	//
    82  	//     logger.LogAttrs(level, msg, slog.Group("s", slog.Int("a", 1), slog.Int("b", 2)))
    83  	//
    84  	// If the name is empty, WithGroup returns the receiver.
    85  	WithGroup(name string) Handler
    86  }
    87  
    88  type defaultHandler struct {
    89  	ch *commonHandler
    90  	// internal.DefaultOutput, except for testing
    91  	output func(pc uintptr, data []byte) error
    92  }
    93  
    94  func newDefaultHandler(output func(uintptr, []byte) error) *defaultHandler {
    95  	return &defaultHandler{
    96  		ch:     &commonHandler{json: false},
    97  		output: output,
    98  	}
    99  }
   100  
   101  func (*defaultHandler) Enabled(_ context.Context, l Level) bool {
   102  	return l >= LevelInfo
   103  }
   104  
   105  // Collect the level, attributes and message in a string and
   106  // write it with the default log.Logger.
   107  // Let the log.Logger handle time and file/line.
   108  func (h *defaultHandler) Handle(ctx context.Context, r Record) error {
   109  	buf := buffer.New()
   110  	buf.WriteString(r.Level.String())
   111  	buf.WriteByte(' ')
   112  	buf.WriteString(r.Message)
   113  	state := h.ch.newHandleState(buf, true, " ")
   114  	defer state.free()
   115  	state.appendNonBuiltIns(r)
   116  	return h.output(r.PC, *buf)
   117  }
   118  
   119  func (h *defaultHandler) WithAttrs(as []Attr) Handler {
   120  	return &defaultHandler{h.ch.withAttrs(as), h.output}
   121  }
   122  
   123  func (h *defaultHandler) WithGroup(name string) Handler {
   124  	return &defaultHandler{h.ch.withGroup(name), h.output}
   125  }
   126  
   127  // HandlerOptions are options for a TextHandler or JSONHandler.
   128  // A zero HandlerOptions consists entirely of default values.
   129  type HandlerOptions struct {
   130  	// AddSource causes the handler to compute the source code position
   131  	// of the log statement and add a SourceKey attribute to the output.
   132  	AddSource bool
   133  
   134  	// Level reports the minimum record level that will be logged.
   135  	// The handler discards records with lower levels.
   136  	// If Level is nil, the handler assumes LevelInfo.
   137  	// The handler calls Level.Level for each record processed;
   138  	// to adjust the minimum level dynamically, use a LevelVar.
   139  	Level Leveler
   140  
   141  	// ReplaceAttr is called to rewrite each non-group attribute before it is logged.
   142  	// The attribute's value has been resolved (see [Value.Resolve]).
   143  	// If ReplaceAttr returns an Attr with Key == "", the attribute is discarded.
   144  	//
   145  	// The built-in attributes with keys "time", "level", "source", and "msg"
   146  	// are passed to this function, except that time is omitted
   147  	// if zero, and source is omitted if AddSource is false.
   148  	//
   149  	// The first argument is a list of currently open groups that contain the
   150  	// Attr. It must not be retained or modified. ReplaceAttr is never called
   151  	// for Group attributes, only their contents. For example, the attribute
   152  	// list
   153  	//
   154  	//     Int("a", 1), Group("g", Int("b", 2)), Int("c", 3)
   155  	//
   156  	// results in consecutive calls to ReplaceAttr with the following arguments:
   157  	//
   158  	//     nil, Int("a", 1)
   159  	//     []string{"g"}, Int("b", 2)
   160  	//     nil, Int("c", 3)
   161  	//
   162  	// ReplaceAttr can be used to change the default keys of the built-in
   163  	// attributes, convert types (for example, to replace a `time.Time` with the
   164  	// integer seconds since the Unix epoch), sanitize personal information, or
   165  	// remove attributes from the output.
   166  	ReplaceAttr func(groups []string, a Attr) Attr
   167  }
   168  
   169  // Keys for "built-in" attributes.
   170  const (
   171  	// TimeKey is the key used by the built-in handlers for the time
   172  	// when the log method is called. The associated Value is a [time.Time].
   173  	TimeKey = "time"
   174  	// LevelKey is the key used by the built-in handlers for the level
   175  	// of the log call. The associated value is a [Level].
   176  	LevelKey = "level"
   177  	// MessageKey is the key used by the built-in handlers for the
   178  	// message of the log call. The associated value is a string.
   179  	MessageKey = "msg"
   180  	// SourceKey is the key used by the built-in handlers for the source file
   181  	// and line of the log call. The associated value is a string.
   182  	SourceKey = "source"
   183  )
   184  
   185  type commonHandler struct {
   186  	json              bool // true => output JSON; false => output text
   187  	opts              HandlerOptions
   188  	preformattedAttrs []byte
   189  	// groupPrefix is for the text handler only.
   190  	// It holds the prefix for groups that were already pre-formatted.
   191  	// A group will appear here when a call to WithGroup is followed by
   192  	// a call to WithAttrs.
   193  	groupPrefix string
   194  	groups      []string // all groups started from WithGroup
   195  	nOpenGroups int      // the number of groups opened in preformattedAttrs
   196  	mu          sync.Mutex
   197  	w           io.Writer
   198  }
   199  
   200  func (h *commonHandler) clone() *commonHandler {
   201  	// We can't use assignment because we can't copy the mutex.
   202  	return &commonHandler{
   203  		json:              h.json,
   204  		opts:              h.opts,
   205  		preformattedAttrs: slices.Clip(h.preformattedAttrs),
   206  		groupPrefix:       h.groupPrefix,
   207  		groups:            slices.Clip(h.groups),
   208  		nOpenGroups:       h.nOpenGroups,
   209  		w:                 h.w,
   210  	}
   211  }
   212  
   213  // enabled reports whether l is greater than or equal to the
   214  // minimum level.
   215  func (h *commonHandler) enabled(l Level) bool {
   216  	minLevel := LevelInfo
   217  	if h.opts.Level != nil {
   218  		minLevel = h.opts.Level.Level()
   219  	}
   220  	return l >= minLevel
   221  }
   222  
   223  func (h *commonHandler) withAttrs(as []Attr) *commonHandler {
   224  	h2 := h.clone()
   225  	// Pre-format the attributes as an optimization.
   226  	state := h2.newHandleState((*buffer.Buffer)(&h2.preformattedAttrs), false, "")
   227  	defer state.free()
   228  	state.prefix.WriteString(h.groupPrefix)
   229  	if len(h2.preformattedAttrs) > 0 {
   230  		state.sep = h.attrSep()
   231  	}
   232  	state.openGroups()
   233  	for _, a := range as {
   234  		state.appendAttr(a)
   235  	}
   236  	// Remember the new prefix for later keys.
   237  	h2.groupPrefix = state.prefix.String()
   238  	// Remember how many opened groups are in preformattedAttrs,
   239  	// so we don't open them again when we handle a Record.
   240  	h2.nOpenGroups = len(h2.groups)
   241  	return h2
   242  }
   243  
   244  func (h *commonHandler) withGroup(name string) *commonHandler {
   245  	h2 := h.clone()
   246  	h2.groups = append(h2.groups, name)
   247  	return h2
   248  }
   249  
   250  func (h *commonHandler) handle(r Record) error {
   251  	state := h.newHandleState(buffer.New(), true, "")
   252  	defer state.free()
   253  	if h.json {
   254  		state.buf.WriteByte('{')
   255  	}
   256  	// Built-in attributes. They are not in a group.
   257  	stateGroups := state.groups
   258  	state.groups = nil // So ReplaceAttrs sees no groups instead of the pre groups.
   259  	rep := h.opts.ReplaceAttr
   260  	// time
   261  	if !r.Time.IsZero() {
   262  		key := TimeKey
   263  		val := r.Time.Round(0) // strip monotonic to match Attr behavior
   264  		if rep == nil {
   265  			state.appendKey(key)
   266  			state.appendTime(val)
   267  		} else {
   268  			state.appendAttr(Time(key, val))
   269  		}
   270  	}
   271  	// level
   272  	key := LevelKey
   273  	val := r.Level
   274  	if rep == nil {
   275  		state.appendKey(key)
   276  		state.appendString(val.String())
   277  	} else {
   278  		state.appendAttr(Any(key, val))
   279  	}
   280  	// source
   281  	if h.opts.AddSource {
   282  		state.appendAttr(Any(SourceKey, r.source()))
   283  	}
   284  	key = MessageKey
   285  	msg := r.Message
   286  	if rep == nil {
   287  		state.appendKey(key)
   288  		state.appendString(msg)
   289  	} else {
   290  		state.appendAttr(String(key, msg))
   291  	}
   292  	state.groups = stateGroups // Restore groups passed to ReplaceAttrs.
   293  	state.appendNonBuiltIns(r)
   294  	state.buf.WriteByte('\n')
   295  
   296  	h.mu.Lock()
   297  	defer h.mu.Unlock()
   298  	_, err := h.w.Write(*state.buf)
   299  	return err
   300  }
   301  
   302  func (s *handleState) appendNonBuiltIns(r Record) {
   303  	// preformatted Attrs
   304  	if len(s.h.preformattedAttrs) > 0 {
   305  		s.buf.WriteString(s.sep)
   306  		s.buf.Write(s.h.preformattedAttrs)
   307  		s.sep = s.h.attrSep()
   308  	}
   309  	// Attrs in Record -- unlike the built-in ones, they are in groups started
   310  	// from WithGroup.
   311  	s.prefix.WriteString(s.h.groupPrefix)
   312  	s.openGroups()
   313  	r.Attrs(func(a Attr) bool {
   314  		s.appendAttr(a)
   315  		return true
   316  	})
   317  	if s.h.json {
   318  		// Close all open groups.
   319  		for range s.h.groups {
   320  			s.buf.WriteByte('}')
   321  		}
   322  		// Close the top-level object.
   323  		s.buf.WriteByte('}')
   324  	}
   325  }
   326  
   327  // attrSep returns the separator between attributes.
   328  func (h *commonHandler) attrSep() string {
   329  	if h.json {
   330  		return ","
   331  	}
   332  	return " "
   333  }
   334  
   335  // handleState holds state for a single call to commonHandler.handle.
   336  // The initial value of sep determines whether to emit a separator
   337  // before the next key, after which it stays true.
   338  type handleState struct {
   339  	h       *commonHandler
   340  	buf     *buffer.Buffer
   341  	freeBuf bool           // should buf be freed?
   342  	sep     string         // separator to write before next key
   343  	prefix  *buffer.Buffer // for text: key prefix
   344  	groups  *[]string      // pool-allocated slice of active groups, for ReplaceAttr
   345  }
   346  
   347  var groupPool = sync.Pool{New: func() any {
   348  	s := make([]string, 0, 10)
   349  	return &s
   350  }}
   351  
   352  func (h *commonHandler) newHandleState(buf *buffer.Buffer, freeBuf bool, sep string) handleState {
   353  	s := handleState{
   354  		h:       h,
   355  		buf:     buf,
   356  		freeBuf: freeBuf,
   357  		sep:     sep,
   358  		prefix:  buffer.New(),
   359  	}
   360  	if h.opts.ReplaceAttr != nil {
   361  		s.groups = groupPool.Get().(*[]string)
   362  		*s.groups = append(*s.groups, h.groups[:h.nOpenGroups]...)
   363  	}
   364  	return s
   365  }
   366  
   367  func (s *handleState) free() {
   368  	if s.freeBuf {
   369  		s.buf.Free()
   370  	}
   371  	if gs := s.groups; gs != nil {
   372  		*gs = (*gs)[:0]
   373  		groupPool.Put(gs)
   374  	}
   375  	s.prefix.Free()
   376  }
   377  
   378  func (s *handleState) openGroups() {
   379  	for _, n := range s.h.groups[s.h.nOpenGroups:] {
   380  		s.openGroup(n)
   381  	}
   382  }
   383  
   384  // Separator for group names and keys.
   385  const keyComponentSep = '.'
   386  
   387  // openGroup starts a new group of attributes
   388  // with the given name.
   389  func (s *handleState) openGroup(name string) {
   390  	if s.h.json {
   391  		s.appendKey(name)
   392  		s.buf.WriteByte('{')
   393  		s.sep = ""
   394  	} else {
   395  		s.prefix.WriteString(name)
   396  		s.prefix.WriteByte(keyComponentSep)
   397  	}
   398  	// Collect group names for ReplaceAttr.
   399  	if s.groups != nil {
   400  		*s.groups = append(*s.groups, name)
   401  	}
   402  }
   403  
   404  // closeGroup ends the group with the given name.
   405  func (s *handleState) closeGroup(name string) {
   406  	if s.h.json {
   407  		s.buf.WriteByte('}')
   408  	} else {
   409  		(*s.prefix) = (*s.prefix)[:len(*s.prefix)-len(name)-1 /* for keyComponentSep */]
   410  	}
   411  	s.sep = s.h.attrSep()
   412  	if s.groups != nil {
   413  		*s.groups = (*s.groups)[:len(*s.groups)-1]
   414  	}
   415  }
   416  
   417  // appendAttr appends the Attr's key and value using app.
   418  // It handles replacement and checking for an empty key.
   419  // after replacement).
   420  func (s *handleState) appendAttr(a Attr) {
   421  	if rep := s.h.opts.ReplaceAttr; rep != nil && a.Value.Kind() != KindGroup {
   422  		var gs []string
   423  		if s.groups != nil {
   424  			gs = *s.groups
   425  		}
   426  		// Resolve before calling ReplaceAttr, so the user doesn't have to.
   427  		a.Value = a.Value.Resolve()
   428  		a = rep(gs, a)
   429  	}
   430  	a.Value = a.Value.Resolve()
   431  	// Elide empty Attrs.
   432  	if a.isEmpty() {
   433  		return
   434  	}
   435  	// Special case: Source.
   436  	if v := a.Value; v.Kind() == KindAny {
   437  		if src, ok := v.Any().(*Source); ok {
   438  			if s.h.json {
   439  				a.Value = src.group()
   440  			} else {
   441  				a.Value = StringValue(fmt.Sprintf("%s:%d", src.File, src.Line))
   442  			}
   443  		}
   444  	}
   445  	if a.Value.Kind() == KindGroup {
   446  		attrs := a.Value.Group()
   447  		// Output only non-empty groups.
   448  		if len(attrs) > 0 {
   449  			// Inline a group with an empty key.
   450  			if a.Key != "" {
   451  				s.openGroup(a.Key)
   452  			}
   453  			for _, aa := range attrs {
   454  				s.appendAttr(aa)
   455  			}
   456  			if a.Key != "" {
   457  				s.closeGroup(a.Key)
   458  			}
   459  		}
   460  	} else {
   461  		s.appendKey(a.Key)
   462  		s.appendValue(a.Value)
   463  	}
   464  }
   465  
   466  func (s *handleState) appendError(err error) {
   467  	s.appendString(fmt.Sprintf("!ERROR:%v", err))
   468  }
   469  
   470  func (s *handleState) appendKey(key string) {
   471  	s.buf.WriteString(s.sep)
   472  	if s.prefix != nil && len(*s.prefix) > 0 {
   473  		// TODO: optimize by avoiding allocation.
   474  		s.appendString(string(*s.prefix) + key)
   475  	} else {
   476  		s.appendString(key)
   477  	}
   478  	if s.h.json {
   479  		s.buf.WriteByte(':')
   480  	} else {
   481  		s.buf.WriteByte('=')
   482  	}
   483  	s.sep = s.h.attrSep()
   484  }
   485  
   486  func (s *handleState) appendString(str string) {
   487  	if s.h.json {
   488  		s.buf.WriteByte('"')
   489  		*s.buf = appendEscapedJSONString(*s.buf, str)
   490  		s.buf.WriteByte('"')
   491  	} else {
   492  		// text
   493  		if needsQuoting(str) {
   494  			*s.buf = strconv.AppendQuote(*s.buf, str)
   495  		} else {
   496  			s.buf.WriteString(str)
   497  		}
   498  	}
   499  }
   500  
   501  func (s *handleState) appendValue(v Value) {
   502  	var err error
   503  	if s.h.json {
   504  		err = appendJSONValue(s, v)
   505  	} else {
   506  		err = appendTextValue(s, v)
   507  	}
   508  	if err != nil {
   509  		s.appendError(err)
   510  	}
   511  }
   512  
   513  func (s *handleState) appendTime(t time.Time) {
   514  	if s.h.json {
   515  		appendJSONTime(s, t)
   516  	} else {
   517  		writeTimeRFC3339Millis(s.buf, t)
   518  	}
   519  }
   520  
   521  // This takes half the time of Time.AppendFormat.
   522  func writeTimeRFC3339Millis(buf *buffer.Buffer, t time.Time) {
   523  	year, month, day := t.Date()
   524  	buf.WritePosIntWidth(year, 4)
   525  	buf.WriteByte('-')
   526  	buf.WritePosIntWidth(int(month), 2)
   527  	buf.WriteByte('-')
   528  	buf.WritePosIntWidth(day, 2)
   529  	buf.WriteByte('T')
   530  	hour, min, sec := t.Clock()
   531  	buf.WritePosIntWidth(hour, 2)
   532  	buf.WriteByte(':')
   533  	buf.WritePosIntWidth(min, 2)
   534  	buf.WriteByte(':')
   535  	buf.WritePosIntWidth(sec, 2)
   536  	ns := t.Nanosecond()
   537  	buf.WriteByte('.')
   538  	buf.WritePosIntWidth(ns/1e6, 3)
   539  	_, offsetSeconds := t.Zone()
   540  	if offsetSeconds == 0 {
   541  		buf.WriteByte('Z')
   542  	} else {
   543  		offsetMinutes := offsetSeconds / 60
   544  		if offsetMinutes < 0 {
   545  			buf.WriteByte('-')
   546  			offsetMinutes = -offsetMinutes
   547  		} else {
   548  			buf.WriteByte('+')
   549  		}
   550  		buf.WritePosIntWidth(offsetMinutes/60, 2)
   551  		buf.WriteByte(':')
   552  		buf.WritePosIntWidth(offsetMinutes%60, 2)
   553  	}
   554  }