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

View as plain text