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 }