Roman/47 gasmeter logs

baseapp/abci.go

@@ -73,7 +73,7 @@ func (app *BaseApp) InitChain(req abci.RequestInitChain) (res abci.ResponseInitC
 	}
 
 	// add block gas meter for any genesis transactions (allow infinite gas)
-	app.deliverState.ctx = app.deliverState.ctx.WithBlockGasMeter(sdk.NewInfiniteGasMeter())
+	app.deliverState.ctx = app.deliverState.ctx.WithBlockGasMeter(sdk.NewInfiniteGasMeter(app.logger))
 
 	res = app.initChainer(app.deliverState.ctx, req)
 

baseapp/abci_test.go

@@ -10,6 +10,7 @@ import (
 
 	dbm "github.com/cometbft/cometbft-db"
 	abci "github.com/cometbft/cometbft/abci/types"
+	"github.com/cometbft/cometbft/libs/log"
 	tmproto "github.com/cometbft/cometbft/proto/tendermint/types"
 	"github.com/cosmos/gogoproto/jsonpb"
 	"github.com/stretchr/testify/require"
@@ -758,7 +759,7 @@ func TestABCI_Query_SimulateTx(t *testing.T) {
 	gasConsumed := uint64(5)
 	anteOpt := func(bapp *baseapp.BaseApp) {
 		bapp.SetAnteHandler(func(ctx sdk.Context, tx sdk.Tx, simulate bool) (newCtx sdk.Context, err error) {
-			newCtx = ctx.WithGasMeter(sdk.NewGasMeter(gasConsumed))
+			newCtx = ctx.WithGasMeter(sdk.NewGasMeter(gasConsumed, log.NewNopLogger()))
 			return
 		})
 	}
@@ -923,7 +924,7 @@ func TestABCI_TxGasLimits(t *testing.T) {
 	gasGranted := uint64(10)
 	anteOpt := func(bapp *baseapp.BaseApp) {
 		bapp.SetAnteHandler(func(ctx sdk.Context, tx sdk.Tx, simulate bool) (newCtx sdk.Context, err error) {
-			newCtx = ctx.WithGasMeter(sdk.NewGasMeter(gasGranted))
+			newCtx = ctx.WithGasMeter(sdk.NewGasMeter(gasGranted, log.NewNopLogger()))
 
 			// AnteHandlers must have their own defer/recover in order for the BaseApp
 			// to know how much gas was used! This is because the GasMeter is created in
@@ -1006,7 +1007,7 @@ func TestABCI_MaxBlockGasLimits(t *testing.T) {
 	gasGranted := uint64(10)
 	anteOpt := func(bapp *baseapp.BaseApp) {
 		bapp.SetAnteHandler(func(ctx sdk.Context, tx sdk.Tx, simulate bool) (newCtx sdk.Context, err error) {
-			newCtx = ctx.WithGasMeter(sdk.NewGasMeter(gasGranted))
+			newCtx = ctx.WithGasMeter(sdk.NewGasMeter(gasGranted, log.NewNopLogger()))
 
 			defer func() {
 				if r := recover(); r != nil {
@@ -1101,7 +1102,7 @@ func TestABCI_GasConsumptionBadTx(t *testing.T) {
 	gasWanted := uint64(5)
 	anteOpt := func(bapp *baseapp.BaseApp) {
 		bapp.SetAnteHandler(func(ctx sdk.Context, tx sdk.Tx, simulate bool) (newCtx sdk.Context, err error) {
-			newCtx = ctx.WithGasMeter(sdk.NewGasMeter(gasWanted))
+			newCtx = ctx.WithGasMeter(sdk.NewGasMeter(gasWanted, log.NewNopLogger()))
 
 			defer func() {
 				if r := recover(); r != nil {

baseapp/baseapp.go

@@ -566,10 +566,10 @@ func (app *BaseApp) getState(mode runTxMode) *state {
 
 func (app *BaseApp) getBlockGasMeter(ctx sdk.Context) storetypes.GasMeter {
 	if maxGas := app.GetMaximumBlockGas(ctx); maxGas > 0 {
-		return storetypes.NewGasMeter(maxGas)
+		return storetypes.NewGasMeter(maxGas, ctx.Logger())
 	}
 
-	return storetypes.NewInfiniteGasMeter()
+	return storetypes.NewInfiniteGasMeter(ctx.Logger())
 }
 
 // retrieve the context for the tx w/ txBytes and other memoized values.
@@ -630,6 +630,8 @@ func (app *BaseApp) runTx(mode runTxMode, txBytes []byte) (gInfo sdk.GasInfo, re
 	ctx := app.getContextForTx(mode, txBytes)
 	ms := ctx.MultiStore()
 
+	ctx.Logger().With("sim", "info").Info("runTx start")
+
 	// only run the tx if there is block gas remaining
 	if mode == runTxModeDeliver && ctx.BlockGasMeter().IsOutOfGas() {
 		return gInfo, nil, nil, 0, sdkerrors.Wrap(sdkerrors.ErrOutOfGas, "no block gas left to run tx")
@@ -673,11 +675,37 @@ func (app *BaseApp) runTx(mode runTxMode, txBytes []byte) (gInfo sdk.GasInfo, re
 		return sdk.GasInfo{}, nil, nil, 0, err
 	}
 
+	ctx.Logger().With("sim", "info").Info("runTx start", "tx_hash", tx.GetMsgs())
+
 	msgs := tx.GetMsgs()
 	if err := validateBasicTxMsgs(msgs); err != nil {
 		return sdk.GasInfo{}, nil, nil, 0, err
 	}
 
+	// hasSwap := false
+
+	// for _, m := range msgs {
+	// 	msgString := m.String()
+
+	// 	if strings.Contains(msgString, "MsgSwapExactAmountIn") {
+	// 		hasSwap = true
+	// 	}
+	// }
+
+	// // Replace logger with filter for a specific message type
+	// appLogerCopy := app.logger
+	// ctxLoggerCopy := ctx.Logger()
+	// if hasSwap {
+	// 	ctx = ctx.WithLogger(ctx.Logger().With("sim", "info"))
+	// 	app.logger = app.logger.With("sim", "info")
+
+	// 	gasMeter := ctx.GasMeter()
+	// 	gasMeter.SetLogger(ctx.Logger())
+	// 	ctx = ctx.WithGasMeter(gasMeter)
+
+	// 	app.logger.Info("Swap sim logger is enabled")
+	// }
+
 	if app.anteHandler != nil {
 		var (
 			anteCtx sdk.Context
@@ -772,6 +800,17 @@ func (app *BaseApp) runTx(mode runTxMode, txBytes []byte) (gInfo sdk.GasInfo, re
 		}
 	}
 
+	// // Revert logger
+	// if hasSwap {
+	// 	app.logger = appLogerCopy
+	// 	ctx = ctx.WithLogger(ctxLoggerCopy)
+	// 	gasMeter := ctx.GasMeter()
+	// 	gasMeter.SetLogger(ctx.Logger())
+	// 	ctx = ctx.WithGasMeter(gasMeter)
+
+	// 	app.logger.Info("Swap sim logger is disabled")
+	// }
+
 	return gInfo, result, anteEvents, priority, err
 }
 
@@ -832,6 +871,8 @@ func (app *BaseApp) runMsgs(ctx sdk.Context, msgs []sdk.Msg, mode runTxMode) (*s
 		return nil, sdkerrors.Wrap(err, "failed to marshal tx data")
 	}
 
+	ctx.Logger().With("sim", "info").Info("runTx end")
+
 	return &sdk.Result{
 		Data:         data,
 		Log:          strings.TrimSpace(msgLogs.String()),

store/gaskv/store_test.go

@@ -7,6 +7,7 @@ import (
 	dbm "github.com/cometbft/cometbft-db"
 	"github.com/stretchr/testify/require"
 
+	"github.com/cometbft/cometbft/libs/log"
 	"github.com/cosmos/cosmos-sdk/store/dbadapter"
 	"github.com/cosmos/cosmos-sdk/store/gaskv"
 	"github.com/cosmos/cosmos-sdk/store/types"
@@ -19,7 +20,7 @@ func valFmt(i int) []byte { return bz(fmt.Sprintf("value%0.8d", i)) }
 
 func TestGasKVStoreBasic(t *testing.T) {
 	mem := dbadapter.Store{DB: dbm.NewMemDB()}
-	meter := types.NewGasMeter(10000)
+	meter := types.NewGasMeter(10000, log.NewNopLogger())
 	st := gaskv.NewStore(mem, meter, types.KVGasConfig())
 
 	require.Equal(t, types.StoreTypeDB, st.GetStoreType())
@@ -39,7 +40,7 @@ func TestGasKVStoreBasic(t *testing.T) {
 
 func TestGasKVStoreIterator(t *testing.T) {
 	mem := dbadapter.Store{DB: dbm.NewMemDB()}
-	meter := types.NewGasMeter(100000)
+	meter := types.NewGasMeter(100000, log.NewNopLogger())
 	st := gaskv.NewStore(mem, meter, types.KVGasConfig())
 	require.False(t, st.Has(keyFmt(1)))
 	require.Empty(t, st.Get(keyFmt(1)), "Expected `key1` to be empty")
@@ -104,14 +105,14 @@ func TestGasKVStoreIterator(t *testing.T) {
 
 func TestGasKVStoreOutOfGasSet(t *testing.T) {
 	mem := dbadapter.Store{DB: dbm.NewMemDB()}
-	meter := types.NewGasMeter(0)
+	meter := types.NewGasMeter(0, log.NewNopLogger())
 	st := gaskv.NewStore(mem, meter, types.KVGasConfig())
 	require.Panics(t, func() { st.Set(keyFmt(1), valFmt(1)) }, "Expected out-of-gas")
 }
 
 func TestGasKVStoreOutOfGasIterator(t *testing.T) {
 	mem := dbadapter.Store{DB: dbm.NewMemDB()}
-	meter := types.NewGasMeter(20000)
+	meter := types.NewGasMeter(20000, log.NewNopLogger())
 	st := gaskv.NewStore(mem, meter, types.KVGasConfig())
 	st.Set(keyFmt(1), valFmt(1))
 	iterator := st.Iterator(nil, nil)

store/types/gas.go

@@ -3,6 +3,8 @@ package types
 import (
 	"fmt"
 	"math"
+
+	"github.com/cometbft/cometbft/libs/log"
 )
 
 // Gas consumption descriptors.
@@ -48,18 +50,29 @@ type GasMeter interface {
 	IsPastLimit() bool
 	IsOutOfGas() bool
 	String() string
+	SetLogger(log.Logger)
 }
 
 type basicGasMeter struct {
 	limit    Gas
 	consumed Gas
+	logger   log.Logger
+}
+
+// SetLogger implements GasMeter.
+func (g *basicGasMeter) SetLogger(logger log.Logger) {
+	g.logger = logger
 }
 
 // NewGasMeter returns a reference to a new basicGasMeter.
-func NewGasMeter(limit Gas) GasMeter {
+func NewGasMeter(limit Gas, logger log.Logger) GasMeter {
+
+	logger = logger.With("sim", "info")
+
 	return &basicGasMeter{
 		limit:    limit,
 		consumed: 0,
+		logger:   logger,
 	}
 }
 
@@ -105,6 +118,8 @@ func addUint64Overflow(a, b uint64) (uint64, bool) {
 
 // ConsumeGas adds the given amount of gas to the gas consumed and panics if it overflows the limit or out of gas.
 func (g *basicGasMeter) ConsumeGas(amount Gas, descriptor string) {
+	g.logger.Info("BasicGasMeter.ConsumeGas", "amount", amount, "descriptor", descriptor)
+
 	var overflow bool
 	g.consumed, overflow = addUint64Overflow(g.consumed, amount)
 	if overflow {
@@ -148,12 +163,22 @@ func (g *basicGasMeter) String() string {
 
 type infiniteGasMeter struct {
 	consumed Gas
+	logger   log.Logger
+}
+
+// SetLogger implements GasMeter.
+func (g *infiniteGasMeter) SetLogger(logger log.Logger) {
+	g.logger = logger
 }
 
 // NewInfiniteGasMeter returns a new gas meter without a limit.
-func NewInfiniteGasMeter() GasMeter {
+func NewInfiniteGasMeter(logger log.Logger) GasMeter {
+
+	logger = logger.With("sim", "info")
+
 	return &infiniteGasMeter{
 		consumed: 0,
+		logger:   logger,
 	}
 }
 
@@ -180,6 +205,8 @@ func (g *infiniteGasMeter) Limit() Gas {
 
 // ConsumeGas adds the given amount of gas to the gas consumed and panics if it overflows the limit.
 func (g *infiniteGasMeter) ConsumeGas(amount Gas, descriptor string) {
+	g.logger.Info("InfiniteGasMeter.ConsumeGas", "amount", amount, "descriptor", descriptor)
+
 	var overflow bool
 	// TODO: Should we set the consumed field after overflow checking?
 	g.consumed, overflow = addUint64Overflow(g.consumed, amount)

types/context.go

@@ -105,7 +105,7 @@ func NewContext(ms MultiStore, header tmproto.Header, isCheckTx bool, logger log
 		chainID:              header.ChainID,
 		checkTx:              isCheckTx,
 		logger:               logger,
-		gasMeter:             storetypes.NewInfiniteGasMeter(),
+		gasMeter:             storetypes.NewInfiniteGasMeter(logger),
 		minGasPrice:          DecCoins{},
 		eventManager:         NewEventManager(),
 		kvGasConfig:          storetypes.KVGasConfig(),

types/context_test.go

@@ -6,6 +6,7 @@ import (
 	"time"
 
 	abci "github.com/cometbft/cometbft/abci/types"
+	"github.com/cometbft/cometbft/libs/log"
 	tmproto "github.com/cometbft/cometbft/proto/tendermint/types"
 	tmtime "github.com/cometbft/cometbft/types/time"
 	"github.com/golang/mock/gomock"
@@ -90,8 +91,8 @@ func (s *contextTestSuite) TestContextWithCustom() {
 	txbytes := []byte("txbytes")
 	logger := mock.NewMockLogger(ctrl)
 	voteinfos := []abci.VoteInfo{{}}
-	meter := types.NewGasMeter(10000)
-	blockGasMeter := types.NewGasMeter(20000)
+	meter := types.NewGasMeter(10000, log.NewNopLogger())
+	blockGasMeter := types.NewGasMeter(20000, log.NewNopLogger())
 	minGasPrices := types.DecCoins{types.NewInt64DecCoin("feetoken", 1)}
 	headerHash := []byte("headerHash")
 	zeroGasCfg := storetypes.GasConfig{}

types/handler.go

@@ -1,5 +1,10 @@
 package types
 
+import (
+	fmt "fmt"
+	reflect "reflect"
+)
+
 // Handler defines the core of the state transition function of an application.
 type Handler func(ctx Context, msg Msg) (*Result, error)
 
@@ -46,7 +51,34 @@ func ChainAnteDecorators(chain ...AnteDecorator) AnteHandler {
 	}
 
 	return func(ctx Context, tx Tx, simulate bool) (Context, error) {
-		return chain[0].AnteHandle(ctx, tx, simulate, ChainAnteDecorators(chain[1:]...))
+
+		structName := getConcreteStructName(chain[0])
+
+		if simulate {
+			ctx.Logger().With("sim", "info").Info(fmt.Sprintf("ChainAnteDecorators - %s START", structName))
+		}
+
+		ctx, err := chain[0].AnteHandle(ctx, tx, simulate, ChainAnteDecorators(chain[1:]...))
+
+		if simulate {
+			ctx.Logger().With("sim", "info").Info(fmt.Sprintf("ChainAnteDecorators - %s END", structName))
+		}
+
+		return ctx, err
+	}
+}
+
+func getConcreteStructName(i interface{}) string {
+	t := reflect.TypeOf(i)
+
+	if t.Kind() == reflect.Ptr {
+		t = t.Elem()
+	}
+
+	if t.Kind() == reflect.Struct {
+		return t.Name()
+	} else {
+		panic(fmt.Sprintf("Expected struct, got %s", t.Kind()))
 	}
 }
 

types/module/module.go

@@ -398,7 +398,7 @@ func (m *Manager) ExportGenesisForModules(ctx sdk.Context, cdc codec.JSONCodec,
 		if module, ok := m.Modules[moduleName].(HasGenesis); ok {
 			channels[moduleName] = make(chan json.RawMessage)
 			go func(module HasGenesis, ch chan json.RawMessage) {
-				ctx := ctx.WithGasMeter(sdk.NewInfiniteGasMeter()) // avoid race conditions
+				ctx := ctx.WithGasMeter(sdk.NewInfiniteGasMeter(ctx.Logger())) // avoid race conditions
 				ch <- module.ExportGenesis(ctx, cdc)
 			}(module, channels[moduleName])
 		}

types/store.go

@@ -7,6 +7,8 @@ import (
 
 	"github.com/cosmos/cosmos-sdk/store/types"
 	"github.com/cosmos/cosmos-sdk/types/kv"
+
+	"github.com/cometbft/cometbft/libs/log"
 )
 
 type (
@@ -156,10 +158,10 @@ type (
 	ErrorGasOverflow = types.ErrorGasOverflow
 )
 
-func NewGasMeter(limit Gas) GasMeter {
-	return types.NewGasMeter(limit)
+func NewGasMeter(limit Gas, logger log.Logger) GasMeter {
+	return types.NewGasMeter(limit, logger)
 }
 
-func NewInfiniteGasMeter() GasMeter {
-	return types.NewInfiniteGasMeter()
+func NewInfiniteGasMeter(log log.Logger) GasMeter {
+	return types.NewInfiniteGasMeter(log)
 }

types/store_test.go

@@ -61,7 +61,7 @@ func (s *storeTestSuite) TestNewTransientStoreKeys() {
 }
 
 func (s *storeTestSuite) TestNewInfiniteGasMeter() {
-	gm := sdk.NewInfiniteGasMeter()
+	gm := sdk.NewInfiniteGasMeter(log.NewNopLogger())
 	s.Require().NotNil(gm)
 	_, ok := gm.(types.GasMeter)
 	s.Require().True(ok)