From 9e034475c8e8b0fbab47e1591974af1d9fc16249 Mon Sep 17 00:00:00 2001 From: Daniel Liu Date: Fri, 15 Nov 2024 10:02:42 +0800 Subject: [PATCH] log: default JSON log handler should log all verbosity levels (#29471) Co-authored-by: lightclient --- internal/debug/flags.go | 4 ++-- log/handler.go | 7 +++++++ log/logger_test.go | 29 ++++++++++++++++++++++++----- 3 files changed, 33 insertions(+), 7 deletions(-) diff --git a/internal/debug/flags.go b/internal/debug/flags.go index 8dc380c4b5..223e9c6fa5 100644 --- a/internal/debug/flags.go +++ b/internal/debug/flags.go @@ -226,9 +226,9 @@ func Setup(ctx *cli.Context) error { case ctx.Bool(logjsonFlag.Name): // Retain backwards compatibility with `--log-json` flag if `--log-format` not set defer log.Warn("The flag '--log-json' is deprecated, please use '--log-format=json' instead") - handler = log.JSONHandler(output) + handler = log.JSONHandlerWithLevel(output, log.LevelInfo) case logFmtFlag == "json": - handler = log.JSONHandler(output) + handler = log.JSONHandlerWithLevel(output, log.LevelInfo) case logFmtFlag == "logfmt": handler = log.LogfmtHandler(output) case logFmtFlag == "", logFmtFlag == "terminal": diff --git a/log/handler.go b/log/handler.go index 326859b138..56eff6671f 100644 --- a/log/handler.go +++ b/log/handler.go @@ -115,8 +115,15 @@ func (l *leveler) Level() slog.Level { // JSONHandler returns a handler which prints records in JSON format. func JSONHandler(wr io.Writer) slog.Handler { + return JSONHandlerWithLevel(wr, levelMaxVerbosity) +} + +// JSONHandlerWithLevel returns a handler which prints records in JSON format that are less than or equal to +// the specified verbosity level. +func JSONHandlerWithLevel(wr io.Writer, level slog.Level) slog.Handler { return slog.NewJSONHandler(wr, &slog.HandlerOptions{ ReplaceAttr: builtinReplaceJSON, + Level: &leveler{level}, }) } diff --git a/log/logger_test.go b/log/logger_test.go index d23e16e572..f1a9a93bce 100644 --- a/log/logger_test.go +++ b/log/logger_test.go @@ -26,7 +26,7 @@ func TestLoggingWithVmodule(t *testing.T) { logger.Trace("a message", "foo", "bar") have := out.String() // The timestamp is locale-dependent, so we want to trim that off - // "INFO [01-01|00:00:00.000] a messag ..." -> "a messag..." + // "INFO [01-01|00:00:00.000] a message ..." -> "a message..." have = strings.Split(have, "]")[1] want := " a message foo=bar\n" if have != want { @@ -42,7 +42,7 @@ func TestTerminalHandlerWithAttrs(t *testing.T) { logger.Trace("a message", "foo", "bar") have := out.String() // The timestamp is locale-dependent, so we want to trim that off - // "INFO [01-01|00:00:00.000] a messag ..." -> "a messag..." + // "INFO [01-01|00:00:00.000] a message ..." -> "a message..." have = strings.Split(have, "]")[1] want := " a message baz=bat foo=bar\n" if have != want { @@ -50,6 +50,25 @@ func TestTerminalHandlerWithAttrs(t *testing.T) { } } +// Make sure the default json handler outputs debug log lines +func TestJSONHandler(t *testing.T) { + out := new(bytes.Buffer) + handler := JSONHandler(out) + logger := slog.New(handler) + logger.Debug("hi there") + if len(out.String()) == 0 { + t.Error("expected non-empty debug log output from default JSON Handler") + } + + out.Reset() + handler = JSONHandlerWithLevel(out, slog.LevelInfo) + logger = slog.New(handler) + logger.Debug("hi there") + if len(out.String()) != 0 { + t.Errorf("expected empty debug log output, but got: %v", out.String()) + } +} + func BenchmarkTraceLogging(b *testing.B) { SetDefault(NewLogger(NewTerminalHandler(os.Stderr, true))) b.ResetTimer() @@ -78,7 +97,7 @@ func benchmarkLogger(b *testing.B, l Logger) { tt = time.Now() bigint = big.NewInt(100) nilbig *big.Int - err = errors.New("Oh nooes it's crap") + err = errors.New("oh nooes it's crap") ) b.ReportAllocs() b.ResetTimer() @@ -107,7 +126,7 @@ func TestLoggerOutput(t *testing.T) { tt = time.Time{} bigint = big.NewInt(100) nilbig *big.Int - err = errors.New("Oh nooes it's crap") + err = errors.New("oh nooes it's crap") smallUint = uint256.NewInt(500_000) bigUint = &uint256.Int{0xff, 0xff, 0xff, 0xff} ) @@ -131,7 +150,7 @@ func TestLoggerOutput(t *testing.T) { have := out.String() t.Logf("output %v", out.String()) - want := `INFO [11-07|19:14:33.821] This is a message foo=123 bytes="[0 0 0 0 0 0 0 0 0 0]" bonk="a string with text" time=0001-01-01T00:00:00+0000 bigint=100 nilbig= err="Oh nooes it's crap" struct="{A:Foo B:12}" struct="{A:Foo\nLinebreak B:122}" ptrstruct="&{A:Foo B:12}" smalluint=500,000 bigUint=1,600,660,942,523,603,594,864,898,306,482,794,244,293,965,082,972,225,630,372,095 + want := `INFO [11-07|19:14:33.821] This is a message foo=123 bytes="[0 0 0 0 0 0 0 0 0 0]" bonk="a string with text" time=0001-01-01T00:00:00+0000 bigint=100 nilbig= err="oh nooes it's crap" struct="{A:Foo B:12}" struct="{A:Foo\nLinebreak B:122}" ptrstruct="&{A:Foo B:12}" smalluint=500,000 bigUint=1,600,660,942,523,603,594,864,898,306,482,794,244,293,965,082,972,225,630,372,095 ` if !bytes.Equal([]byte(have)[25:], []byte(want)[25:]) { t.Errorf("Error\nhave: %q\nwant: %q", have, want)