github.com/twelsh-aw/go/src@v0.0.0-20230516233729-a56fe86a7c81/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 if name == "" { 246 return h 247 } 248 h2 := h.clone() 249 h2.groups = append(h2.groups, name) 250 return h2 251 } 252 253 func (h *commonHandler) handle(r Record) error { 254 state := h.newHandleState(buffer.New(), true, "") 255 defer state.free() 256 if h.json { 257 state.buf.WriteByte('{') 258 } 259 // Built-in attributes. They are not in a group. 260 stateGroups := state.groups 261 state.groups = nil // So ReplaceAttrs sees no groups instead of the pre groups. 262 rep := h.opts.ReplaceAttr 263 // time 264 if !r.Time.IsZero() { 265 key := TimeKey 266 val := r.Time.Round(0) // strip monotonic to match Attr behavior 267 if rep == nil { 268 state.appendKey(key) 269 state.appendTime(val) 270 } else { 271 state.appendAttr(Time(key, val)) 272 } 273 } 274 // level 275 key := LevelKey 276 val := r.Level 277 if rep == nil { 278 state.appendKey(key) 279 state.appendString(val.String()) 280 } else { 281 state.appendAttr(Any(key, val)) 282 } 283 // source 284 if h.opts.AddSource { 285 state.appendAttr(Any(SourceKey, r.source())) 286 } 287 key = MessageKey 288 msg := r.Message 289 if rep == nil { 290 state.appendKey(key) 291 state.appendString(msg) 292 } else { 293 state.appendAttr(String(key, msg)) 294 } 295 state.groups = stateGroups // Restore groups passed to ReplaceAttrs. 296 state.appendNonBuiltIns(r) 297 state.buf.WriteByte('\n') 298 299 h.mu.Lock() 300 defer h.mu.Unlock() 301 _, err := h.w.Write(*state.buf) 302 return err 303 } 304 305 func (s *handleState) appendNonBuiltIns(r Record) { 306 // preformatted Attrs 307 if len(s.h.preformattedAttrs) > 0 { 308 s.buf.WriteString(s.sep) 309 s.buf.Write(s.h.preformattedAttrs) 310 s.sep = s.h.attrSep() 311 } 312 // Attrs in Record -- unlike the built-in ones, they are in groups started 313 // from WithGroup. 314 s.prefix.WriteString(s.h.groupPrefix) 315 s.openGroups() 316 r.Attrs(func(a Attr) bool { 317 s.appendAttr(a) 318 return true 319 }) 320 if s.h.json { 321 // Close all open groups. 322 for range s.h.groups { 323 s.buf.WriteByte('}') 324 } 325 // Close the top-level object. 326 s.buf.WriteByte('}') 327 } 328 } 329 330 // attrSep returns the separator between attributes. 331 func (h *commonHandler) attrSep() string { 332 if h.json { 333 return "," 334 } 335 return " " 336 } 337 338 // handleState holds state for a single call to commonHandler.handle. 339 // The initial value of sep determines whether to emit a separator 340 // before the next key, after which it stays true. 341 type handleState struct { 342 h *commonHandler 343 buf *buffer.Buffer 344 freeBuf bool // should buf be freed? 345 sep string // separator to write before next key 346 prefix *buffer.Buffer // for text: key prefix 347 groups *[]string // pool-allocated slice of active groups, for ReplaceAttr 348 } 349 350 var groupPool = sync.Pool{New: func() any { 351 s := make([]string, 0, 10) 352 return &s 353 }} 354 355 func (h *commonHandler) newHandleState(buf *buffer.Buffer, freeBuf bool, sep string) handleState { 356 s := handleState{ 357 h: h, 358 buf: buf, 359 freeBuf: freeBuf, 360 sep: sep, 361 prefix: buffer.New(), 362 } 363 if h.opts.ReplaceAttr != nil { 364 s.groups = groupPool.Get().(*[]string) 365 *s.groups = append(*s.groups, h.groups[:h.nOpenGroups]...) 366 } 367 return s 368 } 369 370 func (s *handleState) free() { 371 if s.freeBuf { 372 s.buf.Free() 373 } 374 if gs := s.groups; gs != nil { 375 *gs = (*gs)[:0] 376 groupPool.Put(gs) 377 } 378 s.prefix.Free() 379 } 380 381 func (s *handleState) openGroups() { 382 for _, n := range s.h.groups[s.h.nOpenGroups:] { 383 s.openGroup(n) 384 } 385 } 386 387 // Separator for group names and keys. 388 const keyComponentSep = '.' 389 390 // openGroup starts a new group of attributes 391 // with the given name. 392 func (s *handleState) openGroup(name string) { 393 if s.h.json { 394 s.appendKey(name) 395 s.buf.WriteByte('{') 396 s.sep = "" 397 } else { 398 s.prefix.WriteString(name) 399 s.prefix.WriteByte(keyComponentSep) 400 } 401 // Collect group names for ReplaceAttr. 402 if s.groups != nil { 403 *s.groups = append(*s.groups, name) 404 } 405 } 406 407 // closeGroup ends the group with the given name. 408 func (s *handleState) closeGroup(name string) { 409 if s.h.json { 410 s.buf.WriteByte('}') 411 } else { 412 (*s.prefix) = (*s.prefix)[:len(*s.prefix)-len(name)-1 /* for keyComponentSep */] 413 } 414 s.sep = s.h.attrSep() 415 if s.groups != nil { 416 *s.groups = (*s.groups)[:len(*s.groups)-1] 417 } 418 } 419 420 // appendAttr appends the Attr's key and value using app. 421 // It handles replacement and checking for an empty key. 422 // after replacement). 423 func (s *handleState) appendAttr(a Attr) { 424 if rep := s.h.opts.ReplaceAttr; rep != nil && a.Value.Kind() != KindGroup { 425 var gs []string 426 if s.groups != nil { 427 gs = *s.groups 428 } 429 // Resolve before calling ReplaceAttr, so the user doesn't have to. 430 a.Value = a.Value.Resolve() 431 a = rep(gs, a) 432 } 433 a.Value = a.Value.Resolve() 434 // Elide empty Attrs. 435 if a.isEmpty() { 436 return 437 } 438 // Special case: Source. 439 if v := a.Value; v.Kind() == KindAny { 440 if src, ok := v.Any().(*Source); ok { 441 if s.h.json { 442 a.Value = src.group() 443 } else { 444 a.Value = StringValue(fmt.Sprintf("%s:%d", src.File, src.Line)) 445 } 446 } 447 } 448 if a.Value.Kind() == KindGroup { 449 attrs := a.Value.Group() 450 // Output only non-empty groups. 451 if len(attrs) > 0 { 452 // Inline a group with an empty key. 453 if a.Key != "" { 454 s.openGroup(a.Key) 455 } 456 for _, aa := range attrs { 457 s.appendAttr(aa) 458 } 459 if a.Key != "" { 460 s.closeGroup(a.Key) 461 } 462 } 463 } else { 464 s.appendKey(a.Key) 465 s.appendValue(a.Value) 466 } 467 } 468 469 func (s *handleState) appendError(err error) { 470 s.appendString(fmt.Sprintf("!ERROR:%v", err)) 471 } 472 473 func (s *handleState) appendKey(key string) { 474 s.buf.WriteString(s.sep) 475 if s.prefix != nil { 476 // TODO: optimize by avoiding allocation. 477 s.appendString(string(*s.prefix) + key) 478 } else { 479 s.appendString(key) 480 } 481 if s.h.json { 482 s.buf.WriteByte(':') 483 } else { 484 s.buf.WriteByte('=') 485 } 486 s.sep = s.h.attrSep() 487 } 488 489 func (s *handleState) appendString(str string) { 490 if s.h.json { 491 s.buf.WriteByte('"') 492 *s.buf = appendEscapedJSONString(*s.buf, str) 493 s.buf.WriteByte('"') 494 } else { 495 // text 496 if needsQuoting(str) { 497 *s.buf = strconv.AppendQuote(*s.buf, str) 498 } else { 499 s.buf.WriteString(str) 500 } 501 } 502 } 503 504 func (s *handleState) appendValue(v Value) { 505 var err error 506 if s.h.json { 507 err = appendJSONValue(s, v) 508 } else { 509 err = appendTextValue(s, v) 510 } 511 if err != nil { 512 s.appendError(err) 513 } 514 } 515 516 func (s *handleState) appendTime(t time.Time) { 517 if s.h.json { 518 appendJSONTime(s, t) 519 } else { 520 writeTimeRFC3339Millis(s.buf, t) 521 } 522 } 523 524 // This takes half the time of Time.AppendFormat. 525 func writeTimeRFC3339Millis(buf *buffer.Buffer, t time.Time) { 526 year, month, day := t.Date() 527 buf.WritePosIntWidth(year, 4) 528 buf.WriteByte('-') 529 buf.WritePosIntWidth(int(month), 2) 530 buf.WriteByte('-') 531 buf.WritePosIntWidth(day, 2) 532 buf.WriteByte('T') 533 hour, min, sec := t.Clock() 534 buf.WritePosIntWidth(hour, 2) 535 buf.WriteByte(':') 536 buf.WritePosIntWidth(min, 2) 537 buf.WriteByte(':') 538 buf.WritePosIntWidth(sec, 2) 539 ns := t.Nanosecond() 540 buf.WriteByte('.') 541 buf.WritePosIntWidth(ns/1e6, 3) 542 _, offsetSeconds := t.Zone() 543 if offsetSeconds == 0 { 544 buf.WriteByte('Z') 545 } else { 546 offsetMinutes := offsetSeconds / 60 547 if offsetMinutes < 0 { 548 buf.WriteByte('-') 549 offsetMinutes = -offsetMinutes 550 } else { 551 buf.WriteByte('+') 552 } 553 buf.WritePosIntWidth(offsetMinutes/60, 2) 554 buf.WriteByte(':') 555 buf.WritePosIntWidth(offsetMinutes%60, 2) 556 } 557 }