cmd/geth: add testcase showing double-use of log formatter

This commit is contained in:
Martin Holst Swende 2023-10-20 08:31:30 +02:00
parent 6263e17f57
commit 1b2e43e5ba
No known key found for this signature in database
GPG key ID: 683B438C05A5DDF0
4 changed files with 90 additions and 67 deletions

View file

@ -161,3 +161,23 @@ func TestFileOut(t *testing.T) {
t.Errorf("file content wrong") t.Errorf("file content wrong")
} }
} }
func TestRotatingFileOut(t *testing.T) {
var (
have, want []byte
err error
path = fmt.Sprintf("%s/test_file_out-%d", os.TempDir(), rand.Int63())
)
t.Cleanup(func() { os.Remove(path) })
if want, err = runSelf(fmt.Sprintf("--log.file=%s", path), "--log.rotate", "logtest"); err != nil {
t.Fatal(err)
}
if have, err = os.ReadFile(path); err != nil {
t.Fatal(err)
}
if !bytes.Equal(have, want) {
// show an intelligent diff
t.Logf(nicediff(have, want))
t.Errorf("file content wrong")
}
}

View file

@ -92,7 +92,8 @@ func logTest(ctx *cli.Context) error {
// is shorter than beta, it sometimes causes erroneous padding -- and what's more // is shorter than beta, it sometimes causes erroneous padding -- and what's more
// it causes _different_ padding in multi-handler context, e.g. both file- // it causes _different_ padding in multi-handler context, e.g. both file-
// and console output, making the two mismatch. // and console output, making the two mismatch.
log.Info("repeated-key", "foo", "alpha", "foo", "beta") log.Info("repeated-key 1", "foo", "alpha", "foo", "beta")
log.Info("repeated-key 2", "xx", "short", "xx", "longer")
} }
{ // loglevels { // loglevels
log.Debug("log at level debug") log.Debug("log at level debug")

View file

@ -1,33 +1,34 @@
t=2023-10-20T08:16:02+0200 lvl=info msg=big.Int 111,222,333,444,555,678,999=111,222,333,444,555,678,999 t=2023-10-20T08:30:18+0200 lvl=info msg=big.Int 111,222,333,444,555,678,999=111,222,333,444,555,678,999
t=2023-10-20T08:16:02+0200 lvl=info msg=-big.Int -111,222,333,444,555,678,999=-111,222,333,444,555,678,999 t=2023-10-20T08:30:18+0200 lvl=info msg=-big.Int -111,222,333,444,555,678,999=-111,222,333,444,555,678,999
t=2023-10-20T08:16:02+0200 lvl=info msg=big.Int 11,122,233,344,455,567,899,900=11,122,233,344,455,567,899,900 t=2023-10-20T08:30:18+0200 lvl=info msg=big.Int 11,122,233,344,455,567,899,900=11,122,233,344,455,567,899,900
t=2023-10-20T08:16:02+0200 lvl=info msg=-big.Int -11,122,233,344,455,567,899,900=-11,122,233,344,455,567,899,900 t=2023-10-20T08:30:18+0200 lvl=info msg=-big.Int -11,122,233,344,455,567,899,900=-11,122,233,344,455,567,899,900
t=2023-10-20T08:16:02+0200 lvl=info msg=uint256 111,222,333,444,555,678,999=111,222,333,444,555,678,999 t=2023-10-20T08:30:18+0200 lvl=info msg=uint256 111,222,333,444,555,678,999=111,222,333,444,555,678,999
t=2023-10-20T08:16:02+0200 lvl=info msg=uint256 11,122,233,344,455,567,899,900=11,122,233,344,455,567,899,900 t=2023-10-20T08:30:18+0200 lvl=info msg=uint256 11,122,233,344,455,567,899,900=11,122,233,344,455,567,899,900
t=2023-10-20T08:16:02+0200 lvl=info msg=int64 1,000,000=1,000,000 t=2023-10-20T08:30:18+0200 lvl=info msg=int64 1,000,000=1,000,000
t=2023-10-20T08:16:02+0200 lvl=info msg=int64 -1,000,000=-1,000,000 t=2023-10-20T08:30:18+0200 lvl=info msg=int64 -1,000,000=-1,000,000
t=2023-10-20T08:16:02+0200 lvl=info msg=int64 9,223,372,036,854,775,807=9,223,372,036,854,775,807 t=2023-10-20T08:30:18+0200 lvl=info msg=int64 9,223,372,036,854,775,807=9,223,372,036,854,775,807
t=2023-10-20T08:16:02+0200 lvl=info msg=int64 -9,223,372,036,854,775,808=-9,223,372,036,854,775,808 t=2023-10-20T08:30:18+0200 lvl=info msg=int64 -9,223,372,036,854,775,808=-9,223,372,036,854,775,808
t=2023-10-20T08:16:02+0200 lvl=info msg=uint64 1,000,000=1,000,000 t=2023-10-20T08:30:18+0200 lvl=info msg=uint64 1,000,000=1,000,000
t=2023-10-20T08:16:02+0200 lvl=info msg=uint64 18,446,744,073,709,551,615=18,446,744,073,709,551,615 t=2023-10-20T08:30:18+0200 lvl=info msg=uint64 18,446,744,073,709,551,615=18,446,744,073,709,551,615
t=2023-10-20T08:16:02+0200 lvl=info msg="Special chars in value" key="special \r\n\t chars" t=2023-10-20T08:30:18+0200 lvl=info msg="Special chars in value" key="special \r\n\t chars"
t=2023-10-20T08:16:02+0200 lvl=info msg="Special chars in key" "special \n\t chars"=value t=2023-10-20T08:30:18+0200 lvl=info msg="Special chars in key" "special \n\t chars"=value
t=2023-10-20T08:16:02+0200 lvl=info msg=nospace nospace=nospace t=2023-10-20T08:30:18+0200 lvl=info msg=nospace nospace=nospace
t=2023-10-20T08:16:02+0200 lvl=info msg="with space" "with nospace"="with nospace" t=2023-10-20T08:30:18+0200 lvl=info msg="with space" "with nospace"="with nospace"
t=2023-10-20T08:16:02+0200 lvl=info msg="Bash escapes in value" key="\x1b[1G\x1b[K\x1b[1A" t=2023-10-20T08:30:18+0200 lvl=info msg="Bash escapes in value" key="\x1b[1G\x1b[K\x1b[1A"
t=2023-10-20T08:16:02+0200 lvl=info msg="Bash escapes in key" "\x1b[1G\x1b[K\x1b[1A"=value t=2023-10-20T08:30:18+0200 lvl=info msg="Bash escapes in key" "\x1b[1G\x1b[K\x1b[1A"=value
t=2023-10-20T08:16:02+0200 lvl=info msg="Bash escapes in message \x1b[1G\x1b[K\x1b[1A end" key=value t=2023-10-20T08:30:18+0200 lvl=info msg="Bash escapes in message \x1b[1G\x1b[K\x1b[1A end" key=value
t=2023-10-20T08:16:02+0200 lvl=info msg="\x1b[35mColored\x1b[0m[" "\x1b[35mColored\x1b[0m["="\x1b[35mColored\x1b[0m[" t=2023-10-20T08:30:18+0200 lvl=info msg="\x1b[35mColored\x1b[0m[" "\x1b[35mColored\x1b[0m["="\x1b[35mColored\x1b[0m["
t=2023-10-20T08:16:02+0200 lvl=info msg="Custom Stringer value" 2562047h47m16.854s=2562047h47m16.854s t=2023-10-20T08:30:18+0200 lvl=info msg="Custom Stringer value" 2562047h47m16.854s=2562047h47m16.854s
t=2023-10-20T08:16:02+0200 lvl=info msg="Lazy evaluation of value" key="lazy value" t=2023-10-20T08:30:18+0200 lvl=info msg="Lazy evaluation of value" key="lazy value"
t=2023-10-20T08:16:02+0200 lvl=info msg="A message with wonky 💩 characters" t=2023-10-20T08:30:18+0200 lvl=info msg="A message with wonky 💩 characters"
t=2023-10-20T08:16:02+0200 lvl=info msg="A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩" t=2023-10-20T08:30:18+0200 lvl=info msg="A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩"
t=2023-10-20T08:16:02+0200 lvl=info msg="A multiline message \nLALA [ZZZZZZZZZZZZZZZZZZ] Actually part of message above" t=2023-10-20T08:30:18+0200 lvl=info msg="A multiline message \nLALA [ZZZZZZZZZZZZZZZZZZ] Actually part of message above"
t=2023-10-20T08:16:02+0200 lvl=info msg=boolean true=true false=false t=2023-10-20T08:30:18+0200 lvl=info msg=boolean true=true false=false
t=2023-10-20T08:16:02+0200 lvl=info msg=repeated-key foo=alpha foo=beta t=2023-10-20T08:30:18+0200 lvl=info msg="repeated-key 1" foo=alpha foo=beta
t=2023-10-20T08:16:02+0200 lvl=info msg="log at level info" t=2023-10-20T08:30:18+0200 lvl=info msg="repeated-key 2" xx=short xx=longer
t=2023-10-20T08:16:02+0200 lvl=warn msg="log at level warn" t=2023-10-20T08:30:18+0200 lvl=info msg="log at level info"
t=2023-10-20T08:16:02+0200 lvl=eror msg="log at level error" t=2023-10-20T08:30:18+0200 lvl=warn msg="log at level warn"
t=2023-10-20T08:16:02+0200 lvl=info msg=test bar=short a="aligned left" t=2023-10-20T08:30:18+0200 lvl=eror msg="log at level error"
t=2023-10-20T08:16:02+0200 lvl=info msg=test bar="a long message" a=1 t=2023-10-20T08:30:18+0200 lvl=info msg=test bar=short a="aligned left"
t=2023-10-20T08:16:02+0200 lvl=info msg=test bar=short a="aligned right" t=2023-10-20T08:30:18+0200 lvl=info msg=test bar="a long message" a=1
t=2023-10-20T08:30:18+0200 lvl=info msg=test bar=short a="aligned right"

View file

@ -1,34 +1,35 @@
INFO [10-20|08:15:21.795] big.Int 111,222,333,444,555,678,999=111,222,333,444,555,678,999 INFO [10-20|08:30:28.192] big.Int 111,222,333,444,555,678,999=111,222,333,444,555,678,999
INFO [10-20|08:15:21.795] -big.Int -111,222,333,444,555,678,999=-111,222,333,444,555,678,999 INFO [10-20|08:30:28.192] -big.Int -111,222,333,444,555,678,999=-111,222,333,444,555,678,999
INFO [10-20|08:15:21.795] big.Int 11,122,233,344,455,567,899,900=11,122,233,344,455,567,899,900 INFO [10-20|08:30:28.192] big.Int 11,122,233,344,455,567,899,900=11,122,233,344,455,567,899,900
INFO [10-20|08:15:21.795] -big.Int -11,122,233,344,455,567,899,900=-11,122,233,344,455,567,899,900 INFO [10-20|08:30:28.192] -big.Int -11,122,233,344,455,567,899,900=-11,122,233,344,455,567,899,900
INFO [10-20|08:15:21.795] uint256 111,222,333,444,555,678,999=111,222,333,444,555,678,999 INFO [10-20|08:30:28.192] uint256 111,222,333,444,555,678,999=111,222,333,444,555,678,999
INFO [10-20|08:15:21.795] uint256 11,122,233,344,455,567,899,900=11,122,233,344,455,567,899,900 INFO [10-20|08:30:28.192] uint256 11,122,233,344,455,567,899,900=11,122,233,344,455,567,899,900
INFO [10-20|08:15:21.795] int64 1,000,000=1,000,000 INFO [10-20|08:30:28.192] int64 1,000,000=1,000,000
INFO [10-20|08:15:21.795] int64 -1,000,000=-1,000,000 INFO [10-20|08:30:28.192] int64 -1,000,000=-1,000,000
INFO [10-20|08:15:21.795] int64 9,223,372,036,854,775,807=9,223,372,036,854,775,807 INFO [10-20|08:30:28.192] int64 9,223,372,036,854,775,807=9,223,372,036,854,775,807
INFO [10-20|08:15:21.795] int64 -9,223,372,036,854,775,808=-9,223,372,036,854,775,808 INFO [10-20|08:30:28.192] int64 -9,223,372,036,854,775,808=-9,223,372,036,854,775,808
INFO [10-20|08:15:21.795] uint64 1,000,000=1,000,000 INFO [10-20|08:30:28.192] uint64 1,000,000=1,000,000
INFO [10-20|08:15:21.795] uint64 18,446,744,073,709,551,615=18,446,744,073,709,551,615 INFO [10-20|08:30:28.192] uint64 18,446,744,073,709,551,615=18,446,744,073,709,551,615
INFO [10-20|08:15:21.795] Special chars in value key="special \r\n\t chars" INFO [10-20|08:30:28.192] Special chars in value key="special \r\n\t chars"
INFO [10-20|08:15:21.795] Special chars in key "special \n\t chars"=value INFO [10-20|08:30:28.192] Special chars in key "special \n\t chars"=value
INFO [10-20|08:15:21.795] nospace nospace=nospace INFO [10-20|08:30:28.192] nospace nospace=nospace
INFO [10-20|08:15:21.795] with space "with nospace"="with nospace" INFO [10-20|08:30:28.192] with space "with nospace"="with nospace"
INFO [10-20|08:15:21.795] Bash escapes in value key="\x1b[1G\x1b[K\x1b[1A" INFO [10-20|08:30:28.192] Bash escapes in value key="\x1b[1G\x1b[K\x1b[1A"
INFO [10-20|08:15:21.795] Bash escapes in key "\x1b[1G\x1b[K\x1b[1A"=value INFO [10-20|08:30:28.192] Bash escapes in key "\x1b[1G\x1b[K\x1b[1A"=value
INFO [10-20|08:15:21.795] "Bash escapes in message \x1b[1G\x1b[K\x1b[1A end" key=value INFO [10-20|08:30:28.192] "Bash escapes in message \x1b[1G\x1b[K\x1b[1A end" key=value
INFO [10-20|08:15:21.795] "\x1b[35mColored\x1b[0m[" "\x1b[35mColored\x1b[0m["="\x1b[35mColored\x1b[0m[" INFO [10-20|08:30:28.192] "\x1b[35mColored\x1b[0m[" "\x1b[35mColored\x1b[0m["="\x1b[35mColored\x1b[0m["
INFO [10-20|08:15:21.795] Custom Stringer value 2562047h47m16.854s=2562047h47m16.854s INFO [10-20|08:30:28.192] Custom Stringer value 2562047h47m16.854s=2562047h47m16.854s
INFO [10-20|08:15:21.795] Lazy evaluation of value key="lazy value" INFO [10-20|08:30:28.192] Lazy evaluation of value key="lazy value"
INFO [10-20|08:15:21.795] "A message with wonky 💩 characters" INFO [10-20|08:30:28.192] "A message with wonky 💩 characters"
INFO [10-20|08:15:21.795] "A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩" INFO [10-20|08:30:28.192] "A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩"
INFO [10-20|08:15:21.795] A multiline message INFO [10-20|08:30:28.192] A multiline message
LALA [ZZZZZZZZZZZZZZZZZZ] Actually part of message above LALA [ZZZZZZZZZZZZZZZZZZ] Actually part of message above
INFO [10-20|08:15:21.795] boolean true=true false=false INFO [10-20|08:30:28.192] boolean true=true false=false
INFO [10-20|08:15:21.795] repeated-key foo=alpha foo=beta INFO [10-20|08:30:28.192] repeated-key 1 foo=alpha foo=beta
INFO [10-20|08:15:21.795] log at level info INFO [10-20|08:30:28.192] repeated-key 2 xx=short xx=longer
WARN [10-20|08:15:21.795] log at level warn INFO [10-20|08:30:28.192] log at level info
ERROR[10-20|08:15:21.795] log at level error WARN [10-20|08:30:28.192] log at level warn
INFO [10-20|08:15:21.795] test bar=short a="aligned left" ERROR[10-20|08:30:28.192] log at level error
INFO [10-20|08:15:21.795] test bar="a long message" a=1 INFO [10-20|08:30:28.192] test bar=short a="aligned left"
INFO [10-20|08:15:21.795] test bar=short a="aligned right" INFO [10-20|08:30:28.192] test bar="a long message" a=1
INFO [10-20|08:30:28.192] test bar=short a="aligned right"