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 "internal/race" 11 "internal/testenv" 12 "io" 13 "log" 14 loginternal "log/internal" 15 "path/filepath" 16 "regexp" 17 "runtime" 18 "slices" 19 "strings" 20 "sync" 21 "testing" 22 "time" 23) 24 25// textTimeRE is a regexp to match log timestamps for Text handler. 26// This is RFC3339Nano with the fixed 3 digit sub-second precision. 27const textTimeRE = `\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}(Z|[+-]\d{2}:\d{2})` 28 29// jsonTimeRE is a regexp to match log timestamps for Text handler. 30// This is RFC3339Nano with an arbitrary sub-second precision. 31const jsonTimeRE = `\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d+)?(Z|[+-]\d{2}:\d{2})` 32 33func TestLogTextHandler(t *testing.T) { 34 ctx := context.Background() 35 var buf bytes.Buffer 36 37 l := New(NewTextHandler(&buf, nil)) 38 39 check := func(want string) { 40 t.Helper() 41 if want != "" { 42 want = "time=" + textTimeRE + " " + want 43 } 44 checkLogOutput(t, buf.String(), want) 45 buf.Reset() 46 } 47 48 l.Info("msg", "a", 1, "b", 2) 49 check(`level=INFO msg=msg a=1 b=2`) 50 51 // By default, debug messages are not printed. 52 l.Debug("bg", Int("a", 1), "b", 2) 53 check("") 54 55 l.Warn("w", Duration("dur", 3*time.Second)) 56 check(`level=WARN msg=w dur=3s`) 57 58 l.Error("bad", "a", 1) 59 check(`level=ERROR msg=bad a=1`) 60 61 l.Log(ctx, LevelWarn+1, "w", Int("a", 1), String("b", "two")) 62 check(`level=WARN\+1 msg=w a=1 b=two`) 63 64 l.LogAttrs(ctx, LevelInfo+1, "a b c", Int("a", 1), String("b", "two")) 65 check(`level=INFO\+1 msg="a b c" a=1 b=two`) 66 67 l.Info("info", "a", []Attr{Int("i", 1)}) 68 check(`level=INFO msg=info a.i=1`) 69 70 l.Info("info", "a", GroupValue(Int("i", 1))) 71 check(`level=INFO msg=info a.i=1`) 72} 73 74func TestConnections(t *testing.T) { 75 var logbuf, slogbuf bytes.Buffer 76 77 // Revert any changes to the default logger. This is important because other 78 // tests might change the default logger using SetDefault. Also ensure we 79 // restore the default logger at the end of the test. 80 currentLogger := Default() 81 currentLogWriter := log.Writer() 82 currentLogFlags := log.Flags() 83 SetDefault(New(newDefaultHandler(loginternal.DefaultOutput))) 84 t.Cleanup(func() { 85 SetDefault(currentLogger) 86 log.SetOutput(currentLogWriter) 87 log.SetFlags(currentLogFlags) 88 }) 89 90 // The default slog.Logger's handler uses the log package's default output. 91 log.SetOutput(&logbuf) 92 log.SetFlags(log.Lshortfile &^ log.LstdFlags) 93 Info("msg", "a", 1) 94 checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: INFO msg a=1`) 95 logbuf.Reset() 96 Info("msg", "p", nil) 97 checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: INFO msg p=<nil>`) 98 logbuf.Reset() 99 var r *regexp.Regexp 100 Info("msg", "r", r) 101 checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: INFO msg r=<nil>`) 102 logbuf.Reset() 103 Warn("msg", "b", 2) 104 checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: WARN msg b=2`) 105 logbuf.Reset() 106 Error("msg", "err", io.EOF, "c", 3) 107 checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: ERROR msg err=EOF c=3`) 108 109 // Levels below Info are not printed. 110 logbuf.Reset() 111 Debug("msg", "c", 3) 112 checkLogOutput(t, logbuf.String(), "") 113 114 t.Run("wrap default handler", func(t *testing.T) { 115 // It should be possible to wrap the default handler and get the right output. 116 // This works because the default handler uses the pc in the Record 117 // to get the source line, rather than a call depth. 118 logger := New(wrappingHandler{Default().Handler()}) 119 logger.Info("msg", "d", 4) 120 checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: INFO msg d=4`) 121 }) 122 123 // Once slog.SetDefault is called, the direction is reversed: the default 124 // log.Logger's output goes through the handler. 125 SetDefault(New(NewTextHandler(&slogbuf, &HandlerOptions{AddSource: true}))) 126 log.Print("msg2") 127 checkLogOutput(t, slogbuf.String(), "time="+textTimeRE+` level=INFO source=.*logger_test.go:\d{3}"? msg=msg2`) 128 129 // The default log.Logger always outputs at Info level. 130 slogbuf.Reset() 131 SetDefault(New(NewTextHandler(&slogbuf, &HandlerOptions{Level: LevelWarn}))) 132 log.Print("should not appear") 133 if got := slogbuf.String(); got != "" { 134 t.Errorf("got %q, want empty", got) 135 } 136 137 // Setting log's output again breaks the connection. 138 logbuf.Reset() 139 slogbuf.Reset() 140 log.SetOutput(&logbuf) 141 log.SetFlags(log.Lshortfile &^ log.LstdFlags) 142 log.Print("msg3") 143 checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: msg3`) 144 if got := slogbuf.String(); got != "" { 145 t.Errorf("got %q, want empty", got) 146 } 147} 148 149type wrappingHandler struct { 150 h Handler 151} 152 153func (h wrappingHandler) Enabled(ctx context.Context, level Level) bool { 154 return h.h.Enabled(ctx, level) 155} 156func (h wrappingHandler) WithGroup(name string) Handler { return h.h.WithGroup(name) } 157func (h wrappingHandler) WithAttrs(as []Attr) Handler { return h.h.WithAttrs(as) } 158func (h wrappingHandler) Handle(ctx context.Context, r Record) error { return h.h.Handle(ctx, r) } 159 160func TestAttrs(t *testing.T) { 161 check := func(got []Attr, want ...Attr) { 162 t.Helper() 163 if !attrsEqual(got, want) { 164 t.Errorf("got %v, want %v", got, want) 165 } 166 } 167 168 l1 := New(&captureHandler{}).With("a", 1) 169 l2 := New(l1.Handler()).With("b", 2) 170 l2.Info("m", "c", 3) 171 h := l2.Handler().(*captureHandler) 172 check(h.attrs, Int("a", 1), Int("b", 2)) 173 check(attrsSlice(h.r), Int("c", 3)) 174} 175 176func TestCallDepth(t *testing.T) { 177 ctx := context.Background() 178 h := &captureHandler{} 179 var startLine int 180 181 check := func(count int) { 182 t.Helper() 183 const wantFunc = "log/slog.TestCallDepth" 184 const wantFile = "logger_test.go" 185 wantLine := startLine + count*2 186 got := h.r.source() 187 gotFile := filepath.Base(got.File) 188 if got.Function != wantFunc || gotFile != wantFile || got.Line != wantLine { 189 t.Errorf("got (%s, %s, %d), want (%s, %s, %d)", 190 got.Function, gotFile, got.Line, wantFunc, wantFile, wantLine) 191 } 192 } 193 194 defer SetDefault(Default()) // restore 195 logger := New(h) 196 SetDefault(logger) 197 198 // Calls to check must be one line apart. 199 // Determine line where calls start. 200 f, _ := runtime.CallersFrames([]uintptr{callerPC(2)}).Next() 201 startLine = f.Line + 4 202 // Do not change the number of lines between here and the call to check(0). 203 204 logger.Log(ctx, LevelInfo, "") 205 check(0) 206 logger.LogAttrs(ctx, LevelInfo, "") 207 check(1) 208 logger.Debug("") 209 check(2) 210 logger.Info("") 211 check(3) 212 logger.Warn("") 213 check(4) 214 logger.Error("") 215 check(5) 216 Debug("") 217 check(6) 218 Info("") 219 check(7) 220 Warn("") 221 check(8) 222 Error("") 223 check(9) 224 Log(ctx, LevelInfo, "") 225 check(10) 226 LogAttrs(ctx, LevelInfo, "") 227 check(11) 228} 229 230func TestAlloc(t *testing.T) { 231 ctx := context.Background() 232 dl := New(discardHandler{}) 233 defer SetDefault(Default()) // restore 234 SetDefault(dl) 235 236 t.Run("Info", func(t *testing.T) { 237 wantAllocs(t, 0, func() { Info("hello") }) 238 }) 239 t.Run("Error", func(t *testing.T) { 240 wantAllocs(t, 0, func() { Error("hello") }) 241 }) 242 t.Run("logger.Info", func(t *testing.T) { 243 wantAllocs(t, 0, func() { dl.Info("hello") }) 244 }) 245 t.Run("logger.Log", func(t *testing.T) { 246 wantAllocs(t, 0, func() { dl.Log(ctx, LevelDebug, "hello") }) 247 }) 248 t.Run("2 pairs", func(t *testing.T) { 249 s := "abc" 250 i := 2000 251 wantAllocs(t, 2, func() { 252 dl.Info("hello", 253 "n", i, 254 "s", s, 255 ) 256 }) 257 }) 258 t.Run("2 pairs disabled inline", func(t *testing.T) { 259 l := New(discardHandler{disabled: true}) 260 s := "abc" 261 i := 2000 262 wantAllocs(t, 2, func() { 263 l.Log(ctx, LevelInfo, "hello", 264 "n", i, 265 "s", s, 266 ) 267 }) 268 }) 269 t.Run("2 pairs disabled", func(t *testing.T) { 270 l := New(discardHandler{disabled: true}) 271 s := "abc" 272 i := 2000 273 wantAllocs(t, 0, func() { 274 if l.Enabled(ctx, LevelInfo) { 275 l.Log(ctx, LevelInfo, "hello", 276 "n", i, 277 "s", s, 278 ) 279 } 280 }) 281 }) 282 t.Run("9 kvs", func(t *testing.T) { 283 s := "abc" 284 i := 2000 285 d := time.Second 286 wantAllocs(t, 10, func() { 287 dl.Info("hello", 288 "n", i, "s", s, "d", d, 289 "n", i, "s", s, "d", d, 290 "n", i, "s", s, "d", d) 291 }) 292 }) 293 t.Run("pairs", func(t *testing.T) { 294 wantAllocs(t, 0, func() { dl.Info("", "error", io.EOF) }) 295 }) 296 t.Run("attrs1", func(t *testing.T) { 297 wantAllocs(t, 0, func() { dl.LogAttrs(ctx, LevelInfo, "", Int("a", 1)) }) 298 wantAllocs(t, 0, func() { dl.LogAttrs(ctx, LevelInfo, "", Any("error", io.EOF)) }) 299 }) 300 t.Run("attrs3", func(t *testing.T) { 301 wantAllocs(t, 0, func() { 302 dl.LogAttrs(ctx, LevelInfo, "hello", Int("a", 1), String("b", "two"), Duration("c", time.Second)) 303 }) 304 }) 305 t.Run("attrs3 disabled", func(t *testing.T) { 306 logger := New(discardHandler{disabled: true}) 307 wantAllocs(t, 0, func() { 308 logger.LogAttrs(ctx, LevelInfo, "hello", Int("a", 1), String("b", "two"), Duration("c", time.Second)) 309 }) 310 }) 311 t.Run("attrs6", func(t *testing.T) { 312 wantAllocs(t, 1, func() { 313 dl.LogAttrs(ctx, LevelInfo, "hello", 314 Int("a", 1), String("b", "two"), Duration("c", time.Second), 315 Int("d", 1), String("e", "two"), Duration("f", time.Second)) 316 }) 317 }) 318 t.Run("attrs9", func(t *testing.T) { 319 wantAllocs(t, 1, func() { 320 dl.LogAttrs(ctx, LevelInfo, "hello", 321 Int("a", 1), String("b", "two"), Duration("c", time.Second), 322 Int("d", 1), String("e", "two"), Duration("f", time.Second), 323 Int("d", 1), String("e", "two"), Duration("f", time.Second)) 324 }) 325 }) 326} 327 328func TestSetAttrs(t *testing.T) { 329 for _, test := range []struct { 330 args []any 331 want []Attr 332 }{ 333 {nil, nil}, 334 {[]any{"a", 1}, []Attr{Int("a", 1)}}, 335 {[]any{"a", 1, "b", "two"}, []Attr{Int("a", 1), String("b", "two")}}, 336 {[]any{"a"}, []Attr{String(badKey, "a")}}, 337 {[]any{"a", 1, "b"}, []Attr{Int("a", 1), String(badKey, "b")}}, 338 {[]any{"a", 1, 2, 3}, []Attr{Int("a", 1), Int(badKey, 2), Int(badKey, 3)}}, 339 } { 340 r := NewRecord(time.Time{}, 0, "", 0) 341 r.Add(test.args...) 342 got := attrsSlice(r) 343 if !attrsEqual(got, test.want) { 344 t.Errorf("%v:\ngot %v\nwant %v", test.args, got, test.want) 345 } 346 } 347} 348 349func TestSetDefault(t *testing.T) { 350 // Verify that setting the default to itself does not result in deadlock. 351 ctx, cancel := context.WithTimeout(context.Background(), time.Second) 352 defer cancel() 353 defer func(w io.Writer) { log.SetOutput(w) }(log.Writer()) 354 log.SetOutput(io.Discard) 355 go func() { 356 Info("A") 357 SetDefault(Default()) 358 Info("B") 359 cancel() 360 }() 361 <-ctx.Done() 362 if err := ctx.Err(); err != context.Canceled { 363 t.Errorf("wanted canceled, got %v", err) 364 } 365} 366 367// Test defaultHandler minimum level without calling slog.SetDefault. 368func TestLogLoggerLevelForDefaultHandler(t *testing.T) { 369 // Revert any changes to the default logger, flags, and level of log and slog. 370 currentLogLoggerLevel := logLoggerLevel.Level() 371 currentLogWriter := log.Writer() 372 currentLogFlags := log.Flags() 373 t.Cleanup(func() { 374 logLoggerLevel.Set(currentLogLoggerLevel) 375 log.SetOutput(currentLogWriter) 376 log.SetFlags(currentLogFlags) 377 }) 378 379 var logBuf bytes.Buffer 380 log.SetOutput(&logBuf) 381 log.SetFlags(0) 382 383 for _, test := range []struct { 384 logLevel Level 385 logFn func(string, ...any) 386 want string 387 }{ 388 {LevelDebug, Debug, "DEBUG a"}, 389 {LevelDebug, Info, "INFO a"}, 390 {LevelInfo, Debug, ""}, 391 {LevelInfo, Info, "INFO a"}, 392 } { 393 SetLogLoggerLevel(test.logLevel) 394 test.logFn("a") 395 checkLogOutput(t, logBuf.String(), test.want) 396 logBuf.Reset() 397 } 398} 399 400// Test handlerWriter minimum level by calling slog.SetDefault. 401func TestLogLoggerLevelForHandlerWriter(t *testing.T) { 402 removeTime := func(_ []string, a Attr) Attr { 403 if a.Key == TimeKey { 404 return Attr{} 405 } 406 return a 407 } 408 409 // Revert any changes to the default logger. This is important because other 410 // tests might change the default logger using SetDefault. Also ensure we 411 // restore the default logger at the end of the test. 412 currentLogger := Default() 413 currentLogLoggerLevel := logLoggerLevel.Level() 414 currentLogWriter := log.Writer() 415 currentFlags := log.Flags() 416 t.Cleanup(func() { 417 SetDefault(currentLogger) 418 logLoggerLevel.Set(currentLogLoggerLevel) 419 log.SetOutput(currentLogWriter) 420 log.SetFlags(currentFlags) 421 }) 422 423 var logBuf bytes.Buffer 424 log.SetOutput(&logBuf) 425 log.SetFlags(0) 426 SetLogLoggerLevel(LevelError) 427 SetDefault(New(NewTextHandler(&logBuf, &HandlerOptions{ReplaceAttr: removeTime}))) 428 log.Print("error") 429 checkLogOutput(t, logBuf.String(), `level=ERROR msg=error`) 430} 431 432func TestLoggerError(t *testing.T) { 433 var buf bytes.Buffer 434 435 removeTime := func(_ []string, a Attr) Attr { 436 if a.Key == TimeKey { 437 return Attr{} 438 } 439 return a 440 } 441 l := New(NewTextHandler(&buf, &HandlerOptions{ReplaceAttr: removeTime})) 442 l.Error("msg", "err", io.EOF, "a", 1) 443 checkLogOutput(t, buf.String(), `level=ERROR msg=msg err=EOF a=1`) 444 buf.Reset() 445 // use local var 'args' to defeat vet check 446 args := []any{"err", io.EOF, "a"} 447 l.Error("msg", args...) 448 checkLogOutput(t, buf.String(), `level=ERROR msg=msg err=EOF !BADKEY=a`) 449} 450 451func TestNewLogLogger(t *testing.T) { 452 var buf bytes.Buffer 453 h := NewTextHandler(&buf, nil) 454 ll := NewLogLogger(h, LevelWarn) 455 ll.Print("hello") 456 checkLogOutput(t, buf.String(), "time="+textTimeRE+` level=WARN msg=hello`) 457} 458 459func TestLoggerNoOps(t *testing.T) { 460 l := Default() 461 if l.With() != l { 462 t.Error("wanted receiver, didn't get it") 463 } 464 if With() != l { 465 t.Error("wanted receiver, didn't get it") 466 } 467 if l.WithGroup("") != l { 468 t.Error("wanted receiver, didn't get it") 469 } 470} 471 472func TestContext(t *testing.T) { 473 // Verify that the context argument to log output methods is passed to the handler. 474 // Also check the level. 475 h := &captureHandler{} 476 l := New(h) 477 defer SetDefault(Default()) // restore 478 SetDefault(l) 479 480 for _, test := range []struct { 481 f func(context.Context, string, ...any) 482 wantLevel Level 483 }{ 484 {l.DebugContext, LevelDebug}, 485 {l.InfoContext, LevelInfo}, 486 {l.WarnContext, LevelWarn}, 487 {l.ErrorContext, LevelError}, 488 {DebugContext, LevelDebug}, 489 {InfoContext, LevelInfo}, 490 {WarnContext, LevelWarn}, 491 {ErrorContext, LevelError}, 492 } { 493 h.clear() 494 ctx := context.WithValue(context.Background(), "L", test.wantLevel) 495 496 test.f(ctx, "msg") 497 if gv := h.ctx.Value("L"); gv != test.wantLevel || h.r.Level != test.wantLevel { 498 t.Errorf("got context value %v, level %s; want %s for both", gv, h.r.Level, test.wantLevel) 499 } 500 } 501} 502 503func checkLogOutput(t *testing.T, got, wantRegexp string) { 504 t.Helper() 505 got = clean(got) 506 wantRegexp = "^" + wantRegexp + "$" 507 matched, err := regexp.MatchString(wantRegexp, got) 508 if err != nil { 509 t.Fatal(err) 510 } 511 if !matched { 512 t.Errorf("\ngot %s\nwant %s", got, wantRegexp) 513 } 514} 515 516// clean prepares log output for comparison. 517func clean(s string) string { 518 if len(s) > 0 && s[len(s)-1] == '\n' { 519 s = s[:len(s)-1] 520 } 521 return strings.ReplaceAll(s, "\n", "~") 522} 523 524type captureHandler struct { 525 mu sync.Mutex 526 ctx context.Context 527 r Record 528 attrs []Attr 529 groups []string 530} 531 532func (h *captureHandler) Handle(ctx context.Context, r Record) error { 533 h.mu.Lock() 534 defer h.mu.Unlock() 535 h.ctx = ctx 536 h.r = r 537 return nil 538} 539 540func (*captureHandler) Enabled(context.Context, Level) bool { return true } 541 542func (c *captureHandler) WithAttrs(as []Attr) Handler { 543 c.mu.Lock() 544 defer c.mu.Unlock() 545 var c2 captureHandler 546 c2.r = c.r 547 c2.groups = c.groups 548 c2.attrs = concat(c.attrs, as) 549 return &c2 550} 551 552func (c *captureHandler) WithGroup(name string) Handler { 553 c.mu.Lock() 554 defer c.mu.Unlock() 555 var c2 captureHandler 556 c2.r = c.r 557 c2.attrs = c.attrs 558 c2.groups = append(slices.Clip(c.groups), name) 559 return &c2 560} 561 562func (c *captureHandler) clear() { 563 c.mu.Lock() 564 defer c.mu.Unlock() 565 c.ctx = nil 566 c.r = Record{} 567} 568 569type discardHandler struct { 570 disabled bool 571 attrs []Attr 572} 573 574func (d discardHandler) Enabled(context.Context, Level) bool { return !d.disabled } 575func (discardHandler) Handle(context.Context, Record) error { return nil } 576func (d discardHandler) WithAttrs(as []Attr) Handler { 577 d.attrs = concat(d.attrs, as) 578 return d 579} 580func (h discardHandler) WithGroup(name string) Handler { 581 return h 582} 583 584// concat returns a new slice with the elements of s1 followed 585// by those of s2. The slice has no additional capacity. 586func concat[T any](s1, s2 []T) []T { 587 s := make([]T, len(s1)+len(s2)) 588 copy(s, s1) 589 copy(s[len(s1):], s2) 590 return s 591} 592 593// This is a simple benchmark. See the benchmarks subdirectory for more extensive ones. 594func BenchmarkNopLog(b *testing.B) { 595 ctx := context.Background() 596 l := New(&captureHandler{}) 597 b.Run("no attrs", func(b *testing.B) { 598 b.ReportAllocs() 599 for i := 0; i < b.N; i++ { 600 l.LogAttrs(ctx, LevelInfo, "msg") 601 } 602 }) 603 b.Run("attrs", func(b *testing.B) { 604 b.ReportAllocs() 605 for i := 0; i < b.N; i++ { 606 l.LogAttrs(ctx, LevelInfo, "msg", Int("a", 1), String("b", "two"), Bool("c", true)) 607 } 608 }) 609 b.Run("attrs-parallel", func(b *testing.B) { 610 b.ReportAllocs() 611 b.RunParallel(func(pb *testing.PB) { 612 for pb.Next() { 613 l.LogAttrs(ctx, LevelInfo, "msg", Int("a", 1), String("b", "two"), Bool("c", true)) 614 } 615 }) 616 }) 617 b.Run("keys-values", func(b *testing.B) { 618 b.ReportAllocs() 619 for i := 0; i < b.N; i++ { 620 l.Log(ctx, LevelInfo, "msg", "a", 1, "b", "two", "c", true) 621 } 622 }) 623 b.Run("WithContext", func(b *testing.B) { 624 b.ReportAllocs() 625 for i := 0; i < b.N; i++ { 626 l.LogAttrs(ctx, LevelInfo, "msg2", Int("a", 1), String("b", "two"), Bool("c", true)) 627 } 628 }) 629 b.Run("WithContext-parallel", func(b *testing.B) { 630 b.ReportAllocs() 631 b.RunParallel(func(pb *testing.PB) { 632 for pb.Next() { 633 l.LogAttrs(ctx, LevelInfo, "msg", Int("a", 1), String("b", "two"), Bool("c", true)) 634 } 635 }) 636 }) 637} 638 639// callerPC returns the program counter at the given stack depth. 640func callerPC(depth int) uintptr { 641 var pcs [1]uintptr 642 runtime.Callers(depth, pcs[:]) 643 return pcs[0] 644} 645 646func wantAllocs(t *testing.T, want int, f func()) { 647 if race.Enabled { 648 t.Skip("skipping test in race mode") 649 } 650 testenv.SkipIfOptimizationOff(t) 651 t.Helper() 652 got := int(testing.AllocsPerRun(5, f)) 653 if got != want { 654 t.Errorf("got %d allocs, want %d", got, want) 655 } 656} 657 658// panicTextAndJsonMarshaler is a type that panics in MarshalText and MarshalJSON. 659type panicTextAndJsonMarshaler struct { 660 msg any 661} 662 663func (p panicTextAndJsonMarshaler) MarshalText() ([]byte, error) { 664 panic(p.msg) 665} 666 667func (p panicTextAndJsonMarshaler) MarshalJSON() ([]byte, error) { 668 panic(p.msg) 669} 670 671func TestPanics(t *testing.T) { 672 // Revert any changes to the default logger. This is important because other 673 // tests might change the default logger using SetDefault. Also ensure we 674 // restore the default logger at the end of the test. 675 currentLogger := Default() 676 currentLogWriter := log.Writer() 677 currentLogFlags := log.Flags() 678 t.Cleanup(func() { 679 SetDefault(currentLogger) 680 log.SetOutput(currentLogWriter) 681 log.SetFlags(currentLogFlags) 682 }) 683 684 var logBuf bytes.Buffer 685 log.SetOutput(&logBuf) 686 log.SetFlags(log.Lshortfile &^ log.LstdFlags) 687 688 SetDefault(New(newDefaultHandler(loginternal.DefaultOutput))) 689 for _, pt := range []struct { 690 in any 691 out string 692 }{ 693 {(*panicTextAndJsonMarshaler)(nil), `logger_test.go:\d+: INFO msg p=<nil>`}, 694 {panicTextAndJsonMarshaler{io.ErrUnexpectedEOF}, `logger_test.go:\d+: INFO msg p="!PANIC: unexpected EOF"`}, 695 {panicTextAndJsonMarshaler{"panicking"}, `logger_test.go:\d+: INFO msg p="!PANIC: panicking"`}, 696 {panicTextAndJsonMarshaler{42}, `logger_test.go:\d+: INFO msg p="!PANIC: 42"`}, 697 } { 698 Info("msg", "p", pt.in) 699 checkLogOutput(t, logBuf.String(), pt.out) 700 logBuf.Reset() 701 } 702 703 SetDefault(New(NewJSONHandler(&logBuf, nil))) 704 for _, pt := range []struct { 705 in any 706 out string 707 }{ 708 {(*panicTextAndJsonMarshaler)(nil), `{"time":"` + jsonTimeRE + `","level":"INFO","msg":"msg","p":null}`}, 709 {panicTextAndJsonMarshaler{io.ErrUnexpectedEOF}, `{"time":"` + jsonTimeRE + `","level":"INFO","msg":"msg","p":"!PANIC: unexpected EOF"}`}, 710 {panicTextAndJsonMarshaler{"panicking"}, `{"time":"` + jsonTimeRE + `","level":"INFO","msg":"msg","p":"!PANIC: panicking"}`}, 711 {panicTextAndJsonMarshaler{42}, `{"time":"` + jsonTimeRE + `","level":"INFO","msg":"msg","p":"!PANIC: 42"}`}, 712 } { 713 Info("msg", "p", pt.in) 714 checkLogOutput(t, logBuf.String(), pt.out) 715 logBuf.Reset() 716 } 717} 718