From 4d48980e74e7925d40fb89683eac0b43f3540d77 Mon Sep 17 00:00:00 2001 From: Martin Holst Swende Date: Fri, 11 Dec 2020 15:56:00 +0100 Subject: [PATCH] core, eth, les: implement unclean-shutdown marker (#21893) This PR implements unclean shutdown marker. Every time geth boots, it adds a timestamp to a list of timestamps in the database. This list is capped at 10. At a clean shutdown, the timestamp is removed again. Thus, when geth exits unclean, the marker remains, and at boot up we show the most recent unclean shutdowns to the user, which makes it easier to diagnose root-causes to certain problems. Co-authored-by: Nagy Salem --- core/rawdb/accessors_metadata.go | 63 +++++++++++++++++++++++++++++++- core/rawdb/database.go | 2 +- core/rawdb/schema.go | 6 ++- eth/backend.go | 15 ++++++++ les/client.go | 14 +++++++ 5 files changed, 95 insertions(+), 5 deletions(-) diff --git a/core/rawdb/accessors_metadata.go b/core/rawdb/accessors_metadata.go index 14a302a127..079e335fa6 100644 --- a/core/rawdb/accessors_metadata.go +++ b/core/rawdb/accessors_metadata.go @@ -18,6 +18,7 @@ package rawdb import ( "encoding/json" + "time" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/ethdb" @@ -30,7 +31,7 @@ import ( func ReadDatabaseVersion(db ethdb.KeyValueReader) *uint64 { var version uint64 - enc, _ := db.Get(databaseVerisionKey) + enc, _ := db.Get(databaseVersionKey) if len(enc) == 0 { return nil } @@ -47,7 +48,7 @@ func WriteDatabaseVersion(db ethdb.KeyValueWriter, version uint64) { if err != nil { log.Crit("Failed to encode database version", "err", err) } - if err = db.Put(databaseVerisionKey, enc); err != nil { + if err = db.Put(databaseVersionKey, enc); err != nil { log.Crit("Failed to store the database version", "err", err) } } @@ -79,3 +80,61 @@ func WriteChainConfig(db ethdb.KeyValueWriter, hash common.Hash, cfg *params.Cha log.Crit("Failed to store chain config", "err", err) } } + +// crashList is a list of unclean-shutdown-markers, for rlp-encoding to the +// database +type crashList struct { + Discarded uint64 // how many ucs have we deleted + Recent []uint64 // unix timestamps of 10 latest unclean shutdowns +} + +const crashesToKeep = 10 + +// PushUncleanShutdownMarker appends a new unclean shutdown marker and returns +// the previous data +// - a list of timestamps +// - a count of how many old unclean-shutdowns have been discarded +func PushUncleanShutdownMarker(db ethdb.KeyValueStore) ([]uint64, uint64, error) { + var uncleanShutdowns crashList + // Read old data + if data, err := db.Get(uncleanShutdownKey); err != nil { + log.Warn("Error reading unclean shutdown markers", "error", err) + } else if err := rlp.DecodeBytes(data, &uncleanShutdowns); err != nil { + return nil, 0, err + } + var discarded = uncleanShutdowns.Discarded + var previous = make([]uint64, len(uncleanShutdowns.Recent)) + copy(previous, uncleanShutdowns.Recent) + // Add a new (but cap it) + uncleanShutdowns.Recent = append(uncleanShutdowns.Recent, uint64(time.Now().Unix())) + if count := len(uncleanShutdowns.Recent); count > crashesToKeep+1 { + numDel := count - (crashesToKeep + 1) + uncleanShutdowns.Recent = uncleanShutdowns.Recent[numDel:] + uncleanShutdowns.Discarded += uint64(numDel) + } + // And save it again + data, _ := rlp.EncodeToBytes(uncleanShutdowns) + if err := db.Put(uncleanShutdownKey, data); err != nil { + log.Warn("Failed to write unclean-shutdown marker", "err", err) + return nil, 0, err + } + return previous, discarded, nil +} + +// PopUncleanShutdownMarker removes the last unclean shutdown marker +func PopUncleanShutdownMarker(db ethdb.KeyValueStore) { + var uncleanShutdowns crashList + // Read old data + if data, err := db.Get(uncleanShutdownKey); err != nil { + log.Warn("Error reading unclean shutdown markers", "error", err) + } else if err := rlp.DecodeBytes(data, &uncleanShutdowns); err != nil { + log.Error("Error decoding unclean shutdown markers", "error", err) // Should mos def _not_ happen + } + if l := len(uncleanShutdowns.Recent); l > 0 { + uncleanShutdowns.Recent = uncleanShutdowns.Recent[:l-1] + } + data, _ := rlp.EncodeToBytes(uncleanShutdowns) + if err := db.Put(uncleanShutdownKey, data); err != nil { + log.Warn("Failed to clear unclean-shutdown marker", "err", err) + } +} diff --git a/core/rawdb/database.go b/core/rawdb/database.go index b1ac3e9587..b01a31ebcd 100644 --- a/core/rawdb/database.go +++ b/core/rawdb/database.go @@ -355,7 +355,7 @@ func InspectDatabase(db ethdb.Database) error { bloomTrieNodes.Add(size) default: var accounted bool - for _, meta := range [][]byte{databaseVerisionKey, headHeaderKey, headBlockKey, headFastBlockKey, fastTrieProgressKey} { + for _, meta := range [][]byte{databaseVersionKey, headHeaderKey, headBlockKey, headFastBlockKey, fastTrieProgressKey, uncleanShutdownKey} { if bytes.Equal(key, meta) { metadata.Add(size) accounted = true diff --git a/core/rawdb/schema.go b/core/rawdb/schema.go index dbc5025d5d..cff27b4bb0 100644 --- a/core/rawdb/schema.go +++ b/core/rawdb/schema.go @@ -27,8 +27,8 @@ import ( // The fields below define the low level database schema prefixing. var ( - // databaseVerisionKey tracks the current database version. - databaseVerisionKey = []byte("DatabaseVersion") + // databaseVersionKey tracks the current database version. + databaseVersionKey = []byte("DatabaseVersion") // headHeaderKey tracks the latest known header's hash. headHeaderKey = []byte("LastHeader") @@ -81,6 +81,8 @@ var ( preimagePrefix = []byte("secure-key-") // preimagePrefix + hash -> preimage configPrefix = []byte("ethereum-config-") // config prefix for the db + uncleanShutdownKey = []byte("unclean-shutdown") // config prefix for the db + // Chain index prefixes (use `i` + single byte to avoid mixing data types). BloomBitsIndexPrefix = []byte("iB") // BloomBitsIndexPrefix is the data table of a chain indexer to track its progress diff --git a/eth/backend.go b/eth/backend.go index 03b0b319b7..bb4275b92c 100644 --- a/eth/backend.go +++ b/eth/backend.go @@ -24,6 +24,7 @@ import ( "runtime" "sync" "sync/atomic" + "time" "github.com/ethereum/go-ethereum/accounts" "github.com/ethereum/go-ethereum/common" @@ -220,6 +221,19 @@ func New(stack *node.Node, config *Config) (*Ethereum, error) { stack.RegisterAPIs(eth.APIs()) stack.RegisterProtocols(eth.Protocols()) stack.RegisterLifecycle(eth) + // Check for unclean shutdown + if uncleanShutdowns, discards, err := rawdb.PushUncleanShutdownMarker(chainDb); err != nil { + log.Error("Could not update unclean-shutdown-marker list", "error", err) + } else { + if discards > 0 { + log.Warn("Old unclean shutdowns found", "count", discards) + } + for _, tstamp := range uncleanShutdowns { + t := time.Unix(int64(tstamp), 0) + log.Warn("Unclean shutdown detected", "booted", t, + "age", common.PrettyAge(t)) + } + } return eth, nil } @@ -543,6 +557,7 @@ func (s *Ethereum) Stop() error { s.miner.Stop() s.blockchain.Stop() s.engine.Close() + rawdb.PopUncleanShutdownMarker(s.chainDb) s.chainDb.Close() s.eventMux.Stop() return nil diff --git a/les/client.go b/les/client.go index 37250d076f..47997a098b 100644 --- a/les/client.go +++ b/les/client.go @@ -178,6 +178,19 @@ func New(stack *node.Node, config *eth.Config) (*LightEthereum, error) { stack.RegisterProtocols(leth.Protocols()) stack.RegisterLifecycle(leth) + // Check for unclean shutdown + if uncleanShutdowns, discards, err := rawdb.PushUncleanShutdownMarker(chainDb); err != nil { + log.Error("Could not update unclean-shutdown-marker list", "error", err) + } else { + if discards > 0 { + log.Warn("Old unclean shutdowns found", "count", discards) + } + for _, tstamp := range uncleanShutdowns { + t := time.Unix(int64(tstamp), 0) + log.Warn("Unclean shutdown detected", "booted", t, + "age", common.PrettyAge(t)) + } + } return leth, nil } @@ -313,6 +326,7 @@ func (s *LightEthereum) Stop() error { s.engine.Close() s.pruner.close() s.eventMux.Stop() + rawdb.PopUncleanShutdownMarker(s.chainDb) s.chainDb.Close() s.wg.Wait() log.Info("Light ethereum stopped")