cmd/geth: more special cases logging tests (#28527)

adds logging tests for errors and custom fmt.Stringer-types which output strings that needs to be quoted/escaped.

Author: jwasinger

cmd/geth/logtestcmd_active.go

@@ -19,6 +19,7 @@
 package main
 
 import (
+	"errors"
 	"fmt"
 	"math"
 	"math/big"
@@ -39,6 +40,12 @@ var logTestCommand = &cli.Command{
 This command is only meant for testing.
 `}
 
+type customQuotedStringer struct {
+}
+func (c customQuotedStringer) String() string {
+	return "output with 'quotes'"
+}
+
 // logTest is an entry point which spits out some logs. This is used by testing
 // to verify expected outputs
 func logTest(ctx *cli.Context) error {
@@ -70,6 +77,8 @@ func logTest(ctx *cli.Context) error {
 		log.Info("uint64", "18,446,744,073,709,551,615", uint64(math.MaxUint64))
 	}
 	{ // Special characters
+
+
 		log.Info("Special chars in value", "key", "special \r\n\t chars")
 		log.Info("Special chars in key", "special \n\t chars", "value")
 
@@ -83,9 +92,13 @@ func logTest(ctx *cli.Context) error {
 
 		colored := fmt.Sprintf("\u001B[%dmColored\u001B[0m[", 35)
 		log.Info(colored, colored, colored)
+		err := errors.New("this is an 'error'")
+		log.Info("an error message with quotes", "error", err)
 	}
 	{ // Custom Stringer() - type
 		log.Info("Custom Stringer value", "2562047h47m16.854s", common.PrettyDuration(time.Duration(9223372036854775807)))
+		var c customQuotedStringer
+		log.Info("a custom stringer that emits quoted text", "output", c)
 	}
 	{ // Lazy eval
 		log.Info("Lazy evaluation of value", "key", log.Lazy{Fn: func() interface{} { return "lazy value" }})

cmd/geth/testdata/logging/logtest-logfmt.txt

@@ -18,8 +18,10 @@ t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="Bash escapes in value"  key="\x1b[1G\x1
 t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="Bash escapes in key"    "\x1b[1G\x1b[K\x1b[1A"=value
 t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="Bash escapes in message  \x1b[1G\x1b[K\x1b[1A end" key=value
 t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="\x1b[35mColored\x1b[0m[" "\x1b[35mColored\x1b[0m["="\x1b[35mColored\x1b[0m["
-t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="Custom Stringer value"   2562047h47m16.854s=2562047h47m16.854s
-t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="Lazy evaluation of value" key="lazy value"
+t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="an error message with quotes" error="this is an 'error'"
+t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="Custom Stringer value"        2562047h47m16.854s=2562047h47m16.854s
+t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="a custom stringer that emits quoted text" output="output with 'quotes'"
+t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="Lazy evaluation of value"     key="lazy value"
 t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="A message with wonky 💩 characters"
 t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩"
 t=xxxxxxxxxxxxxxxxxxxxxxxx lvl=info msg="A multiline message \nLALA [ZZZZZZZZZZZZZZZZZZ] Actually part of message above"

cmd/geth/testdata/logging/logtest-terminal.txt

@@ -18,22 +18,24 @@ INFO [XX-XX|XX:XX:XX.XXX] Bash escapes in value                    key="\x1b[1G\
 INFO [XX-XX|XX:XX:XX.XXX] Bash escapes in key                      "\x1b[1G\x1b[K\x1b[1A"=value
 INFO [XX-XX|XX:XX:XX.XXX] "Bash escapes in message  \x1b[1G\x1b[K\x1b[1A end" key=value
 INFO [XX-XX|XX:XX:XX.XXX] "\x1b[35mColored\x1b[0m["                "\x1b[35mColored\x1b[0m["="\x1b[35mColored\x1b[0m["
+INFO [XX-XX|XX:XX:XX.XXX] an error message with quotes             error="this is an 'error'"
 INFO [XX-XX|XX:XX:XX.XXX] Custom Stringer value                    2562047h47m16.854s=2562047h47m16.854s
+INFO [XX-XX|XX:XX:XX.XXX] a custom stringer that emits quoted text output="output with 'quotes'"
 INFO [XX-XX|XX:XX:XX.XXX] Lazy evaluation of value                 key="lazy value"
-INFO [XX-XX|XX:XX:XX.XXX] "A message with wonky 💩 characters"
-INFO [XX-XX|XX:XX:XX.XXX] "A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩"
-INFO [XX-XX|XX:XX:XX.XXX] A multiline message
-LALA [XXZXXZXXZXXZXXZXXX] Actually part of message above
+INFO [XX-XX|XX:XX:XX.XXX] "A message with wonky 💩 characters" 
+INFO [XX-XX|XX:XX:XX.XXX] "A multiline message \nINFO [10-18|14:11:31.106] with wonky characters 💩" 
+INFO [XX-XX|XX:XX:XX.XXX] A multiline message 
+LALA [ZZZZZZZZZZZZZZZZZZ] Actually part of message above 
 INFO [XX-XX|XX:XX:XX.XXX] boolean                                  true=true false=false
 INFO [XX-XX|XX:XX:XX.XXX] repeated-key 1                           foo=alpha foo=beta
 INFO [XX-XX|XX:XX:XX.XXX] repeated-key 2                           xx=short xx=longer
-INFO [XX-XX|XX:XX:XX.XXX] log at level info
-WARN [XX-XX|XX:XX:XX.XXX] log at level warn
-ERROR[XX-XX|XX:XX:XX.XXX] log at level error
+INFO [XX-XX|XX:XX:XX.XXX] log at level info 
+WARN [XX-XX|XX:XX:XX.XXX] log at level warn 
+ERROR[XX-XX|XX:XX:XX.XXX] log at level error 
 INFO [XX-XX|XX:XX:XX.XXX] test                                     bar=short a="aligned left"
 INFO [XX-XX|XX:XX:XX.XXX] test                                     bar="a long message" a=1
 INFO [XX-XX|XX:XX:XX.XXX] test                                     bar=short            a="aligned right"
-INFO [XX-XX|XX:XX:XX.XXX] The following logs should align so that the key-fields make 5 columns
+INFO [XX-XX|XX:XX:XX.XXX] The following logs should align so that the key-fields make 5 columns 
 INFO [XX-XX|XX:XX:XX.XXX] Inserted known block                     number=1012 hash=000000..001234 txs=200 gas=1,123,123 other=first
 INFO [XX-XX|XX:XX:XX.XXX] Inserted new block                       number=1    hash=000000..001235 txs=2   gas=1123      other=second
 INFO [XX-XX|XX:XX:XX.XXX] Inserted known block                     number=99   hash=000000..012322 txs=10  gas=1         other=third