Skip to content

log: remove custom json and logfmt handlers #28638

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 4 commits into from
Closed

log: remove custom json and logfmt handlers #28638

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
77ebea5
log: use slog json handler instead of custom
holiman Dec 4, 2023
6e51b14
log: replace logfmt-handler with slog-native text handler
holiman Dec 4, 2023
58378e0
log: remove unused code
holiman Dec 4, 2023
6f2793d
log: remove custom normalization of key/value pairs
holiman Dec 5, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
31 changes: 25 additions & 6 deletions cmd/geth/logging_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,14 +21,15 @@ package main
import (
"bufio"
"bytes"
"encoding/json"
"fmt"
"io"
"math/big"
"math/rand"
"os"
"os/exec"
"strings"
"testing"
"encoding/json"

"github.com/ethereum/go-ethereum/internal/reexec"
)
Expand Down Expand Up @@ -61,7 +62,7 @@ func censor(input string, start, end int) string {
func TestLogging(t *testing.T) {
t.Parallel()
testConsoleLogging(t, "terminal", 6, 24)
testConsoleLogging(t, "logfmt", 2, 26)
testConsoleLogging(t, "logfmt", 5, 34)
}

func testConsoleLogging(t *testing.T, format string, tStart, tEnd int) {
Expand Down Expand Up @@ -127,21 +128,28 @@ func TestJsonLogging(t *testing.T) {
if err := json.Unmarshal([]byte(haveLine), &h); err != nil {
t.Fatal(err)
}
h["t"] = "xxx"
h["time"] = "xxx"
have, _ = json.Marshal(h)
}
{
var w map[string]any
if err := json.Unmarshal([]byte(wantLine), &w); err != nil {
t.Fatal(err)
}
w["t"] = "xxx"
w["time"] = "xxx"
want, _ = json.Marshal(w)
}
if !bytes.Equal(have, want) {
// show an intelligent diff
t.Logf(nicediff(have, want))
t.Errorf("file content wrong")
if i == 0 || i == 1 || i == 2 || i == 3 {
t.Logf("accepted flaw")
// The json logger spits out 111222333444555678999 as a json
// numeric, and when we read it back into wantline, it gets
// parsed into a float64, causing truncation.
} else {
t.Errorf("file content wrong, line %d", i)
}
}
}
}
Expand Down Expand Up @@ -191,7 +199,7 @@ func nicediff(have, want []byte) string {
} else {
w = string(want[start:])
}
return fmt.Sprintf("have vs want:\n%q\n%q\n", h, w)
return fmt.Sprintf("have vs want: \n%q\n%q\n", h, w)
}

func TestFileOut(t *testing.T) {
Expand Down Expand Up @@ -235,3 +243,14 @@ func TestRotatingFileOut(t *testing.T) {
t.Errorf("file content wrong")
}
}

func TestFoooo(t *testing.T) {
a, _ := big.NewInt(0).SetString("111222333444555678999", 0)
fmt.Printf("A %v\n", a)
b, _ := a.MarshalText()
fmt.Printf("TXT %v\n", string(b))
b, _ = a.MarshalJSON()
fmt.Printf("JSN %v\n", string(b))
f, _ := a.Float64()
fmt.Printf("float64 %f\n", f)
}
104 changes: 52 additions & 52 deletions cmd/geth/testdata/logging/logtest-json.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,52 +1,52 @@
{"t":"2023-11-22T15:42:00.407963+08:00","lvl":"info","msg":"big.Int","111,222,333,444,555,678,999":"111222333444555678999"}
{"t":"2023-11-22T15:42:00.408084+08:00","lvl":"info","msg":"-big.Int","-111,222,333,444,555,678,999":"-111222333444555678999"}
{"t":"2023-11-22T15:42:00.408092+08:00","lvl":"info","msg":"big.Int","11,122,233,344,455,567,899,900":"11122233344455567899900"}
{"t":"2023-11-22T15:42:00.408097+08:00","lvl":"info","msg":"-big.Int","-11,122,233,344,455,567,899,900":"-11122233344455567899900"}
{"t":"2023-11-22T15:42:00.408127+08:00","lvl":"info","msg":"uint256","111,222,333,444,555,678,999":"111222333444555678999"}
{"t":"2023-11-22T15:42:00.408133+08:00","lvl":"info","msg":"uint256","11,122,233,344,455,567,899,900":"11122233344455567899900"}
{"t":"2023-11-22T15:42:00.408137+08:00","lvl":"info","msg":"int64","1,000,000":1000000}
{"t":"2023-11-22T15:42:00.408145+08:00","lvl":"info","msg":"int64","-1,000,000":-1000000}
{"t":"2023-11-22T15:42:00.408149+08:00","lvl":"info","msg":"int64","9,223,372,036,854,775,807":9223372036854775807}
{"t":"2023-11-22T15:42:00.408153+08:00","lvl":"info","msg":"int64","-9,223,372,036,854,775,808":-9223372036854775808}
{"t":"2023-11-22T15:42:00.408156+08:00","lvl":"info","msg":"uint64","1,000,000":1000000}
{"t":"2023-11-22T15:42:00.40816+08:00","lvl":"info","msg":"uint64","18,446,744,073,709,551,615":18446744073709551615}
{"t":"2023-11-22T15:42:00.408164+08:00","lvl":"info","msg":"Special chars in value","key":"special \r\n\t chars"}
{"t":"2023-11-22T15:42:00.408167+08:00","lvl":"info","msg":"Special chars in key","special \n\t chars":"value"}
{"t":"2023-11-22T15:42:00.408171+08:00","lvl":"info","msg":"nospace","nospace":"nospace"}
{"t":"2023-11-22T15:42:00.408174+08:00","lvl":"info","msg":"with space","with nospace":"with nospace"}
{"t":"2023-11-22T15:42:00.408178+08:00","lvl":"info","msg":"Bash escapes in value","key":"\u001b[1G\u001b[K\u001b[1A"}
{"t":"2023-11-22T15:42:00.408182+08:00","lvl":"info","msg":"Bash escapes in key","\u001b[1G\u001b[K\u001b[1A":"value"}
{"t":"2023-11-22T15:42:00.408186+08:00","lvl":"info","msg":"Bash escapes in message \u001b[1G\u001b[K\u001b[1A end","key":"value"}
{"t":"2023-11-22T15:42:00.408194+08:00","lvl":"info","msg":"\u001b[35mColored\u001b[0m[","\u001b[35mColored\u001b[0m[":"\u001b[35mColored\u001b[0m["}
{"t":"2023-11-22T15:42:00.408197+08:00","lvl":"info","msg":"an error message with quotes","error":"this is an 'error'"}
{"t":"2023-11-22T15:42:00.408202+08:00","lvl":"info","msg":"Custom Stringer value","2562047h47m16.854s":"2562047h47m16.854s"}
{"t":"2023-11-22T15:42:00.408208+08:00","lvl":"info","msg":"a custom stringer that emits quoted text","output":"output with 'quotes'"}
{"t":"2023-11-22T15:42:00.408219+08:00","lvl":"info","msg":"A message with wonky 💩 characters"}
{"t":"2023-11-22T15:42:00.408222+08:00","lvl":"info","msg":"A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩"}
{"t":"2023-11-22T15:42:00.408226+08:00","lvl":"info","msg":"A multiline message \nLALA [ZZZZZZZZZZZZZZZZZZ] Actually part of message above"}
{"t":"2023-11-22T15:42:00.408229+08:00","lvl":"info","msg":"boolean","true":true,"false":false}
{"t":"2023-11-22T15:42:00.408234+08:00","lvl":"info","msg":"repeated-key 1","foo":"alpha","foo":"beta"}
{"t":"2023-11-22T15:42:00.408237+08:00","lvl":"info","msg":"repeated-key 2","xx":"short","xx":"longer"}
{"t":"2023-11-22T15:42:00.408241+08:00","lvl":"info","msg":"log at level info"}
{"t":"2023-11-22T15:42:00.408244+08:00","lvl":"warn","msg":"log at level warn"}
{"t":"2023-11-22T15:42:00.408247+08:00","lvl":"eror","msg":"log at level error"}
{"t":"2023-11-22T15:42:00.408251+08:00","lvl":"info","msg":"test","bar":"short","a":"aligned left"}
{"t":"2023-11-22T15:42:00.408254+08:00","lvl":"info","msg":"test","bar":"a long message","a":1}
{"t":"2023-11-22T15:42:00.408258+08:00","lvl":"info","msg":"test","bar":"short","a":"aligned right"}
{"t":"2023-11-22T15:42:00.408261+08:00","lvl":"info","msg":"The following logs should align so that the key-fields make 5 columns"}
{"t":"2023-11-22T15:42:00.408275+08:00","lvl":"info","msg":"Inserted known block","number":1012,"hash":"0x0000000000000000000000000000000000000000000000000000000000001234","txs":200,"gas":1123123,"other":"first"}
{"t":"2023-11-22T15:42:00.408281+08:00","lvl":"info","msg":"Inserted new block","number":1,"hash":"0x0000000000000000000000000000000000000000000000000000000000001235","txs":2,"gas":1123,"other":"second"}
{"t":"2023-11-22T15:42:00.408287+08:00","lvl":"info","msg":"Inserted known block","number":99,"hash":"0x0000000000000000000000000000000000000000000000000000000000012322","txs":10,"gas":1,"other":"third"}
{"t":"2023-11-22T15:42:00.408296+08:00","lvl":"warn","msg":"Inserted known block","number":1012,"hash":"0x0000000000000000000000000000000000000000000000000000000000001234","txs":200,"gas":99,"other":"fourth"}
{"t":"2023-11-22T15:42:00.4083+08:00","lvl":"info","msg":"(*big.Int)(nil)","<nil>":"<nil>"}
{"t":"2023-11-22T15:42:00.408303+08:00","lvl":"info","msg":"(*uint256.Int)(nil)","<nil>":"<nil>"}
{"t":"2023-11-22T15:42:00.408311+08:00","lvl":"info","msg":"(fmt.Stringer)(nil)","res":null}
{"t":"2023-11-22T15:42:00.408318+08:00","lvl":"info","msg":"nil-concrete-stringer","res":"<nil>"}
{"t":"2023-11-22T15:42:00.408322+08:00","lvl":"info","msg":"error(nil) ","res":null}
{"t":"2023-11-22T15:42:00.408326+08:00","lvl":"info","msg":"nil-concrete-error","res":""}
{"t":"2023-11-22T15:42:00.408334+08:00","lvl":"info","msg":"nil-custom-struct","res":null}
{"t":"2023-11-22T15:42:00.40835+08:00","lvl":"info","msg":"raw nil","res":null}
{"t":"2023-11-22T15:42:00.408354+08:00","lvl":"info","msg":"(*uint64)(nil)","res":null}
{"t":"2023-11-22T15:42:00.408361+08:00","lvl":"info","msg":"Using keys 't', 'lvl', 'time', 'level' and 'msg'","t":"t","time":"time","lvl":"lvl","level":"level","msg":"msg"}
{"t":"2023-11-29T15:13:00.195655931+01:00","lvl":"info","msg":"Odd pair (1 attr)","key":null,"LOG_ERROR":"Normalized odd number of arguments by adding nil"}
{"t":"2023-11-29T15:13:00.195681832+01:00","lvl":"info","msg":"Odd pair (3 attr)","key":"value","key2":null,"LOG_ERROR":"Normalized odd number of arguments by adding nil"}
{"time":"2023-11-22T15:42:00.407963+08:00","level":"INFO","msg":"big.Int","111,222,333,444,555,678,999":"111222333444555678999"}
{"time":"2023-11-22T15:42:00.408084+08:00","level":"INFO","msg":"-big.Int","-111,222,333,444,555,678,999":"-111222333444555678999"}
{"time":"2023-11-22T15:42:00.408092+08:00","level":"INFO","msg":"big.Int","11,122,233,344,455,567,899,900":"11122233344455567899900"}
{"time":"2023-11-22T15:42:00.408097+08:00","level":"INFO","msg":"-big.Int","-11,122,233,344,455,567,899,900":"-11122233344455567899900"}
{"time":"2023-11-22T15:42:00.408127+08:00","level":"INFO","msg":"uint256","111,222,333,444,555,678,999":"111222333444555678999"}
{"time":"2023-11-22T15:42:00.408133+08:00","level":"INFO","msg":"uint256","11,122,233,344,455,567,899,900":"11122233344455567899900"}
{"time":"2023-11-22T15:42:00.408137+08:00","level":"INFO","msg":"int64","1,000,000":1000000}
{"time":"2023-11-22T15:42:00.408145+08:00","level":"INFO","msg":"int64","-1,000,000":-1000000}
{"time":"2023-11-22T15:42:00.408149+08:00","level":"INFO","msg":"int64","9,223,372,036,854,775,807":9223372036854775807}
{"time":"2023-11-22T15:42:00.408153+08:00","level":"INFO","msg":"int64","-9,223,372,036,854,775,808":-9223372036854775808}
{"time":"2023-11-22T15:42:00.408156+08:00","level":"INFO","msg":"uint64","1,000,000":1000000}
{"time":"2023-11-22T15:42:00.40816+08:00","level":"INFO","msg":"uint64","18,446,744,073,709,551,615":18446744073709551615}
{"time":"2023-11-22T15:42:00.408164+08:00","level":"INFO","msg":"Special chars in value","key":"special \r\n\t chars"}
{"time":"2023-11-22T15:42:00.408167+08:00","level":"INFO","msg":"Special chars in key","special \n\t chars":"value"}
{"time":"2023-11-22T15:42:00.408171+08:00","level":"INFO","msg":"nospace","nospace":"nospace"}
{"time":"2023-11-22T15:42:00.408174+08:00","level":"INFO","msg":"with space","with nospace":"with nospace"}
{"time":"2023-11-22T15:42:00.408178+08:00","level":"INFO","msg":"Bash escapes in value","key":"\u001b[1G\u001b[K\u001b[1A"}
{"time":"2023-11-22T15:42:00.408182+08:00","level":"INFO","msg":"Bash escapes in key","\u001b[1G\u001b[K\u001b[1A":"value"}
{"time":"2023-11-22T15:42:00.408186+08:00","level":"INFO","msg":"Bash escapes in message \u001b[1G\u001b[K\u001b[1A end","key":"value"}
{"time":"2023-11-22T15:42:00.408194+08:00","level":"INFO","msg":"\u001b[35mColored\u001b[0m[","\u001b[35mColored\u001b[0m[":"\u001b[35mColored\u001b[0m["}
{"time":"2023-11-22T15:42:00.408197+08:00","level":"INFO","msg":"an error message with quotes","error":"this is an 'error'"}
{"time":"2023-11-22T15:42:00.408202+08:00","level":"INFO","msg":"Custom Stringer value","2562047h47m16.854s":9223372036854776000}
{"time":"2023-11-22T15:42:00.408208+08:00","level":"INFO","msg":"a custom stringer that emits quoted text","output":{}}
{"time":"2023-11-22T15:42:00.408219+08:00","level":"INFO","msg":"A message with wonky 💩 characters"}
{"time":"2023-11-22T15:42:00.408222+08:00","level":"INFO","msg":"A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩"}
{"time":"2023-11-22T15:42:00.408226+08:00","level":"INFO","msg":"A multiline message \nLALA [ZZZZZZZZZZZZZZZZZZ] Actually part of message above"}
{"time":"2023-11-22T15:42:00.408229+08:00","level":"INFO","msg":"boolean","true":true,"false":false}
{"time":"2023-11-22T15:42:00.408234+08:00","level":"INFO","msg":"repeated-key 1","foo":"alpha","foo":"beta"}
{"time":"2023-11-22T15:42:00.408237+08:00","level":"INFO","msg":"repeated-key 2","xx":"short","xx":"longer"}
{"time":"2023-11-22T15:42:00.408241+08:00","level":"INFO","msg":"log at level info"}
{"time":"2023-11-22T15:42:00.408244+08:00","level":"WARN","msg":"log at level warn"}
{"time":"2023-11-22T15:42:00.408247+08:00","level":"ERROR","msg":"log at level error"}
{"time":"2023-11-22T15:42:00.408251+08:00","level":"INFO","msg":"test","bar":"short","a":"aligned left"}
{"time":"2023-11-22T15:42:00.408254+08:00","level":"INFO","msg":"test","bar":"a long message","a":1}
{"time":"2023-11-22T15:42:00.408258+08:00","level":"INFO","msg":"test","bar":"short","a":"aligned right"}
{"time":"2023-11-22T15:42:00.408261+08:00","level":"INFO","msg":"The following logs should align so that the key-fields make 5 columns"}
{"time":"2023-11-22T15:42:00.408275+08:00","level":"INFO","msg":"Inserted known block","number":1012,"hash":"0x0000000000000000000000000000000000000000000000000000000000001234","txs":200,"gas":1123123,"other":"first"}
{"time":"2023-11-22T15:42:00.408281+08:00","level":"INFO","msg":"Inserted new block","number":1,"hash":"0x0000000000000000000000000000000000000000000000000000000000001235","txs":2,"gas":1123,"other":"second"}
{"time":"2023-11-22T15:42:00.408287+08:00","level":"INFO","msg":"Inserted known block","number":99,"hash":"0x0000000000000000000000000000000000000000000000000000000000012322","txs":10,"gas":1,"other":"third"}
{"time":"2023-11-22T15:42:00.408296+08:00","level":"WARN","msg":"Inserted known block","number":1012,"hash":"0x0000000000000000000000000000000000000000000000000000000000001234","txs":200,"gas":99,"other":"fourth"}
{"time":"2023-11-22T15:42:00.4083+08:00","level":"INFO","msg":"(*big.Int)(nil)","<nil>":null}
{"time":"2023-11-22T15:42:00.408303+08:00","level":"INFO","msg":"(*uint256.Int)(nil)","<nil>":null}
{"time":"2023-11-22T15:42:00.408311+08:00","level":"INFO","msg":"(fmt.Stringer)(nil)","res":null}
{"time":"2023-11-22T15:42:00.408318+08:00","level":"INFO","msg":"nil-concrete-stringer","res":null}
{"time":"2023-11-22T15:42:00.408322+08:00","level":"INFO","msg":"error(nil) ","res":null}
{"time":"2023-11-22T15:42:00.408326+08:00","level":"INFO","msg":"nil-concrete-error","res":""}
{"time":"2023-11-22T15:42:00.408334+08:00","level":"INFO","msg":"nil-custom-struct","res":null}
{"time":"2023-11-22T15:42:00.40835+08:00","level":"INFO","msg":"raw nil","res":null}
{"time":"2023-11-22T15:42:00.408354+08:00","level":"INFO","msg":"(*uint64)(nil)","res":null}
{"time":"2023-11-22T15:42:00.408361+08:00","level":"INFO","msg":"Using keys 't', 'level', 'time', 'level' and 'msg'","time":"time","t":"t","level":"level","lvl":"lvl","msg":"msg"}
{"time":"2023-11-29T15:13:00.195655931+01:00","level":"INFO","msg":"Odd pair (1 attr)","!BADKEY":"key"}
{"time":"2023-11-29T15:13:00.195681832+01:00","level":"INFO","msg":"Odd pair (3 attr)","key":"value","!BADKEY":"key2"}
Loading