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 <[email protected]>

Author: holiman

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)
+	}
+}

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

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
 

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

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")