-
Notifications
You must be signed in to change notification settings - Fork 0
Expand file tree
/
Copy pathlogger.go
More file actions
559 lines (489 loc) · 17 KB
/
Copy pathlogger.go
File metadata and controls
559 lines (489 loc) · 17 KB
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
package scarylog
import (
"context"
"fmt"
"io"
"log/slog"
"os"
"runtime"
"strings"
"time"
)
type Logger struct {
logger *slog.Logger
// root is the handler slog.New was built from. Keeping it lets WithOverwrite
// rebuild the attribute set on the same handler instead of constructing a
// fresh one on every call.
root slog.Handler
groupName string
opts *Options
}
type Options struct {
// Level is nil when the caller never passed WithLevel. The built-in handler
// then defaults to slog.LevelInfo; a handler supplied via WithHandler is left
// alone. An explicit level is honored in both cases.
Level slog.Leveler
DefaultAttrs []any
GroupName string
AttrMap map[string]string
TimeFormat string
Handler slog.Handler
Writer io.Writer
AddSource bool
}
type Option func(*Options)
func WithLevel(level slog.Leveler) Option {
return func(o *Options) {
o.Level = level
}
}
// WithHandler replaces the built-in handler entirely. The supplied handler owns
// its own output format, so WithAttrRemapping and WithTimeFormat can only reach
// the attributes scarylog passes it, never the handler's own time/level/msg keys
// — those are set by the handler's ReplaceAttr, which scarylog cannot reach from
// the outside. WithLevel is applied as an outer filter and does take effect.
// To keep every option working, use WithWriter instead.
func WithHandler(h slog.Handler) Option {
return func(o *Options) {
o.Handler = h
}
}
// WithWriter sends the built-in JSON handler's output to w instead of os.Stdout.
// Unlike WithHandler it keeps every other option in effect (WithLevel,
// WithAttrRemapping, WithTimeFormat), which makes it the right choice for tests.
func WithWriter(w io.Writer) Option {
return func(o *Options) {
if w != nil {
o.Writer = w
}
}
}
func WithDefaultAttrs(args ...any) Option {
return func(o *Options) {
o.DefaultAttrs = append(o.DefaultAttrs, args...)
}
}
func WithGroup(name string) Option {
return func(o *Options) {
o.GroupName = name
}
}
func WithAttrRemapping(attrMap map[string]string) Option {
return func(o *Options) {
o.AttrMap = attrMap
}
}
func WithTimeFormat(timeFormat string) Option {
return func(o *Options) {
o.TimeFormat = timeFormat
}
}
// WithSource adds a "source" attribute with the file, line and function of the
// call site to every record. It configures the built-in handler; a handler
// supplied through WithHandler decides this for itself via its own
// slog.HandlerOptions.AddSource.
func WithSource(enabled bool) Option {
return func(o *Options) {
o.AddSource = enabled
}
}
func NewLogger(opts ...Option) *Logger {
options := &Options{}
for _, opt := range opts {
opt(options)
}
return newLoggerWithOptions(options)
}
func newLoggerWithOptions(options *Options) *Logger {
root := buildHandler(options)
slogLogger := slog.New(root)
if len(options.DefaultAttrs) > 0 {
slogLogger = slogLogger.With(options.DefaultAttrs...)
}
return &Logger{
logger: slogLogger,
root: root,
groupName: options.GroupName,
opts: options,
}
}
// buildHandler resolves the options into the handler the logger writes through:
// either the caller's handler (wrapped so the options that *can* apply to it do)
// or the built-in JSON handler with every option applied natively.
func buildHandler(o *Options) slog.Handler {
if o.Handler != nil {
return wrapHandler(o.Handler, o)
}
w := o.Writer
if w == nil {
w = os.Stdout
}
level := o.Level
if level == nil {
level = slog.LevelInfo
}
handlerOpts := &slog.HandlerOptions{Level: level, AddSource: o.AddSource}
if len(o.AttrMap) > 0 || o.TimeFormat != "" {
handlerOpts.ReplaceAttr = func(_ []string, a slog.Attr) slog.Attr {
if newKey, ok := o.AttrMap[a.Key]; ok {
a.Key = newKey
}
if a.Key == slog.TimeKey && o.TimeFormat != "" {
a.Value = slog.StringValue(a.Value.Time().Format(o.TimeFormat))
}
return a
}
}
return slog.NewJSONHandler(w, handlerOpts)
}
// wrap nests the given args inside the logger's group when one is configured,
// so every leveled method shares identical grouping behavior.
func (l *Logger) wrap(args []any) []any {
if l.groupName != "" && len(args) > 0 {
return []any{slog.Group(l.groupName, args...)}
}
return args
}
// callerSkip is the runtime.Callers skip that lands on the user's call site:
// 0 is runtime.Callers, 1 is emit, 2 is the internal helper that called it
// (log, errorLog or errorMsgLog), 3 is the public method, 4 is the caller.
//
// Every public logging method must therefore reach emit through exactly one
// helper. Adding or removing a frame on any of those paths silently moves the
// reported source, so the depth is asserted in the tests.
const callerSkip = 4
// emit builds the record and hands it to the handler.
//
// It captures the program counter here rather than calling slog.Logger.Log,
// which would record its own caller — this package — and make every record's
// source point inside scarylog instead of at the code that logged. This is the
// standard obligation of anything that wraps slog.
func (l *Logger) emit(ctx context.Context, level slog.Level, msg string, args []any) {
if ctx == nil {
ctx = context.Background()
}
if !l.logger.Enabled(ctx, level) {
return
}
var pcs [1]uintptr
runtime.Callers(callerSkip, pcs[:])
r := slog.NewRecord(time.Now(), level, msg, pcs[0])
r.Add(args...)
_ = l.logger.Handler().Handle(ctx, r)
}
// log is the shared sink for every leveled method. It forwards the given
// context.Context to slog so context-aware handlers (e.g. trace correlation)
// can enrich the record from request-scoped values in ctx.
func (l *Logger) log(ctx context.Context, level slog.Level, msg string, args ...any) {
l.emit(ctx, level, msg, l.wrap(args))
}
// Log records msg at an arbitrary level, for callers that compute the level at
// runtime. ctx is forwarded to the handler.
func (l *Logger) Log(ctx context.Context, level slog.Level, msg string, args ...any) {
l.log(ctx, level, msg, args...)
}
// Enabled reports whether a record at the given level would be handled. Use it
// to skip building expensive attributes.
func (l *Logger) Enabled(ctx context.Context, level slog.Level) bool {
if ctx == nil {
ctx = context.Background()
}
return l.logger.Enabled(ctx, level)
}
func (l *Logger) Info(msg string, args ...any) {
l.log(context.Background(), slog.LevelInfo, msg, args...)
}
func (l *Logger) InfoContext(ctx context.Context, msg string, args ...any) {
l.log(ctx, slog.LevelInfo, msg, args...)
}
func (l *Logger) Warn(msg string, args ...any) {
l.log(context.Background(), slog.LevelWarn, msg, args...)
}
func (l *Logger) WarnContext(ctx context.Context, msg string, args ...any) {
l.log(ctx, slog.LevelWarn, msg, args...)
}
func (l *Logger) Debug(msg string, args ...any) {
l.log(context.Background(), slog.LevelDebug, msg, args...)
}
func (l *Logger) DebugContext(ctx context.Context, msg string, args ...any) {
l.log(ctx, slog.LevelDebug, msg, args...)
}
func caller(skip int) string {
_, file, line, ok := runtime.Caller(skip)
if !ok {
return "unknown"
}
return fmt.Sprintf("%s:%d", shortPath(file), line)
}
// shortPath trims an absolute path down to its last two segments
// (e.g. "pkg/file.go"), so caller attributes don't leak the build
// machine's filesystem layout and read like slog's own source field.
func shortPath(file string) string {
idx := strings.LastIndexByte(file, '/')
if idx < 0 {
return file
}
if prev := strings.LastIndexByte(file[:idx], '/'); prev >= 0 {
return file[prev+1:]
}
return file
}
// maxUnwrapNodes bounds the total number of errors stackOf examines across the
// whole Unwrap tree. It is a budget for the entire walk, not a per-chain depth:
// a cyclic error — single-wrap or multi — burns through it and the walk gives up.
const maxUnwrapNodes = 1000
// stackOf returns a stack trace rendered by err or by any error it wraps.
//
// Stack-carrying error libraries (github.com/pkg/errors, cockroachdb/errors)
// expose their trace through fmt.Formatter under %+v. Wrapping such an error
// with fmt.Errorf("...: %w", err) hides it again: *fmt.wrapError does not
// implement fmt.Formatter. Since wrapping is exactly what this package tells
// callers to do for context, the whole chain is searched rather than only the
// error on top — otherwise the documented idiom would silently disable stacks.
//
// The outermost trace wins: when several errors in the chain carry one, that is
// the most complete. The returned text belongs to that error, not to the full
// wrapped message — the record's message already carries err.Error() in full.
//
// The walk is deliberately iterative. Recursing per branch would grow the
// goroutine stack with the error tree, and a cyclic multi-error would grow it
// without bound — a fatal stack overflow, which recover cannot catch. A single
// budget covers the whole tree, so no input can make the walk unbounded.
func stackOf(err error) (string, bool) {
// pending holds branches deferred by multi-errors, popped LIFO so the walk
// stays depth-first and left-to-right and the same trace wins as before. It
// stays nil for the common single-wrap chain, which allocates nothing.
var pending []error
for budget := maxUnwrapNodes; err != nil && budget > 0; budget-- {
if _, ok := err.(fmt.Formatter); ok {
if s := fmt.Sprintf("%+v", err); s != err.Error() {
return s, true
}
}
switch e := err.(type) {
case interface{ Unwrap() error }:
err = e.Unwrap()
case interface{ Unwrap() []error }:
// errors.Join and multi-error wrappers: first branch with a trace.
// Pushed in reverse so they pop in their original order.
subs := e.Unwrap()
err = nil
for i := len(subs) - 1; i >= 0; i-- {
if subs[i] != nil {
pending = append(pending, subs[i])
}
}
default:
err = nil
}
if err == nil && len(pending) > 0 {
err = pending[len(pending)-1]
pending = pending[:len(pending)-1]
}
}
return "", false
}
// Error logs err at the error level. The error itself is the message, so add
// context by wrapping it at the call site, e.g. fmt.Errorf("save user: %w", err).
// If err implements fmt.Formatter and renders a stack trace under %+v (as
// github.com/pkg/errors or cockroachdb/errors do), that stack is attached.
//
// Because the message is the fully rendered error, it carries whatever variable
// data the error text contains. When you need a stable, low-cardinality message
// for grouping and alerting, use ErrorMsg.
func (l *Logger) Error(err error, args ...any) {
l.errorLog(context.Background(), err, caller(2), args...)
}
// ErrorContext behaves like Error but forwards ctx to the handler.
func (l *Logger) ErrorContext(ctx context.Context, err error, args ...any) {
l.errorLog(ctx, err, caller(2), args...)
}
// errorLog is the shared implementation for Error/ErrorContext. callerStr is
// captured by the public method so the reported caller is the user's call site.
func (l *Logger) errorLog(ctx context.Context, err error, callerStr string, args ...any) {
if err == nil {
l.emit(ctx, slog.LevelError, "Error called with nil error",
append([]any{"caller", callerStr}, l.wrap(args)...))
return
}
allArgs := []any{
"caller", callerStr,
}
if s, ok := stackOf(err); ok {
allArgs = append(allArgs, slog.String("stack", s))
}
allArgs = append(allArgs, l.wrap(args)...)
l.emit(ctx, slog.LevelError, err.Error(), allArgs)
}
// ErrorMsg logs err at the error level under the stable message msg, putting the
// error text in the "error" attribute instead of the message. Prefer it over
// Error when the message feeds grouping or alerting: err.Error() usually embeds
// variable data (addresses, ids, timeouts), which makes every record a distinct
// message. Passing a nil err is safe — only msg is logged.
func (l *Logger) ErrorMsg(msg string, err error, args ...any) {
l.errorMsgLog(context.Background(), msg, err, caller(2), args...)
}
// ErrorMsgContext behaves like ErrorMsg but forwards ctx to the handler.
func (l *Logger) ErrorMsgContext(ctx context.Context, msg string, err error, args ...any) {
l.errorMsgLog(ctx, msg, err, caller(2), args...)
}
// errorMsgLog is the shared implementation for ErrorMsg/ErrorMsgContext.
func (l *Logger) errorMsgLog(ctx context.Context, msg string, err error, callerStr string, args ...any) {
allArgs := []any{
"caller", callerStr,
}
if err != nil {
allArgs = append(allArgs, slog.String("error", err.Error()))
if s, ok := stackOf(err); ok {
allArgs = append(allArgs, slog.String("stack", s))
}
}
allArgs = append(allArgs, l.wrap(args)...)
l.emit(ctx, slog.LevelError, msg, allArgs)
}
func (l *Logger) With(args ...any) *Logger {
// Mirror the new attrs into a fresh Options so that attribute readers
// (GetAttr/GetString) and WithOverwrite see them too, without mutating
// the shared opts.
newOpts := *l.opts
newOpts.DefaultAttrs = append(append([]any{}, l.opts.DefaultAttrs...), args...)
return &Logger{
logger: l.logger.With(args...),
root: l.root,
groupName: l.groupName,
opts: &newOpts,
}
}
// WithOverwrite creates a new logger with the given attributes, overwriting any existing attributes with the same key.
// It can handle attributes provided as key-value pairs (string, any), or as slog.Attr structs (including slog.Group).
// Attribute order is preserved: an overwritten key keeps its original position,
// and genuinely new keys are appended in the order given.
func (l *Logger) WithOverwrite(args ...any) *Logger {
final := mergeAttrs(l.opts.DefaultAttrs, args)
newOpts := *l.opts
newOpts.DefaultAttrs = final
// Group() only sets the logger's field, so l.groupName — not opts.GroupName —
// is the group actually in force.
newOpts.GroupName = l.groupName
return &Logger{
// Rebuild on the same root handler: reconstructing it here would drop a
// custom handler's identity and allocate a new one on every call.
logger: slog.New(l.root).With(final...),
root: l.root,
groupName: l.groupName,
opts: &newOpts,
}
}
// attrEntry is one merged attribute, kept in insertion order. Either a key/value
// pair (isAttr false) or a slog.Attr, mirroring the two arg styles slog accepts.
type attrEntry struct {
key string
val any
attr slog.Attr
isAttr bool
}
// mergeAttrs merges overrides onto base by key, preserving the order in which
// keys first appeared. Args in either style (string+any or slog.Attr) are
// accepted; anything else is skipped, exactly as slog would.
func mergeAttrs(base, overrides []any) []any {
entries := make([]attrEntry, 0, len(base)/2+len(overrides)/2)
index := make(map[string]int, len(base)/2+len(overrides)/2)
put := func(e attrEntry) {
if i, ok := index[e.key]; ok {
entries[i] = e
return
}
index[e.key] = len(entries)
entries = append(entries, e)
}
collect := func(args []any) {
for i := 0; i < len(args); {
switch v := args[i].(type) {
case string:
if i+1 >= len(args) {
// Dangling key with no value: slog would log it as a
// "!BADKEY" record; drop it here as before.
i++
continue
}
put(attrEntry{key: v, val: args[i+1]})
i += 2
case slog.Attr:
put(attrEntry{key: v.Key, attr: v, isAttr: true})
i++
default:
i++
}
}
}
collect(base)
collect(overrides)
out := make([]any, 0, len(entries)*2)
for _, e := range entries {
if e.isAttr {
out = append(out, e.attr)
} else {
out = append(out, e.key, e.val)
}
}
return out
}
// Group returns a new logger that directs its output to the specified group.
// The new logger inherits all the settings of the parent logger.
func (l *Logger) Group(name string) *Logger {
// Create a shallow copy of the logger, but with a new group name.
return &Logger{
logger: l.logger,
root: l.root,
groupName: name,
opts: l.opts,
}
}
// GetAttr retrieves an attribute value from the logger's DefaultAttrs by key.
// Returns the value and true if found, or nil and false if not found.
// It handles both key-value pairs (string, any) and slog.Attr entries, so it
// stays correct regardless of whether the attr was added via WithDefaultAttrs,
// With, or WithOverwrite.
func (l *Logger) GetAttr(key string) (any, bool) {
args := l.opts.DefaultAttrs
for i := 0; i < len(args); {
switch v := args[i].(type) {
case string:
if i+1 >= len(args) {
return nil, false
}
if v == key {
return args[i+1], true
}
i += 2
case slog.Attr:
if v.Key == key {
return v.Value.Any(), true
}
i++
default:
i++
}
}
return nil, false
}
// GetString retrieves a string attribute from the logger's DefaultAttrs by key.
// Returns the value and true if found and is a string, or empty string and false otherwise.
func (l *Logger) GetString(key string) (string, bool) {
if val, ok := l.GetAttr(key); ok {
if s, ok := val.(string); ok {
return s, true
}
}
return "", false
}
// GetAttrName returns the remapped attribute name if it exists in AttrMap, otherwise returns the original key.
func (l *Logger) GetAttrName(key string) string {
if l.opts.AttrMap == nil {
return key
}
if newName, ok := l.opts.AttrMap[key]; ok {
return newName
}
return key
}