Merge PR: add pruning log and invalidTxs log (#1189)

* add pruning log

* add invalidTxs log

* fix ut

Co-authored-by: Zhong Qiu <[email protected]>

app/elapse_info.go

@@ -71,11 +71,12 @@ func (e *ElapsedTimeInfos) Dump(logger log.Logger) {
 		}
 	}
 
-	info := fmt.Sprintf("%s<%s>, %s<%s>, %s<%s>, %s[%s]",
+	info := fmt.Sprintf("%s<%s>, %s<%s>, %s<%s>, %s[%s], %s<%s>",
 		trace.Height, e.infoMap[trace.Height],
 		trace.Tx, e.infoMap[trace.Tx],
 		trace.GasUsed, e.infoMap[trace.GasUsed],
 		trace.RunTx, e.infoMap[trace.RunTx],
+		trace.InvalidTxs, e.infoMap[trace.InvalidTxs],
 	)
 
 	if len(detailInfo) > 0 {

libs/cosmos-sdk/baseapp/baseapp.go

@@ -195,6 +195,7 @@ func NewBaseApp(
 	if app.interBlockCache != nil {
 		app.cms.SetInterBlockCache(app.interBlockCache)
 	}
+	app.cms.SetLogger(app.logger)
 
 	app.parallelTxManage.workgroup.Start()
 

libs/cosmos-sdk/server/mock/store.go

@@ -1,6 +1,7 @@
 package mock
 
 import (
+	"github.com/okex/exchain/libs/tendermint/libs/log"
 	"io"
 
 	dbm "github.com/tendermint/tm-db"
@@ -187,3 +188,7 @@ func NewCommitMultiStore() sdk.CommitMultiStore {
 func (ms multiStore) StopStore() {
 	panic("not implemented")
 }
+
+func (ms multiStore) SetLogger(log log.Logger) {
+	panic("not implemented")
+}

libs/cosmos-sdk/store/rootmulti/store.go

@@ -11,6 +11,7 @@ import (
 	abci "github.com/okex/exchain/libs/tendermint/abci/types"
 	"github.com/okex/exchain/libs/tendermint/crypto/merkle"
 	"github.com/okex/exchain/libs/tendermint/crypto/tmhash"
+	tmlog "github.com/okex/exchain/libs/tendermint/libs/log"
 	tmtypes "github.com/okex/exchain/libs/tendermint/types"
 	"github.com/pkg/errors"
 	dbm "github.com/tendermint/tm-db"
@@ -49,6 +50,8 @@ type Store struct {
 	traceContext types.TraceContext
 
 	interBlockCache types.MultiStorePersistentCache
+
+	logger tmlog.Logger
 }
 
 var (
@@ -377,10 +380,20 @@ func (rs *Store) Commit() types.CommitID {
 // pruneStores will batch delete a list of heights from each mounted sub-store.
 // Afterwards, pruneHeights is reset.
 func (rs *Store) pruneStores() {
-	if len(rs.pruneHeights) == 0 {
+	pruneCnt := len(rs.pruneHeights)
+	if pruneCnt == 0 {
 		return
 	}
 
+	if rs.logger != nil {
+		rs.logger.Info("pruning start", "pruning-count", pruneCnt, "curr-height", rs.lastCommitInfo.Version+1)
+		rs.logger.Debug("pruning", "pruning-heights", rs.pruneHeights)
+	}
+	defer func() {
+		if rs.logger != nil {
+			rs.logger.Info("pruning end")
+		}
+	}()
 	for key, store := range rs.stores {
 		if store.GetStoreType() == types.StoreTypeIAVL {
 			// If the store is wrapped with an inter-block cache, we must first unwrap
@@ -1047,3 +1060,7 @@ func (rs *Store) StopStore() {
 	}
 
 }
+
+func (rs *Store) SetLogger(log tmlog.Logger) {
+	rs.logger = log.With("module", "root-multi")
+}

libs/cosmos-sdk/store/rootmulti/store_test.go

@@ -5,9 +5,9 @@ import (
 	"math"
 	"testing"
 
-	"github.com/stretchr/testify/require"
 	abci "github.com/okex/exchain/libs/tendermint/abci/types"
 	"github.com/okex/exchain/libs/tendermint/crypto/merkle"
+	"github.com/stretchr/testify/require"
 	dbm "github.com/tendermint/tm-db"
 
 	"github.com/okex/exchain/libs/cosmos-sdk/store/iavl"

libs/cosmos-sdk/store/types/store.go

@@ -2,6 +2,7 @@ package types
 
 import (
 	"fmt"
+	"github.com/okex/exchain/libs/tendermint/libs/log"
 	"io"
 
 	abci "github.com/okex/exchain/libs/tendermint/abci/types"
@@ -179,6 +180,8 @@ type CommitMultiStore interface {
 	SetInterBlockCache(MultiStorePersistentCache)
 
 	StopStore()
+
+	SetLogger(log log.Logger)
 }
 
 //---------subsp-------------------------------

libs/tendermint/state/execution.go

@@ -374,6 +374,7 @@ func execBlockOnProxyApp(
 	}
 
 	logger.Info("Executed block", "height", block.Height, "validTxs", validTxs, "invalidTxs", invalidTxs)
+	trace.GetElapsedInfo().AddInfo(trace.InvalidTxs, fmt.Sprintf("%d", invalidTxs))
 
 	return abciResponses, nil
 }

libs/tendermint/state/execution_parallel.go

@@ -1,9 +1,11 @@
 package state
 
 import (
+	"fmt"
 	abci "github.com/okex/exchain/libs/tendermint/abci/types"
 	"github.com/okex/exchain/libs/tendermint/libs/log"
 	"github.com/okex/exchain/libs/tendermint/proxy"
+	"github.com/okex/exchain/libs/tendermint/trace"
 	"github.com/okex/exchain/libs/tendermint/types"
 	dbm "github.com/tendermint/tm-db"
 )
@@ -54,6 +56,7 @@ func execBlockOnProxyAppAsync(
 	}
 
 	logger.Info("Executed block", "height", block.Height, "validTxs", validTxs, "invalidTxs", invalidTxs)
+	trace.GetElapsedInfo().AddInfo(trace.InvalidTxs, fmt.Sprintf("%d", invalidTxs))
 
 	return abciResponses, nil
 }

libs/tendermint/trace/trace.go

@@ -22,6 +22,7 @@ const (
 
 
 	Abci       = "abci"
+	InvalidTxs = "InvalidTxs"
 	SaveResp   = "saveResp"
 	Persist    = "persist"
 	SaveState  = "saveState"