Source file
src/log/slog/handler_test.go
1
2
3
4
5
6
7 package slog
8
9 import (
10 "bytes"
11 "context"
12 "encoding/json"
13 "fmt"
14 "io"
15 "log/slog/internal/buffer"
16 "os"
17 "path/filepath"
18 "slices"
19 "strconv"
20 "strings"
21 "sync"
22 "testing"
23 "time"
24 )
25
26 func TestDefaultHandle(t *testing.T) {
27 ctx := context.Background()
28 preAttrs := []Attr{Int("pre", 0)}
29 attrs := []Attr{Int("a", 1), String("b", "two")}
30 for _, test := range []struct {
31 name string
32 with func(Handler) Handler
33 attrs []Attr
34 want string
35 }{
36 {
37 name: "no attrs",
38 want: "INFO message",
39 },
40 {
41 name: "attrs",
42 attrs: attrs,
43 want: "INFO message a=1 b=two",
44 },
45 {
46 name: "preformatted",
47 with: func(h Handler) Handler { return h.WithAttrs(preAttrs) },
48 attrs: attrs,
49 want: "INFO message pre=0 a=1 b=two",
50 },
51 {
52 name: "groups",
53 attrs: []Attr{
54 Int("a", 1),
55 Group("g",
56 Int("b", 2),
57 Group("h", Int("c", 3)),
58 Int("d", 4)),
59 Int("e", 5),
60 },
61 want: "INFO message a=1 g.b=2 g.h.c=3 g.d=4 e=5",
62 },
63 {
64 name: "group",
65 with: func(h Handler) Handler { return h.WithAttrs(preAttrs).WithGroup("s") },
66 attrs: attrs,
67 want: "INFO message pre=0 s.a=1 s.b=two",
68 },
69 {
70 name: "preformatted groups",
71 with: func(h Handler) Handler {
72 return h.WithAttrs([]Attr{Int("p1", 1)}).
73 WithGroup("s1").
74 WithAttrs([]Attr{Int("p2", 2)}).
75 WithGroup("s2")
76 },
77 attrs: attrs,
78 want: "INFO message p1=1 s1.p2=2 s1.s2.a=1 s1.s2.b=two",
79 },
80 {
81 name: "two with-groups",
82 with: func(h Handler) Handler {
83 return h.WithAttrs([]Attr{Int("p1", 1)}).
84 WithGroup("s1").
85 WithGroup("s2")
86 },
87 attrs: attrs,
88 want: "INFO message p1=1 s1.s2.a=1 s1.s2.b=two",
89 },
90 } {
91 t.Run(test.name, func(t *testing.T) {
92 var got string
93 var h Handler = newDefaultHandler(func(_ uintptr, b []byte) error {
94 got = string(b)
95 return nil
96 })
97 if test.with != nil {
98 h = test.with(h)
99 }
100 r := NewRecord(time.Time{}, LevelInfo, "message", 0)
101 r.AddAttrs(test.attrs...)
102 if err := h.Handle(ctx, r); err != nil {
103 t.Fatal(err)
104 }
105 if got != test.want {
106 t.Errorf("\ngot %s\nwant %s", got, test.want)
107 }
108 })
109 }
110 }
111
112 func TestConcurrentWrites(t *testing.T) {
113 ctx := context.Background()
114 count := 1000
115 for _, handlerType := range []string{"text", "json"} {
116 t.Run(handlerType, func(t *testing.T) {
117 var buf bytes.Buffer
118 var h Handler
119 switch handlerType {
120 case "text":
121 h = NewTextHandler(&buf, nil)
122 case "json":
123 h = NewJSONHandler(&buf, nil)
124 default:
125 t.Fatalf("unexpected handlerType %q", handlerType)
126 }
127 sub1 := h.WithAttrs([]Attr{Bool("sub1", true)})
128 sub2 := h.WithAttrs([]Attr{Bool("sub2", true)})
129 var wg sync.WaitGroup
130 for i := 0; i < count; i++ {
131 sub1Record := NewRecord(time.Time{}, LevelInfo, "hello from sub1", 0)
132 sub1Record.AddAttrs(Int("i", i))
133 sub2Record := NewRecord(time.Time{}, LevelInfo, "hello from sub2", 0)
134 sub2Record.AddAttrs(Int("i", i))
135 wg.Add(1)
136 go func() {
137 defer wg.Done()
138 if err := sub1.Handle(ctx, sub1Record); err != nil {
139 t.Error(err)
140 }
141 if err := sub2.Handle(ctx, sub2Record); err != nil {
142 t.Error(err)
143 }
144 }()
145 }
146 wg.Wait()
147 for i := 1; i <= 2; i++ {
148 want := "hello from sub" + strconv.Itoa(i)
149 n := strings.Count(buf.String(), want)
150 if n != count {
151 t.Fatalf("want %d occurrences of %q, got %d", count, want, n)
152 }
153 }
154 })
155 }
156 }
157
158
159 func TestJSONAndTextHandlers(t *testing.T) {
160
161 removeAll := func(_ []string, a Attr) Attr { return Attr{} }
162
163 attrs := []Attr{String("a", "one"), Int("b", 2), Any("", nil)}
164 preAttrs := []Attr{Int("pre", 3), String("x", "y")}
165
166 for _, test := range []struct {
167 name string
168 replace func([]string, Attr) Attr
169 addSource bool
170 with func(Handler) Handler
171 preAttrs []Attr
172 attrs []Attr
173 wantText string
174 wantJSON string
175 }{
176 {
177 name: "basic",
178 attrs: attrs,
179 wantText: "time=2000-01-02T03:04:05.000Z level=INFO msg=message a=one b=2",
180 wantJSON: `{"time":"2000-01-02T03:04:05Z","level":"INFO","msg":"message","a":"one","b":2}`,
181 },
182 {
183 name: "empty key",
184 attrs: append(slices.Clip(attrs), Any("", "v")),
185 wantText: `time=2000-01-02T03:04:05.000Z level=INFO msg=message a=one b=2 ""=v`,
186 wantJSON: `{"time":"2000-01-02T03:04:05Z","level":"INFO","msg":"message","a":"one","b":2,"":"v"}`,
187 },
188 {
189 name: "cap keys",
190 replace: upperCaseKey,
191 attrs: attrs,
192 wantText: "TIME=2000-01-02T03:04:05.000Z LEVEL=INFO MSG=message A=one B=2",
193 wantJSON: `{"TIME":"2000-01-02T03:04:05Z","LEVEL":"INFO","MSG":"message","A":"one","B":2}`,
194 },
195 {
196 name: "remove all",
197 replace: removeAll,
198 attrs: attrs,
199 wantText: "",
200 wantJSON: `{}`,
201 },
202 {
203 name: "preformatted",
204 with: func(h Handler) Handler { return h.WithAttrs(preAttrs) },
205 preAttrs: preAttrs,
206 attrs: attrs,
207 wantText: "time=2000-01-02T03:04:05.000Z level=INFO msg=message pre=3 x=y a=one b=2",
208 wantJSON: `{"time":"2000-01-02T03:04:05Z","level":"INFO","msg":"message","pre":3,"x":"y","a":"one","b":2}`,
209 },
210 {
211 name: "preformatted cap keys",
212 replace: upperCaseKey,
213 with: func(h Handler) Handler { return h.WithAttrs(preAttrs) },
214 preAttrs: preAttrs,
215 attrs: attrs,
216 wantText: "TIME=2000-01-02T03:04:05.000Z LEVEL=INFO MSG=message PRE=3 X=y A=one B=2",
217 wantJSON: `{"TIME":"2000-01-02T03:04:05Z","LEVEL":"INFO","MSG":"message","PRE":3,"X":"y","A":"one","B":2}`,
218 },
219 {
220 name: "preformatted remove all",
221 replace: removeAll,
222 with: func(h Handler) Handler { return h.WithAttrs(preAttrs) },
223 preAttrs: preAttrs,
224 attrs: attrs,
225 wantText: "",
226 wantJSON: "{}",
227 },
228 {
229 name: "remove built-in",
230 replace: removeKeys(TimeKey, LevelKey, MessageKey),
231 attrs: attrs,
232 wantText: "a=one b=2",
233 wantJSON: `{"a":"one","b":2}`,
234 },
235 {
236 name: "preformatted remove built-in",
237 replace: removeKeys(TimeKey, LevelKey, MessageKey),
238 with: func(h Handler) Handler { return h.WithAttrs(preAttrs) },
239 attrs: attrs,
240 wantText: "pre=3 x=y a=one b=2",
241 wantJSON: `{"pre":3,"x":"y","a":"one","b":2}`,
242 },
243 {
244 name: "groups",
245 replace: removeKeys(TimeKey, LevelKey),
246 attrs: []Attr{
247 Int("a", 1),
248 Group("g",
249 Int("b", 2),
250 Group("h", Int("c", 3)),
251 Int("d", 4)),
252 Int("e", 5),
253 },
254 wantText: "msg=message a=1 g.b=2 g.h.c=3 g.d=4 e=5",
255 wantJSON: `{"msg":"message","a":1,"g":{"b":2,"h":{"c":3},"d":4},"e":5}`,
256 },
257 {
258 name: "empty group",
259 replace: removeKeys(TimeKey, LevelKey),
260 attrs: []Attr{Group("g"), Group("h", Int("a", 1))},
261 wantText: "msg=message h.a=1",
262 wantJSON: `{"msg":"message","h":{"a":1}}`,
263 },
264 {
265 name: "nested empty group",
266 replace: removeKeys(TimeKey, LevelKey),
267 attrs: []Attr{
268 Group("g",
269 Group("h",
270 Group("i"), Group("j"))),
271 },
272 wantText: `msg=message`,
273 wantJSON: `{"msg":"message"}`,
274 },
275 {
276 name: "nested non-empty group",
277 replace: removeKeys(TimeKey, LevelKey),
278 attrs: []Attr{
279 Group("g",
280 Group("h",
281 Group("i"), Group("j", Int("a", 1)))),
282 },
283 wantText: `msg=message g.h.j.a=1`,
284 wantJSON: `{"msg":"message","g":{"h":{"j":{"a":1}}}}`,
285 },
286 {
287 name: "escapes",
288 replace: removeKeys(TimeKey, LevelKey),
289 attrs: []Attr{
290 String("a b", "x\t\n\000y"),
291 Group(" b.c=\"\\x2E\t",
292 String("d=e", "f.g\""),
293 Int("m.d", 1)),
294 },
295 wantText: `msg=message "a b"="x\t\n\x00y" " b.c=\"\\x2E\t.d=e"="f.g\"" " b.c=\"\\x2E\t.m.d"=1`,
296 wantJSON: `{"msg":"message","a b":"x\t\n\u0000y"," b.c=\"\\x2E\t":{"d=e":"f.g\"","m.d":1}}`,
297 },
298 {
299 name: "LogValuer",
300 replace: removeKeys(TimeKey, LevelKey),
301 attrs: []Attr{
302 Int("a", 1),
303 Any("name", logValueName{"Ren", "Hoek"}),
304 Int("b", 2),
305 },
306 wantText: "msg=message a=1 name.first=Ren name.last=Hoek b=2",
307 wantJSON: `{"msg":"message","a":1,"name":{"first":"Ren","last":"Hoek"},"b":2}`,
308 },
309 {
310
311 name: "resolve",
312 attrs: []Attr{
313 Any("", &replace{Value{}}),
314 Any("name", logValueName{"Ren", "Hoek"}),
315 },
316 wantText: "time=2000-01-02T03:04:05.000Z level=INFO msg=message name.first=Ren name.last=Hoek",
317 wantJSON: `{"time":"2000-01-02T03:04:05Z","level":"INFO","msg":"message","name":{"first":"Ren","last":"Hoek"}}`,
318 },
319 {
320 name: "with-group",
321 replace: removeKeys(TimeKey, LevelKey),
322 with: func(h Handler) Handler { return h.WithAttrs(preAttrs).WithGroup("s") },
323 attrs: attrs,
324 wantText: "msg=message pre=3 x=y s.a=one s.b=2",
325 wantJSON: `{"msg":"message","pre":3,"x":"y","s":{"a":"one","b":2}}`,
326 },
327 {
328 name: "preformatted with-groups",
329 replace: removeKeys(TimeKey, LevelKey),
330 with: func(h Handler) Handler {
331 return h.WithAttrs([]Attr{Int("p1", 1)}).
332 WithGroup("s1").
333 WithAttrs([]Attr{Int("p2", 2)}).
334 WithGroup("s2").
335 WithAttrs([]Attr{Int("p3", 3)})
336 },
337 attrs: attrs,
338 wantText: "msg=message p1=1 s1.p2=2 s1.s2.p3=3 s1.s2.a=one s1.s2.b=2",
339 wantJSON: `{"msg":"message","p1":1,"s1":{"p2":2,"s2":{"p3":3,"a":"one","b":2}}}`,
340 },
341 {
342 name: "two with-groups",
343 replace: removeKeys(TimeKey, LevelKey),
344 with: func(h Handler) Handler {
345 return h.WithAttrs([]Attr{Int("p1", 1)}).
346 WithGroup("s1").
347 WithGroup("s2")
348 },
349 attrs: attrs,
350 wantText: "msg=message p1=1 s1.s2.a=one s1.s2.b=2",
351 wantJSON: `{"msg":"message","p1":1,"s1":{"s2":{"a":"one","b":2}}}`,
352 },
353 {
354 name: "empty with-groups",
355 replace: removeKeys(TimeKey, LevelKey),
356 with: func(h Handler) Handler {
357 return h.WithGroup("x").WithGroup("y")
358 },
359 wantText: "msg=message",
360 wantJSON: `{"msg":"message"}`,
361 },
362 {
363 name: "empty with-groups, no non-empty attrs",
364 replace: removeKeys(TimeKey, LevelKey),
365 with: func(h Handler) Handler {
366 return h.WithGroup("x").WithAttrs([]Attr{Group("g")}).WithGroup("y")
367 },
368 wantText: "msg=message",
369 wantJSON: `{"msg":"message"}`,
370 },
371 {
372 name: "one empty with-group",
373 replace: removeKeys(TimeKey, LevelKey),
374 with: func(h Handler) Handler {
375 return h.WithGroup("x").WithAttrs([]Attr{Int("a", 1)}).WithGroup("y")
376 },
377 attrs: []Attr{Group("g", Group("h"))},
378 wantText: "msg=message x.a=1",
379 wantJSON: `{"msg":"message","x":{"a":1}}`,
380 },
381 {
382 name: "GroupValue as Attr value",
383 replace: removeKeys(TimeKey, LevelKey),
384 attrs: []Attr{{"v", AnyValue(IntValue(3))}},
385 wantText: "msg=message v=3",
386 wantJSON: `{"msg":"message","v":3}`,
387 },
388 {
389 name: "byte slice",
390 replace: removeKeys(TimeKey, LevelKey),
391 attrs: []Attr{Any("bs", []byte{1, 2, 3, 4})},
392 wantText: `msg=message bs="\x01\x02\x03\x04"`,
393 wantJSON: `{"msg":"message","bs":"AQIDBA=="}`,
394 },
395 {
396 name: "json.RawMessage",
397 replace: removeKeys(TimeKey, LevelKey),
398 attrs: []Attr{Any("bs", json.RawMessage([]byte("1234")))},
399 wantText: `msg=message bs="1234"`,
400 wantJSON: `{"msg":"message","bs":1234}`,
401 },
402 {
403 name: "inline group",
404 replace: removeKeys(TimeKey, LevelKey),
405 attrs: []Attr{
406 Int("a", 1),
407 Group("", Int("b", 2), Int("c", 3)),
408 Int("d", 4),
409 },
410 wantText: `msg=message a=1 b=2 c=3 d=4`,
411 wantJSON: `{"msg":"message","a":1,"b":2,"c":3,"d":4}`,
412 },
413 {
414 name: "Source",
415 replace: func(gs []string, a Attr) Attr {
416 if a.Key == SourceKey {
417 s := a.Value.Any().(*Source)
418 s.File = filepath.Base(s.File)
419 return Any(a.Key, s)
420 }
421 return removeKeys(TimeKey, LevelKey)(gs, a)
422 },
423 addSource: true,
424 wantText: `source=handler_test.go:$LINE msg=message`,
425 wantJSON: `{"source":{"function":"log/slog.TestJSONAndTextHandlers","file":"handler_test.go","line":$LINE},"msg":"message"}`,
426 },
427 {
428 name: "replace built-in with group",
429 replace: func(_ []string, a Attr) Attr {
430 if a.Key == TimeKey {
431 return Group(TimeKey, "mins", 3, "secs", 2)
432 }
433 if a.Key == LevelKey {
434 return Attr{}
435 }
436 return a
437 },
438 wantText: `time.mins=3 time.secs=2 msg=message`,
439 wantJSON: `{"time":{"mins":3,"secs":2},"msg":"message"}`,
440 },
441 {
442 name: "replace empty",
443 replace: func([]string, Attr) Attr { return Attr{} },
444 attrs: []Attr{Group("g", Int("a", 1))},
445 wantText: "",
446 wantJSON: `{}`,
447 },
448 {
449 name: "replace empty 1",
450 with: func(h Handler) Handler {
451 return h.WithGroup("g").WithAttrs([]Attr{Int("a", 1)})
452 },
453 replace: func([]string, Attr) Attr { return Attr{} },
454 attrs: []Attr{Group("h", Int("b", 2))},
455 wantText: "",
456 wantJSON: `{}`,
457 },
458 {
459 name: "replace empty 2",
460 with: func(h Handler) Handler {
461 return h.WithGroup("g").WithAttrs([]Attr{Int("a", 1)}).WithGroup("h").WithAttrs([]Attr{Int("b", 2)})
462 },
463 replace: func([]string, Attr) Attr { return Attr{} },
464 attrs: []Attr{Group("i", Int("c", 3))},
465 wantText: "",
466 wantJSON: `{}`,
467 },
468 {
469 name: "replace empty 3",
470 with: func(h Handler) Handler { return h.WithGroup("g") },
471 replace: func([]string, Attr) Attr { return Attr{} },
472 attrs: []Attr{Int("a", 1)},
473 wantText: "",
474 wantJSON: `{}`,
475 },
476 {
477 name: "replace empty inline",
478 with: func(h Handler) Handler {
479 return h.WithGroup("g").WithAttrs([]Attr{Int("a", 1)}).WithGroup("h").WithAttrs([]Attr{Int("b", 2)})
480 },
481 replace: func([]string, Attr) Attr { return Attr{} },
482 attrs: []Attr{Group("", Int("c", 3))},
483 wantText: "",
484 wantJSON: `{}`,
485 },
486 {
487 name: "replace partial empty attrs 1",
488 with: func(h Handler) Handler {
489 return h.WithGroup("g").WithAttrs([]Attr{Int("a", 1)}).WithGroup("h").WithAttrs([]Attr{Int("b", 2)})
490 },
491 replace: func(groups []string, attr Attr) Attr {
492 return removeKeys(TimeKey, LevelKey, MessageKey, "a")(groups, attr)
493 },
494 attrs: []Attr{Group("i", Int("c", 3))},
495 wantText: "g.h.b=2 g.h.i.c=3",
496 wantJSON: `{"g":{"h":{"b":2,"i":{"c":3}}}}`,
497 },
498 {
499 name: "replace partial empty attrs 2",
500 with: func(h Handler) Handler {
501 return h.WithGroup("g").WithAttrs([]Attr{Int("a", 1)}).WithAttrs([]Attr{Int("n", 4)}).WithGroup("h").WithAttrs([]Attr{Int("b", 2)})
502 },
503 replace: func(groups []string, attr Attr) Attr {
504 return removeKeys(TimeKey, LevelKey, MessageKey, "a", "b")(groups, attr)
505 },
506 attrs: []Attr{Group("i", Int("c", 3))},
507 wantText: "g.n=4 g.h.i.c=3",
508 wantJSON: `{"g":{"n":4,"h":{"i":{"c":3}}}}`,
509 },
510 {
511 name: "replace partial empty attrs 3",
512 with: func(h Handler) Handler {
513 return h.WithGroup("g").WithAttrs([]Attr{Int("x", 0)}).WithAttrs([]Attr{Int("a", 1)}).WithAttrs([]Attr{Int("n", 4)}).WithGroup("h").WithAttrs([]Attr{Int("b", 2)})
514 },
515 replace: func(groups []string, attr Attr) Attr {
516 return removeKeys(TimeKey, LevelKey, MessageKey, "a", "c")(groups, attr)
517 },
518 attrs: []Attr{Group("i", Int("c", 3))},
519 wantText: "g.x=0 g.n=4 g.h.b=2",
520 wantJSON: `{"g":{"x":0,"n":4,"h":{"b":2}}}`,
521 },
522 {
523 name: "replace resolved group",
524 replace: func(groups []string, a Attr) Attr {
525 if a.Value.Kind() == KindGroup {
526 return Attr{"bad", IntValue(1)}
527 }
528 return removeKeys(TimeKey, LevelKey, MessageKey)(groups, a)
529 },
530 attrs: []Attr{Any("name", logValueName{"Perry", "Platypus"})},
531 wantText: "name.first=Perry name.last=Platypus",
532 wantJSON: `{"name":{"first":"Perry","last":"Platypus"}}`,
533 },
534 {
535 name: "group and key (or both) needs quoting",
536 replace: removeKeys(TimeKey, LevelKey),
537 attrs: []Attr{
538 Group("prefix",
539 String(" needs quoting ", "v"), String("NotNeedsQuoting", "v"),
540 ),
541 Group("prefix needs quoting",
542 String(" needs quoting ", "v"), String("NotNeedsQuoting", "v"),
543 ),
544 },
545 wantText: `msg=message "prefix. needs quoting "=v prefix.NotNeedsQuoting=v "prefix needs quoting. needs quoting "=v "prefix needs quoting.NotNeedsQuoting"=v`,
546 wantJSON: `{"msg":"message","prefix":{" needs quoting ":"v","NotNeedsQuoting":"v"},"prefix needs quoting":{" needs quoting ":"v","NotNeedsQuoting":"v"}}`,
547 },
548 } {
549 r := NewRecord(testTime, LevelInfo, "message", callerPC(2))
550 source := r.Source()
551 if source == nil {
552 t.Fatal("source is nil")
553 }
554 line := strconv.Itoa(source.Line)
555 r.AddAttrs(test.attrs...)
556 var buf bytes.Buffer
557 opts := HandlerOptions{ReplaceAttr: test.replace, AddSource: test.addSource}
558 t.Run(test.name, func(t *testing.T) {
559 for _, handler := range []struct {
560 name string
561 h Handler
562 want string
563 }{
564 {"text", NewTextHandler(&buf, &opts), test.wantText},
565 {"json", NewJSONHandler(&buf, &opts), test.wantJSON},
566 } {
567 t.Run(handler.name, func(t *testing.T) {
568 h := handler.h
569 if test.with != nil {
570 h = test.with(h)
571 }
572 buf.Reset()
573 if err := h.Handle(nil, r); err != nil {
574 t.Fatal(err)
575 }
576 want := strings.ReplaceAll(handler.want, "$LINE", line)
577 got := strings.TrimSuffix(buf.String(), "\n")
578 if got != want {
579 t.Errorf("\ngot %s\nwant %s\n", got, want)
580 }
581 })
582 }
583 })
584 }
585 }
586
587
588
589 func removeKeys(keys ...string) func([]string, Attr) Attr {
590 return func(_ []string, a Attr) Attr {
591 for _, k := range keys {
592 if a.Key == k {
593 return Attr{}
594 }
595 }
596 return a
597 }
598 }
599
600 func upperCaseKey(_ []string, a Attr) Attr {
601 a.Key = strings.ToUpper(a.Key)
602 return a
603 }
604
605 type logValueName struct {
606 first, last string
607 }
608
609 func (n logValueName) LogValue() Value {
610 return GroupValue(
611 String("first", n.first),
612 String("last", n.last))
613 }
614
615 func TestHandlerEnabled(t *testing.T) {
616 levelVar := func(l Level) *LevelVar {
617 var al LevelVar
618 al.Set(l)
619 return &al
620 }
621
622 for _, test := range []struct {
623 leveler Leveler
624 want bool
625 }{
626 {nil, true},
627 {LevelWarn, false},
628 {&LevelVar{}, true},
629 {levelVar(LevelWarn), false},
630 {LevelDebug, true},
631 {levelVar(LevelDebug), true},
632 } {
633 h := &commonHandler{opts: HandlerOptions{Level: test.leveler}}
634 got := h.enabled(LevelInfo)
635 if got != test.want {
636 t.Errorf("%v: got %t, want %t", test.leveler, got, test.want)
637 }
638 }
639 }
640
641 func TestJSONAndTextHandlersWithUnavailableSource(t *testing.T) {
642
643
644 var buf bytes.Buffer
645 opts := &HandlerOptions{
646 ReplaceAttr: removeKeys(LevelKey),
647 AddSource: true,
648 }
649
650 for _, test := range []struct {
651 name string
652 h Handler
653 want string
654 }{
655 {"text", NewTextHandler(&buf, opts), "source=:0 msg=message"},
656 {"json", NewJSONHandler(&buf, opts), `{"msg":"message"}`},
657 } {
658 t.Run(test.name, func(t *testing.T) {
659 buf.Reset()
660 r := NewRecord(time.Time{}, LevelInfo, "message", 0)
661 err := test.h.Handle(t.Context(), r)
662 if err != nil {
663 t.Fatal(err)
664 }
665
666 want := strings.TrimSpace(test.want)
667 got := strings.TrimSpace(buf.String())
668 if got != want {
669 t.Errorf("\ngot %s\nwant %s", got, want)
670 }
671 })
672 }
673 }
674
675 func TestSecondWith(t *testing.T) {
676
677
678 var buf bytes.Buffer
679 h := NewTextHandler(&buf, &HandlerOptions{ReplaceAttr: removeKeys(TimeKey)})
680 logger := New(h).With(
681 String("app", "playground"),
682 String("role", "tester"),
683 Int("data_version", 2),
684 )
685 appLogger := logger.With("type", "log")
686 _ = logger.With("type", "metric")
687 appLogger.Info("foo")
688 got := strings.TrimSpace(buf.String())
689 want := `level=INFO msg=foo app=playground role=tester data_version=2 type=log`
690 if got != want {
691 t.Errorf("\ngot %s\nwant %s", got, want)
692 }
693 }
694
695 func TestReplaceAttrGroups(t *testing.T) {
696
697 type ga struct {
698 groups string
699 key string
700 val string
701 }
702
703 var got []ga
704
705 h := NewTextHandler(io.Discard, &HandlerOptions{ReplaceAttr: func(gs []string, a Attr) Attr {
706 v := a.Value.String()
707 if a.Key == TimeKey {
708 v = "<now>"
709 }
710 got = append(got, ga{strings.Join(gs, ","), a.Key, v})
711 return a
712 }})
713 New(h).
714 With(Int("a", 1)).
715 WithGroup("g1").
716 With(Int("b", 2)).
717 WithGroup("g2").
718 With(
719 Int("c", 3),
720 Group("g3", Int("d", 4)),
721 Int("e", 5)).
722 Info("m",
723 Int("f", 6),
724 Group("g4", Int("h", 7)),
725 Int("i", 8))
726
727 want := []ga{
728 {"", "a", "1"},
729 {"g1", "b", "2"},
730 {"g1,g2", "c", "3"},
731 {"g1,g2,g3", "d", "4"},
732 {"g1,g2", "e", "5"},
733 {"", "time", "<now>"},
734 {"", "level", "INFO"},
735 {"", "msg", "m"},
736 {"g1,g2", "f", "6"},
737 {"g1,g2,g4", "h", "7"},
738 {"g1,g2", "i", "8"},
739 }
740 if !slices.Equal(got, want) {
741 t.Errorf("\ngot %v\nwant %v", got, want)
742 }
743 }
744
745 const rfc3339Millis = "2006-01-02T15:04:05.000Z07:00"
746
747 func TestWriteTimeRFC3339(t *testing.T) {
748 for _, tm := range []time.Time{
749 time.Date(2000, 1, 2, 3, 4, 5, 0, time.UTC),
750 time.Date(2000, 1, 2, 3, 4, 5, 400, time.Local),
751 time.Date(2000, 11, 12, 3, 4, 500, 5e7, time.UTC),
752 } {
753 got := string(appendRFC3339Millis(nil, tm))
754 want := tm.Format(rfc3339Millis)
755 if got != want {
756 t.Errorf("got %s, want %s", got, want)
757 }
758 }
759 }
760
761 func BenchmarkWriteTime(b *testing.B) {
762 tm := time.Date(2022, 3, 4, 5, 6, 7, 823456789, time.Local)
763 b.ResetTimer()
764 var buf []byte
765 for i := 0; i < b.N; i++ {
766 buf = appendRFC3339Millis(buf[:0], tm)
767 }
768 }
769
770 func TestDiscardHandler(t *testing.T) {
771 ctx := context.Background()
772 stdout, stderr := os.Stdout, os.Stderr
773 os.Stdout, os.Stderr = nil, nil
774 t.Cleanup(func() {
775 os.Stdout, os.Stderr = stdout, stderr
776 })
777
778
779 l := New(DiscardHandler)
780 l.Info("msg", "a", 1, "b", 2)
781 l.Debug("bg", Int("a", 1), "b", 2)
782 l.Warn("w", Duration("dur", 3*time.Second))
783 l.Error("bad", "a", 1)
784 l.Log(ctx, LevelWarn+1, "w", Int("a", 1), String("b", "two"))
785 l.LogAttrs(ctx, LevelInfo+1, "a b c", Int("a", 1), String("b", "two"))
786 l.Info("info", "a", []Attr{Int("i", 1)})
787 l.Info("info", "a", GroupValue(Int("i", 1)))
788 }
789
790 func BenchmarkAppendKey(b *testing.B) {
791 for _, size := range []int{5, 10, 30, 50, 100} {
792 for _, quoting := range []string{"no_quoting", "pre_quoting", "key_quoting", "both_quoting"} {
793 b.Run(fmt.Sprintf("%s_prefix_size_%d", quoting, size), func(b *testing.B) {
794 var (
795 hs = NewJSONHandler(io.Discard, nil).newHandleState(buffer.New(), false, "")
796 prefix = bytes.Repeat([]byte("x"), size)
797 key = "key"
798 )
799
800 if quoting == "pre_quoting" || quoting == "both_quoting" {
801 prefix[0] = '"'
802 }
803 if quoting == "key_quoting" || quoting == "both_quoting" {
804 key = "ke\""
805 }
806
807 hs.prefix = (*buffer.Buffer)(&prefix)
808
809 for b.Loop() {
810 hs.appendKey(key)
811 hs.buf.Reset()
812 }
813 })
814 }
815 }
816 }
817
View as plain text