Source file src/log/slog/handler_test.go

     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  // TODO: verify that the output of Marshal{Text,JSON} is suitably escaped.
     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  // Verify the common parts of TextHandler and JSONHandler.
   159  func TestJSONAndTextHandlers(t *testing.T) {
   160  	// remove all Attrs
   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), // to simplify the result
   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)), // dot is not escaped
   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  			// Test resolution when there is no ReplaceAttr function.
   311  			name: "resolve",
   312  			attrs: []Attr{
   313  				Any("", &replace{Value{}}), // should be elided
   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  		line := strconv.Itoa(r.source().Line)
   551  		r.AddAttrs(test.attrs...)
   552  		var buf bytes.Buffer
   553  		opts := HandlerOptions{ReplaceAttr: test.replace, AddSource: test.addSource}
   554  		t.Run(test.name, func(t *testing.T) {
   555  			for _, handler := range []struct {
   556  				name string
   557  				h    Handler
   558  				want string
   559  			}{
   560  				{"text", NewTextHandler(&buf, &opts), test.wantText},
   561  				{"json", NewJSONHandler(&buf, &opts), test.wantJSON},
   562  			} {
   563  				t.Run(handler.name, func(t *testing.T) {
   564  					h := handler.h
   565  					if test.with != nil {
   566  						h = test.with(h)
   567  					}
   568  					buf.Reset()
   569  					if err := h.Handle(nil, r); err != nil {
   570  						t.Fatal(err)
   571  					}
   572  					want := strings.ReplaceAll(handler.want, "$LINE", line)
   573  					got := strings.TrimSuffix(buf.String(), "\n")
   574  					if got != want {
   575  						t.Errorf("\ngot  %s\nwant %s\n", got, want)
   576  					}
   577  				})
   578  			}
   579  		})
   580  	}
   581  }
   582  
   583  // removeKeys returns a function suitable for HandlerOptions.ReplaceAttr
   584  // that removes all Attrs with the given keys.
   585  func removeKeys(keys ...string) func([]string, Attr) Attr {
   586  	return func(_ []string, a Attr) Attr {
   587  		for _, k := range keys {
   588  			if a.Key == k {
   589  				return Attr{}
   590  			}
   591  		}
   592  		return a
   593  	}
   594  }
   595  
   596  func upperCaseKey(_ []string, a Attr) Attr {
   597  	a.Key = strings.ToUpper(a.Key)
   598  	return a
   599  }
   600  
   601  type logValueName struct {
   602  	first, last string
   603  }
   604  
   605  func (n logValueName) LogValue() Value {
   606  	return GroupValue(
   607  		String("first", n.first),
   608  		String("last", n.last))
   609  }
   610  
   611  func TestHandlerEnabled(t *testing.T) {
   612  	levelVar := func(l Level) *LevelVar {
   613  		var al LevelVar
   614  		al.Set(l)
   615  		return &al
   616  	}
   617  
   618  	for _, test := range []struct {
   619  		leveler Leveler
   620  		want    bool
   621  	}{
   622  		{nil, true},
   623  		{LevelWarn, false},
   624  		{&LevelVar{}, true}, // defaults to Info
   625  		{levelVar(LevelWarn), false},
   626  		{LevelDebug, true},
   627  		{levelVar(LevelDebug), true},
   628  	} {
   629  		h := &commonHandler{opts: HandlerOptions{Level: test.leveler}}
   630  		got := h.enabled(LevelInfo)
   631  		if got != test.want {
   632  			t.Errorf("%v: got %t, want %t", test.leveler, got, test.want)
   633  		}
   634  	}
   635  }
   636  
   637  func TestSecondWith(t *testing.T) {
   638  	// Verify that a second call to Logger.With does not corrupt
   639  	// the original.
   640  	var buf bytes.Buffer
   641  	h := NewTextHandler(&buf, &HandlerOptions{ReplaceAttr: removeKeys(TimeKey)})
   642  	logger := New(h).With(
   643  		String("app", "playground"),
   644  		String("role", "tester"),
   645  		Int("data_version", 2),
   646  	)
   647  	appLogger := logger.With("type", "log") // this becomes type=met
   648  	_ = logger.With("type", "metric")
   649  	appLogger.Info("foo")
   650  	got := strings.TrimSpace(buf.String())
   651  	want := `level=INFO msg=foo app=playground role=tester data_version=2 type=log`
   652  	if got != want {
   653  		t.Errorf("\ngot  %s\nwant %s", got, want)
   654  	}
   655  }
   656  
   657  func TestReplaceAttrGroups(t *testing.T) {
   658  	// Verify that ReplaceAttr is called with the correct groups.
   659  	type ga struct {
   660  		groups string
   661  		key    string
   662  		val    string
   663  	}
   664  
   665  	var got []ga
   666  
   667  	h := NewTextHandler(io.Discard, &HandlerOptions{ReplaceAttr: func(gs []string, a Attr) Attr {
   668  		v := a.Value.String()
   669  		if a.Key == TimeKey {
   670  			v = "<now>"
   671  		}
   672  		got = append(got, ga{strings.Join(gs, ","), a.Key, v})
   673  		return a
   674  	}})
   675  	New(h).
   676  		With(Int("a", 1)).
   677  		WithGroup("g1").
   678  		With(Int("b", 2)).
   679  		WithGroup("g2").
   680  		With(
   681  			Int("c", 3),
   682  			Group("g3", Int("d", 4)),
   683  			Int("e", 5)).
   684  		Info("m",
   685  			Int("f", 6),
   686  			Group("g4", Int("h", 7)),
   687  			Int("i", 8))
   688  
   689  	want := []ga{
   690  		{"", "a", "1"},
   691  		{"g1", "b", "2"},
   692  		{"g1,g2", "c", "3"},
   693  		{"g1,g2,g3", "d", "4"},
   694  		{"g1,g2", "e", "5"},
   695  		{"", "time", "<now>"},
   696  		{"", "level", "INFO"},
   697  		{"", "msg", "m"},
   698  		{"g1,g2", "f", "6"},
   699  		{"g1,g2,g4", "h", "7"},
   700  		{"g1,g2", "i", "8"},
   701  	}
   702  	if !slices.Equal(got, want) {
   703  		t.Errorf("\ngot  %v\nwant %v", got, want)
   704  	}
   705  }
   706  
   707  const rfc3339Millis = "2006-01-02T15:04:05.000Z07:00"
   708  
   709  func TestWriteTimeRFC3339(t *testing.T) {
   710  	for _, tm := range []time.Time{
   711  		time.Date(2000, 1, 2, 3, 4, 5, 0, time.UTC),
   712  		time.Date(2000, 1, 2, 3, 4, 5, 400, time.Local),
   713  		time.Date(2000, 11, 12, 3, 4, 500, 5e7, time.UTC),
   714  	} {
   715  		got := string(appendRFC3339Millis(nil, tm))
   716  		want := tm.Format(rfc3339Millis)
   717  		if got != want {
   718  			t.Errorf("got %s, want %s", got, want)
   719  		}
   720  	}
   721  }
   722  
   723  func BenchmarkWriteTime(b *testing.B) {
   724  	tm := time.Date(2022, 3, 4, 5, 6, 7, 823456789, time.Local)
   725  	b.ResetTimer()
   726  	var buf []byte
   727  	for i := 0; i < b.N; i++ {
   728  		buf = appendRFC3339Millis(buf[:0], tm)
   729  	}
   730  }
   731  
   732  func TestDiscardHandler(t *testing.T) {
   733  	ctx := context.Background()
   734  	stdout, stderr := os.Stdout, os.Stderr
   735  	os.Stdout, os.Stderr = nil, nil // panic on write
   736  	t.Cleanup(func() {
   737  		os.Stdout, os.Stderr = stdout, stderr
   738  	})
   739  
   740  	// Just ensure nothing panics during normal usage
   741  	l := New(DiscardHandler)
   742  	l.Info("msg", "a", 1, "b", 2)
   743  	l.Debug("bg", Int("a", 1), "b", 2)
   744  	l.Warn("w", Duration("dur", 3*time.Second))
   745  	l.Error("bad", "a", 1)
   746  	l.Log(ctx, LevelWarn+1, "w", Int("a", 1), String("b", "two"))
   747  	l.LogAttrs(ctx, LevelInfo+1, "a b c", Int("a", 1), String("b", "two"))
   748  	l.Info("info", "a", []Attr{Int("i", 1)})
   749  	l.Info("info", "a", GroupValue(Int("i", 1)))
   750  }
   751  
   752  func BenchmarkAppendKey(b *testing.B) {
   753  	for _, size := range []int{5, 10, 30, 50, 100} {
   754  		for _, quoting := range []string{"no_quoting", "pre_quoting", "key_quoting", "both_quoting"} {
   755  			b.Run(fmt.Sprintf("%s_prefix_size_%d", quoting, size), func(b *testing.B) {
   756  				var (
   757  					hs     = NewJSONHandler(io.Discard, nil).newHandleState(buffer.New(), false, "")
   758  					prefix = bytes.Repeat([]byte("x"), size)
   759  					key    = "key"
   760  				)
   761  
   762  				if quoting == "pre_quoting" || quoting == "both_quoting" {
   763  					prefix[0] = '"'
   764  				}
   765  				if quoting == "key_quoting" || quoting == "both_quoting" {
   766  					key = "ke\""
   767  				}
   768  
   769  				hs.prefix = (*buffer.Buffer)(&prefix)
   770  
   771  				for b.Loop() {
   772  					hs.appendKey(key)
   773  					hs.buf.Reset()
   774  				}
   775  			})
   776  		}
   777  	}
   778  }
   779  

View as plain text