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 5package slog 6 7import ( 8 "bytes" 9 "context" 10 "encoding/json" 11 "errors" 12 "fmt" 13 "io" 14 "log/slog/internal/buffer" 15 "math" 16 "os" 17 "path/filepath" 18 "strings" 19 "testing" 20 "time" 21) 22 23func TestJSONHandler(t *testing.T) { 24 for _, test := range []struct { 25 name string 26 opts HandlerOptions 27 want string 28 }{ 29 { 30 "none", 31 HandlerOptions{}, 32 `{"time":"2000-01-02T03:04:05Z","level":"INFO","msg":"m","a":1,"m":{"b":2}}`, 33 }, 34 { 35 "replace", 36 HandlerOptions{ReplaceAttr: upperCaseKey}, 37 `{"TIME":"2000-01-02T03:04:05Z","LEVEL":"INFO","MSG":"m","A":1,"M":{"b":2}}`, 38 }, 39 } { 40 t.Run(test.name, func(t *testing.T) { 41 var buf bytes.Buffer 42 h := NewJSONHandler(&buf, &test.opts) 43 r := NewRecord(testTime, LevelInfo, "m", 0) 44 r.AddAttrs(Int("a", 1), Any("m", map[string]int{"b": 2})) 45 if err := h.Handle(context.Background(), r); err != nil { 46 t.Fatal(err) 47 } 48 got := strings.TrimSuffix(buf.String(), "\n") 49 if got != test.want { 50 t.Errorf("\ngot %s\nwant %s", got, test.want) 51 } 52 }) 53 } 54} 55 56// for testing json.Marshaler 57type jsonMarshaler struct { 58 s string 59} 60 61func (j jsonMarshaler) String() string { return j.s } // should be ignored 62 63func (j jsonMarshaler) MarshalJSON() ([]byte, error) { 64 if j.s == "" { 65 return nil, errors.New("json: empty string") 66 } 67 return []byte(fmt.Sprintf(`[%q]`, j.s)), nil 68} 69 70type jsonMarshalerError struct { 71 jsonMarshaler 72} 73 74func (jsonMarshalerError) Error() string { return "oops" } 75 76func TestAppendJSONValue(t *testing.T) { 77 // jsonAppendAttrValue should always agree with json.Marshal. 78 for _, value := range []any{ 79 "hello\r\n\t\a", 80 `"[{escape}]"`, 81 "<escapeHTML&>", 82 // \u2028\u2029 is an edge case in JavaScript vs JSON. 83 // \xF6 is an incomplete encoding. 84 "\u03B8\u2028\u2029\uFFFF\xF6", 85 `-123`, 86 int64(-9_200_123_456_789_123_456), 87 uint64(9_200_123_456_789_123_456), 88 -12.75, 89 1.23e-9, 90 false, 91 time.Minute, 92 testTime, 93 jsonMarshaler{"xyz"}, 94 jsonMarshalerError{jsonMarshaler{"pqr"}}, 95 LevelWarn, 96 } { 97 got := jsonValueString(AnyValue(value)) 98 want, err := marshalJSON(value) 99 if err != nil { 100 t.Fatal(err) 101 } 102 if got != want { 103 t.Errorf("%v: got %s, want %s", value, got, want) 104 } 105 } 106} 107 108func marshalJSON(x any) (string, error) { 109 var buf bytes.Buffer 110 enc := json.NewEncoder(&buf) 111 enc.SetEscapeHTML(false) 112 if err := enc.Encode(x); err != nil { 113 return "", err 114 } 115 return strings.TrimSpace(buf.String()), nil 116} 117 118func TestJSONAppendAttrValueSpecial(t *testing.T) { 119 // Attr values that render differently from json.Marshal. 120 for _, test := range []struct { 121 value any 122 want string 123 }{ 124 {math.NaN(), `"!ERROR:json: unsupported value: NaN"`}, 125 {math.Inf(+1), `"!ERROR:json: unsupported value: +Inf"`}, 126 {math.Inf(-1), `"!ERROR:json: unsupported value: -Inf"`}, 127 {io.EOF, `"EOF"`}, 128 } { 129 got := jsonValueString(AnyValue(test.value)) 130 if got != test.want { 131 t.Errorf("%v: got %s, want %s", test.value, got, test.want) 132 } 133 } 134} 135 136func jsonValueString(v Value) string { 137 var buf []byte 138 s := &handleState{h: &commonHandler{json: true}, buf: (*buffer.Buffer)(&buf)} 139 if err := appendJSONValue(s, v); err != nil { 140 s.appendError(err) 141 } 142 return string(buf) 143} 144 145func BenchmarkJSONHandler(b *testing.B) { 146 for _, bench := range []struct { 147 name string 148 opts HandlerOptions 149 }{ 150 {"defaults", HandlerOptions{}}, 151 {"time format", HandlerOptions{ 152 ReplaceAttr: func(_ []string, a Attr) Attr { 153 v := a.Value 154 if v.Kind() == KindTime { 155 return String(a.Key, v.Time().Format(rfc3339Millis)) 156 } 157 if a.Key == "level" { 158 return Attr{"severity", a.Value} 159 } 160 return a 161 }, 162 }}, 163 {"time unix", HandlerOptions{ 164 ReplaceAttr: func(_ []string, a Attr) Attr { 165 v := a.Value 166 if v.Kind() == KindTime { 167 return Int64(a.Key, v.Time().UnixNano()) 168 } 169 if a.Key == "level" { 170 return Attr{"severity", a.Value} 171 } 172 return a 173 }, 174 }}, 175 } { 176 b.Run(bench.name, func(b *testing.B) { 177 ctx := context.Background() 178 l := New(NewJSONHandler(io.Discard, &bench.opts)).With( 179 String("program", "my-test-program"), 180 String("package", "log/slog"), 181 String("traceID", "2039232309232309"), 182 String("URL", "https://pkg.go.dev/golang.org/x/log/slog")) 183 b.ReportAllocs() 184 b.ResetTimer() 185 for i := 0; i < b.N; i++ { 186 l.LogAttrs(ctx, LevelInfo, "this is a typical log message", 187 String("module", "github.com/google/go-cmp"), 188 String("version", "v1.23.4"), 189 Int("count", 23), 190 Int("number", 123456), 191 ) 192 } 193 }) 194 } 195} 196 197func BenchmarkPreformatting(b *testing.B) { 198 type req struct { 199 Method string 200 URL string 201 TraceID string 202 Addr string 203 } 204 205 structAttrs := []any{ 206 String("program", "my-test-program"), 207 String("package", "log/slog"), 208 Any("request", &req{ 209 Method: "GET", 210 URL: "https://pkg.go.dev/golang.org/x/log/slog", 211 TraceID: "2039232309232309", 212 Addr: "127.0.0.1:8080", 213 }), 214 } 215 216 outFile, err := os.Create(filepath.Join(b.TempDir(), "bench.log")) 217 if err != nil { 218 b.Fatal(err) 219 } 220 defer func() { 221 if err := outFile.Close(); err != nil { 222 b.Fatal(err) 223 } 224 }() 225 226 for _, bench := range []struct { 227 name string 228 wc io.Writer 229 attrs []any 230 }{ 231 {"separate", io.Discard, []any{ 232 String("program", "my-test-program"), 233 String("package", "log/slog"), 234 String("method", "GET"), 235 String("URL", "https://pkg.go.dev/golang.org/x/log/slog"), 236 String("traceID", "2039232309232309"), 237 String("addr", "127.0.0.1:8080"), 238 }}, 239 {"struct", io.Discard, structAttrs}, 240 {"struct file", outFile, structAttrs}, 241 } { 242 ctx := context.Background() 243 b.Run(bench.name, func(b *testing.B) { 244 l := New(NewJSONHandler(bench.wc, nil)).With(bench.attrs...) 245 b.ReportAllocs() 246 b.ResetTimer() 247 for i := 0; i < b.N; i++ { 248 l.LogAttrs(ctx, LevelInfo, "this is a typical log message", 249 String("module", "github.com/google/go-cmp"), 250 String("version", "v1.23.4"), 251 Int("count", 23), 252 Int("number", 123456), 253 ) 254 } 255 }) 256 } 257} 258 259func BenchmarkJSONEncoding(b *testing.B) { 260 value := 3.14 261 buf := buffer.New() 262 defer buf.Free() 263 b.Run("json.Marshal", func(b *testing.B) { 264 b.ReportAllocs() 265 for i := 0; i < b.N; i++ { 266 by, err := json.Marshal(value) 267 if err != nil { 268 b.Fatal(err) 269 } 270 buf.Write(by) 271 *buf = (*buf)[:0] 272 } 273 }) 274 b.Run("Encoder.Encode", func(b *testing.B) { 275 b.ReportAllocs() 276 for i := 0; i < b.N; i++ { 277 if err := json.NewEncoder(buf).Encode(value); err != nil { 278 b.Fatal(err) 279 } 280 *buf = (*buf)[:0] 281 } 282 }) 283 _ = buf 284} 285