log: default JSON log handler should log all verbosity levels (ethereum#29471)

Co-authored-by: lightclient <[email protected]>

Author: gzliudan

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":

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},
 	})
 }
 

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,14 +42,33 @@ 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 {
 		t.Errorf("\nhave: %q\nwant: %q\n", have, want)
 	}
 }
 
+// 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=<nil> 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=<nil> 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)