From 267c64ea856961784d87b7212bf7f4fe83df3ff0 Mon Sep 17 00:00:00 2001 From: Chill Validation Date: Fri, 3 Mar 2023 22:58:48 +0100 Subject: [PATCH 1/3] Snapshot create and restore debug logs for real-time monitoring --- store/rootmulti/store.go | 23 +++++++++++++++++++++-- 1 file changed, 21 insertions(+), 2 deletions(-) diff --git a/store/rootmulti/store.go b/store/rootmulti/store.go index 38f54607c19a..01bb5d705f60 100644 --- a/store/rootmulti/store.go +++ b/store/rootmulti/store.go @@ -1,6 +1,7 @@ package rootmulti import ( + "encoding/hex" "errors" "fmt" "io" @@ -211,6 +212,7 @@ func (rs *Store) LoadVersion(ver int64) error { func (rs *Store) loadVersion(ver int64, upgrades *types.StoreUpgrades) error { infos := make(map[string]types.StoreInfo) + rs.logger.Debug("loadVersion", "ver", ver) cInfo := &types.CommitInfo{} // load old data if we are not version 0 @@ -248,12 +250,13 @@ func (rs *Store) loadVersion(ver int64, upgrades *types.StoreUpgrades) error { for _, key := range storesKeys { storeParams := rs.storesParams[key] commitID := rs.getCommitID(infos, key.Name()) + rs.logger.Debug("loadVersion commitID", "key", key, "ver", ver, "hash", hex.EncodeToString(commitID.Hash)) // If it has been added, set the initial version if upgrades.IsAdded(key.Name()) || upgrades.RenamedFrom(key.Name()) != "" { storeParams.initialVersion = uint64(ver) + 1 } else if commitID.Version != ver && storeParams.typ == types.StoreTypeIAVL { - return fmt.Errorf("version of store %s mismatch root store's version; expected %d got %d", key.Name(), ver, commitID.Version) + return fmt.Errorf("version of store %s mismatch root store's version; expected %d got %d; New stores should be added using StoreUpgrades", key.Name(), ver, commitID.Version) } store, err := rs.loadCommitStoreFromParams(key, commitID, storeParams) @@ -605,9 +608,11 @@ func (rs *Store) PruneStores(clearPruningManager bool, pruningHeights []int64) ( return nil } - rs.logger.Debug("pruning heights", "heights", pruningHeights) + rs.logger.Debug("pruning store", "heights", pruningHeights) for key, store := range rs.stores { + rs.logger.Debug("pruning store", "key", key) // Also log store.name (a private variable)? + // If the store is wrapped with an inter-block cache, we must first unwrap // it to get the underlying IAVL store. if store.GetStoreType() != types.StoreTypeIAVL { @@ -773,8 +778,14 @@ func (rs *Store) Snapshot(height uint64, protoWriter protoio.Writer) error { // and the following messages contain a SnapshotNode (i.e. an ExportNode). Store changes // are demarcated by new SnapshotStore items. for _, store := range stores { + rs.logger.Debug("starting snapshot", "store", store.name, "height", height) exporter, err := store.Export(int64(height)) + if exporter == nil { + rs.logger.Error("snapshot failed; exporter is nil", "store", store.name) + return err + } if err != nil { + rs.logger.Error("snapshot failed; exporter error", "store", store.name, "err", err) return err } @@ -789,12 +800,16 @@ func (rs *Store) Snapshot(height uint64, protoWriter protoio.Writer) error { }, }) if err != nil { + rs.logger.Error("snapshot failed; item store write failed", "store", store.name, "err", err) return err } + nodeCount := 0 for { node, err := exporter.Next() if err == iavltree.ErrorExportDone { + rs.logger.Debug("Snapshot Done", "store", store.name, "nodeCount", nodeCount) + nodeCount = 0 break } else if err != nil { return err @@ -812,6 +827,7 @@ func (rs *Store) Snapshot(height uint64, protoWriter protoio.Writer) error { if err != nil { return err } + nodeCount++ } return nil @@ -863,9 +879,12 @@ loop: return snapshottypes.SnapshotItem{}, errorsmod.Wrap(err, "import failed") } defer importer.Close() + // Importer height must reflect the node height (which usually matches the block height, but not always) + rs.logger.Debug("restoring snapshot", "store", item.Store.Name) case *snapshottypes.SnapshotItem_IAVL: if importer == nil { + rs.logger.Error("failed to restore; received IAVL node item before store item") return snapshottypes.SnapshotItem{}, errorsmod.Wrap(types.ErrLogic, "received IAVL node item before store item") } if item.IAVL.Height > math.MaxInt8 { From dbf802dc4078389e59f59b18ee2d92efc86a1565 Mon Sep 17 00:00:00 2001 From: Chill Validation Date: Mon, 6 Mar 2023 13:46:54 +0100 Subject: [PATCH 2/3] Remove encoding/hex dependency --- store/rootmulti/store.go | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/store/rootmulti/store.go b/store/rootmulti/store.go index 01bb5d705f60..4faae40f6bb0 100644 --- a/store/rootmulti/store.go +++ b/store/rootmulti/store.go @@ -1,7 +1,6 @@ package rootmulti import ( - "encoding/hex" "errors" "fmt" "io" @@ -250,7 +249,7 @@ func (rs *Store) loadVersion(ver int64, upgrades *types.StoreUpgrades) error { for _, key := range storesKeys { storeParams := rs.storesParams[key] commitID := rs.getCommitID(infos, key.Name()) - rs.logger.Debug("loadVersion commitID", "key", key, "ver", ver, "hash", hex.EncodeToString(commitID.Hash)) + rs.logger.Debug("loadVersion commitID", "key", key, "ver", ver, "hash", fmt.Sprintf("%x", commitID.Hash)) // If it has been added, set the initial version if upgrades.IsAdded(key.Name()) || upgrades.RenamedFrom(key.Name()) != "" { From 40cdf667a25010c3720dbf4369bddb9970618d84 Mon Sep 17 00:00:00 2001 From: Marko Date: Mon, 6 Mar 2023 17:22:52 +0100 Subject: [PATCH 3/3] Update store/rootmulti/store.go Co-authored-by: Aleksandr Bezobchuk --- store/rootmulti/store.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/store/rootmulti/store.go b/store/rootmulti/store.go index 4faae40f6bb0..da45c99f064a 100644 --- a/store/rootmulti/store.go +++ b/store/rootmulti/store.go @@ -255,7 +255,7 @@ func (rs *Store) loadVersion(ver int64, upgrades *types.StoreUpgrades) error { if upgrades.IsAdded(key.Name()) || upgrades.RenamedFrom(key.Name()) != "" { storeParams.initialVersion = uint64(ver) + 1 } else if commitID.Version != ver && storeParams.typ == types.StoreTypeIAVL { - return fmt.Errorf("version of store %s mismatch root store's version; expected %d got %d; New stores should be added using StoreUpgrades", key.Name(), ver, commitID.Version) + return fmt.Errorf("version of store %s mismatch root store's version; expected %d got %d; new stores should be added using StoreUpgrades", key.Name(), ver, commitID.Version) } store, err := rs.loadCommitStoreFromParams(key, commitID, storeParams)