Skip to content

Commit 7a36833

Browse files
karalabeatif-konasl
authored andcommitted
all: make logs a bit easier on the eye to digest (ethereum#22665)
* all: add thousandths separators for big numbers on log messages * p2p/sentry: drop accidental file * common, log: add fast number formatter * common, eth/protocols/snap: simplifty fancy num types * log: handle nil big ints
1 parent 101d460 commit 7a36833

File tree

11 files changed

+202
-27
lines changed

11 files changed

+202
-27
lines changed

accounts/url.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,7 @@ func (u URL) String() string {
6464
func (u URL) TerminalString() string {
6565
url := u.String()
6666
if len(url) > 32 {
67-
return url[:31] + ""
67+
return url[:31] + ".."
6868
}
6969
return url
7070
}

cmd/evm/README.md

+3-3
Original file line numberDiff line numberDiff line change
@@ -256,9 +256,9 @@ Error code: 4
256256
Another thing that can be done, is to chain invocations:
257257
```
258258
./evm t8n --input.alloc=./testdata/1/alloc.json --input.txs=./testdata/1/txs.json --input.env=./testdata/1/env.json --output.alloc=stdout | ./evm t8n --input.alloc=stdin --input.env=./testdata/1/env.json --input.txs=./testdata/1/txs.json
259-
INFO [01-21|22:41:22.963] rejected tx index=1 hash="0557ba18d673" from=0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192 error="nonce too low: address 0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192, tx: 0 state: 1"
260-
INFO [01-21|22:41:22.966] rejected tx index=0 hash="0557ba18d673" from=0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192 error="nonce too low: address 0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192, tx: 0 state: 1"
261-
INFO [01-21|22:41:22.967] rejected tx index=1 hash="0557ba18d673" from=0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192 error="nonce too low: address 0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192, tx: 0 state: 1"
259+
INFO [01-21|22:41:22.963] rejected tx index=1 hash=0557ba..18d673 from=0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192 error="nonce too low: address 0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192, tx: 0 state: 1"
260+
INFO [01-21|22:41:22.966] rejected tx index=0 hash=0557ba..18d673 from=0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192 error="nonce too low: address 0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192, tx: 0 state: 1"
261+
INFO [01-21|22:41:22.967] rejected tx index=1 hash=0557ba..18d673 from=0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192 error="nonce too low: address 0x8A8eAFb1cf62BfBeb1741769DAE1a9dd47996192, tx: 0 state: 1"
262262
263263
```
264264
What happened here, is that we first applied two identical transactions, so the second one was rejected.

cmd/evm/testdata/8/readme.md

+3-3
Original file line numberDiff line numberDiff line change
@@ -56,8 +56,8 @@ dir=./testdata/8 \
5656
If we try to execute it on older rules:
5757
```
5858
dir=./testdata/8 && ./evm t8n --state.fork=Istanbul --input.alloc=$dir/alloc.json --input.txs=$dir/txs.json --input.env=$dir/env.json
59-
INFO [01-21|23:21:51.265] rejected tx index=0 hash="d2818d6ab3da" error="tx type not supported"
60-
INFO [01-21|23:21:51.265] rejected tx index=1 hash="26ea0081c01b" from=0xa94f5374Fce5edBC8E2a8697C15331677e6EbF0B error="nonce too high: address 0xa94f5374Fce5edBC8E2a8697C15331677e6EbF0B, tx: 1 state: 0"
61-
INFO [01-21|23:21:51.265] rejected tx index=2 hash="698d01369cee" error="tx type not supported"
59+
INFO [01-21|23:21:51.265] rejected tx index=0 hash=d2818d..6ab3da error="tx type not supported"
60+
INFO [01-21|23:21:51.265] rejected tx index=1 hash=26ea00..81c01b from=0xa94f5374Fce5edBC8E2a8697C15331677e6EbF0B error="nonce too high: address 0xa94f5374Fce5edBC8E2a8697C15331677e6EbF0B, tx: 1 state: 0"
61+
INFO [01-21|23:21:51.265] rejected tx index=2 hash=698d01..369cee error="tx type not supported"
6262
```
6363
Number `1` and `3` are not applicable, and therefore number `2` has wrong nonce.

common/types.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -76,7 +76,7 @@ func (h Hash) Hex() string { return hexutil.Encode(h[:]) }
7676
// TerminalString implements log.TerminalStringer, formatting a string for console
7777
// output during logging.
7878
func (h Hash) TerminalString() string {
79-
return fmt.Sprintf("%x%x", h[:3], h[29:])
79+
return fmt.Sprintf("%x..%x", h[:3], h[29:])
8080
}
8181

8282
// String implements the stringer interface and is used also by the logger when

core/blockchain.go

+5-5
Original file line numberDiff line numberDiff line change
@@ -794,7 +794,7 @@ func (bc *BlockChain) FastSyncCommitHead(hash common.Hash) error {
794794
// Make sure that both the block as well at its state trie exists
795795
block := bc.GetBlockByHash(hash)
796796
if block == nil {
797-
return fmt.Errorf("non existent block [%x]", hash[:4])
797+
return fmt.Errorf("non existent block [%x..]", hash[:4])
798798
}
799799
if _, err := trie.NewSecure(block.Root(), bc.stateCache.TrieDB()); err != nil {
800800
return err
@@ -1311,7 +1311,7 @@ func (bc *BlockChain) InsertReceiptChain(blockChain types.Blocks, receiptChain [
13111311
if blockChain[i].NumberU64() != blockChain[i-1].NumberU64()+1 || blockChain[i].ParentHash() != blockChain[i-1].Hash() {
13121312
log.Error("Non contiguous receipt insert", "number", blockChain[i].Number(), "hash", blockChain[i].Hash(), "parent", blockChain[i].ParentHash(),
13131313
"prevnumber", blockChain[i-1].Number(), "prevhash", blockChain[i-1].Hash())
1314-
return 0, fmt.Errorf("non contiguous insert: item %d is #%d [%x], item %d is #%d [%x] (parent [%x])", i-1, blockChain[i-1].NumberU64(),
1314+
return 0, fmt.Errorf("non contiguous insert: item %d is #%d [%x..], item %d is #%d [%x..] (parent [%x..])", i-1, blockChain[i-1].NumberU64(),
13151315
blockChain[i-1].Hash().Bytes()[:4], i, blockChain[i].NumberU64(), blockChain[i].Hash().Bytes()[:4], blockChain[i].ParentHash().Bytes()[:4])
13161316
}
13171317
}
@@ -1376,7 +1376,7 @@ func (bc *BlockChain) InsertReceiptChain(blockChain types.Blocks, receiptChain [
13761376
}
13771377
// Short circuit if the owner header is unknown
13781378
if !bc.HasHeader(block.Hash(), block.NumberU64()) {
1379-
return i, fmt.Errorf("containing header #%d [%x] unknown", block.Number(), block.Hash().Bytes()[:4])
1379+
return i, fmt.Errorf("containing header #%d [%x..] unknown", block.Number(), block.Hash().Bytes()[:4])
13801380
}
13811381
var (
13821382
start = time.Now()
@@ -1520,7 +1520,7 @@ func (bc *BlockChain) InsertReceiptChain(blockChain types.Blocks, receiptChain [
15201520
}
15211521
// Short circuit if the owner header is unknown
15221522
if !bc.HasHeader(block.Hash(), block.NumberU64()) {
1523-
return i, fmt.Errorf("containing header #%d [%x] unknown", block.Number(), block.Hash().Bytes()[:4])
1523+
return i, fmt.Errorf("containing header #%d [%x..] unknown", block.Number(), block.Hash().Bytes()[:4])
15241524
}
15251525
if !skipPresenceCheck {
15261526
// Ignore if the entire data is already known
@@ -1902,7 +1902,7 @@ func (bc *BlockChain) InsertChain(chain types.Blocks) (int, error) {
19021902
log.Error("Non contiguous block insert", "number", block.Number(), "hash", block.Hash(),
19031903
"parent", block.ParentHash(), "prevnumber", prev.Number(), "prevhash", prev.Hash())
19041904

1905-
return 0, fmt.Errorf("non contiguous insert: item %d is #%d [%x], item %d is #%d [%x] (parent [%x])", i-1, prev.NumberU64(),
1905+
return 0, fmt.Errorf("non contiguous insert: item %d is #%d [%x..], item %d is #%d [%x..] (parent [%x..])", i-1, prev.NumberU64(),
19061906
prev.Hash().Bytes()[:4], i, block.NumberU64(), block.Hash().Bytes()[:4], block.ParentHash().Bytes()[:4])
19071907
}
19081908
}

core/blockchain_test.go

+2-2
Original file line numberDiff line numberDiff line change
@@ -1494,13 +1494,13 @@ func TestBlockchainHeaderchainReorgConsistency(t *testing.T) {
14941494
t.Fatalf("block %d: failed to insert into chain: %v", i, err)
14951495
}
14961496
if chain.CurrentBlock().Hash() != chain.CurrentHeader().Hash() {
1497-
t.Errorf("block %d: current block/header mismatch: block #%d [%x], header #%d [%x]", i, chain.CurrentBlock().Number(), chain.CurrentBlock().Hash().Bytes()[:4], chain.CurrentHeader().Number, chain.CurrentHeader().Hash().Bytes()[:4])
1497+
t.Errorf("block %d: current block/header mismatch: block #%d [%x..], header #%d [%x..]", i, chain.CurrentBlock().Number(), chain.CurrentBlock().Hash().Bytes()[:4], chain.CurrentHeader().Number, chain.CurrentHeader().Hash().Bytes()[:4])
14981498
}
14991499
if _, err := chain.InsertChain(forks[i : i+1]); err != nil {
15001500
t.Fatalf(" fork %d: failed to insert into chain: %v", i, err)
15011501
}
15021502
if chain.CurrentBlock().Hash() != chain.CurrentHeader().Hash() {
1503-
t.Errorf(" fork %d: current block/header mismatch: block #%d [%x], header #%d [%x]", i, chain.CurrentBlock().Number(), chain.CurrentBlock().Hash().Bytes()[:4], chain.CurrentHeader().Number, chain.CurrentHeader().Hash().Bytes()[:4])
1503+
t.Errorf(" fork %d: current block/header mismatch: block #%d [%x..], header #%d [%x..]", i, chain.CurrentBlock().Number(), chain.CurrentBlock().Hash().Bytes()[:4], chain.CurrentHeader().Number, chain.CurrentHeader().Hash().Bytes()[:4])
15041504
}
15051505
}
15061506
}

core/chain_indexer.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -401,7 +401,7 @@ func (c *ChainIndexer) processSection(section uint64, lastHead common.Hash) (com
401401
}
402402
header := rawdb.ReadHeader(c.chainDb, hash, number)
403403
if header == nil {
404-
return common.Hash{}, fmt.Errorf("block #%d [%x] not found", number, hash[:4])
404+
return common.Hash{}, fmt.Errorf("block #%d [%x..] not found", number, hash[:4])
405405
} else if header.ParentHash != lastHead {
406406
return common.Hash{}, fmt.Errorf("chain reorged during section processing")
407407
}

core/headerchain.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -306,7 +306,7 @@ func (hc *HeaderChain) ValidateHeaderChain(chain []*types.Header, checkFreq int)
306306
log.Error("Non contiguous header insert", "number", chain[i].Number, "hash", hash,
307307
"parent", chain[i].ParentHash, "prevnumber", chain[i-1].Number, "prevhash", parentHash)
308308

309-
return 0, fmt.Errorf("non contiguous insert: item %d is #%d [%x], item %d is #%d [%x] (parent [%x])", i-1, chain[i-1].Number,
309+
return 0, fmt.Errorf("non contiguous insert: item %d is #%d [%x..], item %d is #%d [%x..] (parent [%x..])", i-1, chain[i-1].Number,
310310
parentHash.Bytes()[:4], i, chain[i].Number, hash.Bytes()[:4], chain[i].ParentHash[:4])
311311
}
312312
// If the header is a banned one, straight out abort

eth/protocols/snap/sync.go

+7-7
Original file line numberDiff line numberDiff line change
@@ -2675,9 +2675,9 @@ func (s *Syncer) reportSyncProgress(force bool) {
26752675
// Create a mega progress report
26762676
var (
26772677
progress = fmt.Sprintf("%.2f%%", float64(synced)*100/estBytes)
2678-
accounts = fmt.Sprintf("%d@%v", s.accountSynced, s.accountBytes.TerminalString())
2679-
storage = fmt.Sprintf("%d@%v", s.storageSynced, s.storageBytes.TerminalString())
2680-
bytecode = fmt.Sprintf("%d@%v", s.bytecodeSynced, s.bytecodeBytes.TerminalString())
2678+
accounts = fmt.Sprintf("%v@%v", log.FormatLogfmtUint64(s.accountSynced), s.accountBytes.TerminalString())
2679+
storage = fmt.Sprintf("%v@%v", log.FormatLogfmtUint64(s.storageSynced), s.storageBytes.TerminalString())
2680+
bytecode = fmt.Sprintf("%v@%v", log.FormatLogfmtUint64(s.bytecodeSynced), s.bytecodeBytes.TerminalString())
26812681
)
26822682
log.Info("State sync in progress", "synced", progress, "state", synced,
26832683
"accounts", accounts, "slots", storage, "codes", bytecode, "eta", common.PrettyDuration(estTime-elapsed))
@@ -2693,10 +2693,10 @@ func (s *Syncer) reportHealProgress(force bool) {
26932693

26942694
// Create a mega progress report
26952695
var (
2696-
trienode = fmt.Sprintf("%d@%v", s.trienodeHealSynced, s.trienodeHealBytes.TerminalString())
2697-
bytecode = fmt.Sprintf("%d@%v", s.bytecodeHealSynced, s.bytecodeHealBytes.TerminalString())
2698-
accounts = fmt.Sprintf("%d@%v", s.accountHealed, s.accountHealedBytes.TerminalString())
2699-
storage = fmt.Sprintf("%d@%v", s.storageHealed, s.storageHealedBytes.TerminalString())
2696+
trienode = fmt.Sprintf("%v@%v", log.FormatLogfmtUint64(s.trienodeHealSynced), s.trienodeHealBytes.TerminalString())
2697+
bytecode = fmt.Sprintf("%v@%v", log.FormatLogfmtUint64(s.bytecodeHealSynced), s.bytecodeHealBytes.TerminalString())
2698+
accounts = fmt.Sprintf("%v@%v", log.FormatLogfmtUint64(s.accountHealed), s.accountHealedBytes.TerminalString())
2699+
storage = fmt.Sprintf("%v@%v", log.FormatLogfmtUint64(s.storageHealed), s.storageHealedBytes.TerminalString())
27002700
)
27012701
log.Info("State heal in progress", "accounts", accounts, "slots", storage,
27022702
"codes", bytecode, "nodes", trienode, "pending", s.healer.scheduler.Pending())

log/format.go

+103-3
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@ import (
44
"bytes"
55
"encoding/json"
66
"fmt"
7+
"math/big"
78
"reflect"
89
"strconv"
910
"strings"
@@ -329,11 +330,20 @@ func formatLogfmtValue(value interface{}, term bool) string {
329330
return "nil"
330331
}
331332

332-
if t, ok := value.(time.Time); ok {
333+
switch v := value.(type) {
334+
case time.Time:
333335
// Performance optimization: No need for escaping since the provided
334336
// timeFormat doesn't have any escape characters, and escaping is
335337
// expensive.
336-
return t.Format(timeFormat)
338+
return v.Format(timeFormat)
339+
340+
case *big.Int:
341+
// Big ints get consumed by the Stringer clause so we need to handle
342+
// them earlier on.
343+
if v == nil {
344+
return "<nil>"
345+
}
346+
return formatLogfmtBigInt(v)
337347
}
338348
if term {
339349
if s, ok := value.(TerminalStringer); ok {
@@ -349,15 +359,105 @@ func formatLogfmtValue(value interface{}, term bool) string {
349359
return strconv.FormatFloat(float64(v), floatFormat, 3, 64)
350360
case float64:
351361
return strconv.FormatFloat(v, floatFormat, 3, 64)
352-
case int, int8, int16, int32, int64, uint, uint8, uint16, uint32, uint64:
362+
case int8, uint8:
353363
return fmt.Sprintf("%d", value)
364+
case int:
365+
return FormatLogfmtInt64(int64(v))
366+
case int16:
367+
return FormatLogfmtInt64(int64(v))
368+
case int32:
369+
return FormatLogfmtInt64(int64(v))
370+
case int64:
371+
return FormatLogfmtInt64(v)
372+
case uint:
373+
return FormatLogfmtUint64(uint64(v))
374+
case uint16:
375+
return FormatLogfmtUint64(uint64(v))
376+
case uint32:
377+
return FormatLogfmtUint64(uint64(v))
378+
case uint64:
379+
return FormatLogfmtUint64(v)
354380
case string:
355381
return escapeString(v)
356382
default:
357383
return escapeString(fmt.Sprintf("%+v", value))
358384
}
359385
}
360386

387+
// FormatLogfmtInt64 formats a potentially big number in a friendlier split format.
388+
func FormatLogfmtInt64(n int64) string {
389+
if n < 0 {
390+
return formatLogfmtUint64(uint64(-n), true)
391+
}
392+
return formatLogfmtUint64(uint64(n), false)
393+
}
394+
395+
// FormatLogfmtUint64 formats a potentially big number in a friendlier split format.
396+
func FormatLogfmtUint64(n uint64) string {
397+
return formatLogfmtUint64(n, false)
398+
}
399+
400+
func formatLogfmtUint64(n uint64, neg bool) string {
401+
// Small numbers are fine as is
402+
if n < 100000 {
403+
if neg {
404+
return strconv.Itoa(-int(n))
405+
} else {
406+
return strconv.Itoa(int(n))
407+
}
408+
}
409+
// Large numbers should be split
410+
const maxLength = 26
411+
412+
var (
413+
out = make([]byte, maxLength)
414+
i = maxLength - 1
415+
comma = 0
416+
)
417+
for ; n > 0; i-- {
418+
if comma == 3 {
419+
comma = 0
420+
out[i] = ','
421+
} else {
422+
comma++
423+
out[i] = '0' + byte(n%10)
424+
n /= 10
425+
}
426+
}
427+
if neg {
428+
out[i] = '-'
429+
i--
430+
}
431+
return string(out[i+1:])
432+
}
433+
434+
var big1000 = big.NewInt(1000)
435+
436+
// formatLogfmtBigInt formats a potentially gigantic number in a friendlier split
437+
// format.
438+
func formatLogfmtBigInt(n *big.Int) string {
439+
// Most number don't need fancy handling, just downcast
440+
if n.IsUint64() {
441+
return FormatLogfmtUint64(n.Uint64())
442+
}
443+
if n.IsInt64() {
444+
return FormatLogfmtInt64(n.Int64())
445+
}
446+
// Ok, huge number needs huge effort
447+
groups := make([]string, 0, 8) // random initial size to cover most cases
448+
for n.Cmp(big1000) >= 0 {
449+
_, mod := n.DivMod(n, big1000, nil)
450+
groups = append(groups, fmt.Sprintf("%03d", mod))
451+
}
452+
groups = append(groups, n.String())
453+
454+
last := len(groups) - 1
455+
for i := 0; i < len(groups)/2; i++ {
456+
groups[i], groups[last-i] = groups[last-i], groups[i]
457+
}
458+
return strings.Join(groups, ",")
459+
}
460+
361461
// escapeString checks if the provided string needs escaping/quoting, and
362462
// calls strconv.Quote if needed
363463
func escapeString(s string) string {

log/format_test.go

+75
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,75 @@
1+
package log
2+
3+
import (
4+
"math"
5+
"math/rand"
6+
"testing"
7+
)
8+
9+
func TestPrettyInt64(t *testing.T) {
10+
tests := []struct {
11+
n int64
12+
s string
13+
}{
14+
{0, "0"},
15+
{10, "10"},
16+
{-10, "-10"},
17+
{100, "100"},
18+
{-100, "-100"},
19+
{1000, "1000"},
20+
{-1000, "-1000"},
21+
{10000, "10000"},
22+
{-10000, "-10000"},
23+
{99999, "99999"},
24+
{-99999, "-99999"},
25+
{100000, "100,000"},
26+
{-100000, "-100,000"},
27+
{1000000, "1,000,000"},
28+
{-1000000, "-1,000,000"},
29+
{math.MaxInt64, "9,223,372,036,854,775,807"},
30+
{math.MinInt64, "-9,223,372,036,854,775,808"},
31+
}
32+
for i, tt := range tests {
33+
if have := FormatLogfmtInt64(tt.n); have != tt.s {
34+
t.Errorf("test %d: format mismatch: have %s, want %s", i, have, tt.s)
35+
}
36+
}
37+
}
38+
39+
func TestPrettyUint64(t *testing.T) {
40+
tests := []struct {
41+
n uint64
42+
s string
43+
}{
44+
{0, "0"},
45+
{10, "10"},
46+
{100, "100"},
47+
{1000, "1000"},
48+
{10000, "10000"},
49+
{99999, "99999"},
50+
{100000, "100,000"},
51+
{1000000, "1,000,000"},
52+
{math.MaxUint64, "18,446,744,073,709,551,615"},
53+
}
54+
for i, tt := range tests {
55+
if have := FormatLogfmtUint64(tt.n); have != tt.s {
56+
t.Errorf("test %d: format mismatch: have %s, want %s", i, have, tt.s)
57+
}
58+
}
59+
}
60+
61+
var sink string
62+
63+
func BenchmarkPrettyInt64Logfmt(b *testing.B) {
64+
b.ReportAllocs()
65+
for i := 0; i < b.N; i++ {
66+
sink = FormatLogfmtInt64(rand.Int63())
67+
}
68+
}
69+
70+
func BenchmarkPrettyUint64Logfmt(b *testing.B) {
71+
b.ReportAllocs()
72+
for i := 0; i < b.N; i++ {
73+
sink = FormatLogfmtUint64(rand.Uint64())
74+
}
75+
}

0 commit comments

Comments
 (0)