From 0f2ba07c4122fbc2d836a2f374e5da8d8546e99f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Szil=C3=A1gyi?= Date: Thu, 20 Sep 2018 11:41:59 +0300 Subject: [PATCH] common, core, light: add block age into info logs --- common/format.go | 42 ++++++++++++++++++++++++++++++++++++++++++ core/blockchain.go | 28 ++++++++++++++++++---------- core/headerchain.go | 14 ++++++++++++-- light/lightchain.go | 4 ++-- 4 files changed, 74 insertions(+), 14 deletions(-) diff --git a/common/format.go b/common/format.go index fccc29962..6fc21af71 100644 --- a/common/format.go +++ b/common/format.go @@ -38,3 +38,45 @@ func (d PrettyDuration) String() string { } return label } + +// PrettyAge is a pretty printed version of a time.Duration value that rounds +// the values up to a single most significant unit, days/weeks/years included. +type PrettyAge time.Time + +// ageUnits is a list of units the age pretty printing uses. +var ageUnits = []struct { + Size time.Duration + Symbol string +}{ + {12 * 30 * 24 * time.Hour, "y"}, + {30 * 24 * time.Hour, "mo"}, + {7 * 24 * time.Hour, "w"}, + {24 * time.Hour, "d"}, + {time.Hour, "h"}, + {time.Minute, "m"}, + {time.Second, "s"}, +} + +// String implements the Stringer interface, allowing pretty printing of duration +// values rounded to the most significant time unit. +func (t PrettyAge) String() string { + // Calculate the time difference and handle the 0 cornercase + diff := time.Since(time.Time(t)) + if diff < time.Second { + return "0" + } + // Accumulate a precision of 3 components before returning + result, prec := "", 0 + + for _, unit := range ageUnits { + if diff > unit.Size { + result = fmt.Sprintf("%s%d%s", result, diff/unit.Size, unit.Symbol) + diff %= unit.Size + + if prec += 1; prec >= 3 { + break + } + } + } + return result +} diff --git a/core/blockchain.go b/core/blockchain.go index 63f60ca28..7a3b09705 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -251,9 +251,9 @@ func (bc *BlockChain) loadLastState() error { blockTd := bc.GetTd(currentBlock.Hash(), currentBlock.NumberU64()) fastTd := bc.GetTd(currentFastBlock.Hash(), currentFastBlock.NumberU64()) - log.Info("Loaded most recent local header", "number", currentHeader.Number, "hash", currentHeader.Hash(), "td", headerTd) - log.Info("Loaded most recent local full block", "number", currentBlock.Number(), "hash", currentBlock.Hash(), "td", blockTd) - log.Info("Loaded most recent local fast block", "number", currentFastBlock.Number(), "hash", currentFastBlock.Hash(), "td", fastTd) + log.Info("Loaded most recent local header", "number", currentHeader.Number, "hash", currentHeader.Hash(), "td", headerTd, "age", common.PrettyAge(time.Unix(currentHeader.Time.Int64(), 0))) + log.Info("Loaded most recent local full block", "number", currentBlock.Number(), "hash", currentBlock.Hash(), "td", blockTd, "age", common.PrettyAge(time.Unix(currentBlock.Time().Int64(), 0))) + log.Info("Loaded most recent local fast block", "number", currentFastBlock.Number(), "hash", currentFastBlock.Hash(), "td", fastTd, "age", common.PrettyAge(time.Unix(currentFastBlock.Time().Int64(), 0))) return nil } @@ -850,13 +850,16 @@ func (bc *BlockChain) InsertReceiptChain(blockChain types.Blocks, receiptChain [ } bc.mu.Unlock() - log.Info("Imported new block receipts", - "count", stats.processed, - "elapsed", common.PrettyDuration(time.Since(start)), - "number", head.Number(), - "hash", head.Hash(), + context := []interface{}{ + "count", stats.processed, "elapsed", common.PrettyDuration(time.Since(start)), + "number", head.Number(), "hash", head.Hash(), "age", common.PrettyAge(time.Unix(head.Time().Int64(), 0)), "size", common.StorageSize(bytes), - "ignored", stats.ignored) + } + if stats.ignored > 0 { + context = append(context, []interface{}{"ignored", stats.ignored}...) + } + log.Info("Imported new block receipts", context...) + return 0, nil } @@ -1229,8 +1232,13 @@ func (st *insertStats) report(chain []*types.Block, index int, cache common.Stor context := []interface{}{ "blocks", st.processed, "txs", txs, "mgas", float64(st.usedGas) / 1000000, "elapsed", common.PrettyDuration(elapsed), "mgasps", float64(st.usedGas) * 1000 / float64(elapsed), - "number", end.Number(), "hash", end.Hash(), "cache", cache, + "number", end.Number(), "hash", end.Hash(), } + if timestamp := time.Unix(end.Time().Int64(), 0); time.Since(timestamp) > time.Minute { + context = append(context, []interface{}{"age", common.PrettyAge(timestamp)}...) + } + context = append(context, []interface{}{"cache", cache}...) + if st.queued > 0 { context = append(context, []interface{}{"queued", st.queued}...) } diff --git a/core/headerchain.go b/core/headerchain.go index 2bbec28bf..d2093113c 100644 --- a/core/headerchain.go +++ b/core/headerchain.go @@ -281,8 +281,18 @@ func (hc *HeaderChain) InsertHeaderChain(chain []*types.Header, writeHeader WhCa } // Report some public statistics so the user has a clue what's going on last := chain[len(chain)-1] - log.Info("Imported new block headers", "count", stats.processed, "elapsed", common.PrettyDuration(time.Since(start)), - "number", last.Number, "hash", last.Hash(), "ignored", stats.ignored) + + context := []interface{}{ + "count", stats.processed, "elapsed", common.PrettyDuration(time.Since(start)), + "number", last.Number, "hash", last.Hash(), + } + if timestamp := time.Unix(last.Time.Int64(), 0); time.Since(timestamp) > time.Minute { + context = append(context, []interface{}{"age", common.PrettyAge(timestamp)}...) + } + if stats.ignored > 0 { + context = append(context, []interface{}{"ignored", stats.ignored}...) + } + log.Info("Imported new block headers", context...) return 0, nil } diff --git a/light/lightchain.go b/light/lightchain.go index d40a4ee6c..81bdaad75 100644 --- a/light/lightchain.go +++ b/light/lightchain.go @@ -157,7 +157,7 @@ func (self *LightChain) loadLastState() error { // Issue a status log and return header := self.hc.CurrentHeader() headerTd := self.GetTd(header.Hash(), header.Number.Uint64()) - log.Info("Loaded most recent local header", "number", header.Number, "hash", header.Hash(), "td", headerTd) + log.Info("Loaded most recent local header", "number", header.Number, "hash", header.Hash(), "td", headerTd, "age", common.PrettyAge(time.Unix(header.Time.Int64(), 0))) return nil } @@ -488,7 +488,7 @@ func (self *LightChain) SyncCht(ctx context.Context) bool { // Ensure the chain didn't move past the latest block while retrieving it if self.hc.CurrentHeader().Number.Uint64() < header.Number.Uint64() { - log.Info("Updated latest header based on CHT", "number", header.Number, "hash", header.Hash()) + log.Info("Updated latest header based on CHT", "number", header.Number, "hash", header.Hash(), "age", common.PrettyAge(time.Unix(header.Time.Int64(), 0))) self.hc.SetCurrentHeader(header) } return true