Store EVM tx receipts for txs that fail (#1399)

Previously EVM tx receipts were only stored for EVM txs that didn't error out, this presented a problem because EVM txs that fail are still committed to a block and the block explorer expects to be able to find a receipt for each tx in a block. Now (after the `receipts:v3` feature flag is activated) receipts will be stored for all EVM txs, regardless of whether they succeeded or not.

NOTE: `NonceHandler.IncNonceOnFailedTx` should be enabled in the on-chain config before the `receipts:v3` feature flag. This will ensure that EVM tx hashes are generated with the correct nonce.

Co-authored-by: Vadim Macagon <[email protected]>

app.go

@@ -555,17 +555,8 @@ func (a *Application) EndBlock(req abci.RequestEndBlock) abci.ResponseEndBlock {
 		panic(fmt.Sprintf("app height %d doesn't match EndBlock height %d", a.height(), req.Height))
 	}
 
-	// TODO: Need to cleanup this receipts stuff...
-	// 1. The storeTx is no longer used by the receipt handler, so need to remove it.
-	// 2. receiptHandler.CommitBlock() should be moved to Application.Commit().
+	// TODO: receiptHandler.CommitBlock() should be moved to Application.Commit()
 	storeTx := store.WrapAtomic(a.Store).BeginTx()
-	state := NewStoreState(
-		context.Background(),
-		storeTx,
-		a.curBlockHeader,
-		nil,
-		a.GetValidatorSet,
-	).WithOnChainConfig(a.config)
 	receiptHandler := a.ReceiptHandlerProvider.Store()
 	if err := receiptHandler.CommitBlock(a.height()); err != nil {
 		storeTx.Rollback()
@@ -576,7 +567,7 @@ func (a *Application) EndBlock(req abci.RequestEndBlock) abci.ResponseEndBlock {
 	}
 
 	storeTx = store.WrapAtomic(a.Store).BeginTx()
-	state = NewStoreState(
+	state := NewStoreState(
 		context.Background(),
 		storeTx,
 		a.curBlockHeader,
@@ -611,8 +602,6 @@ func (a *Application) EndBlock(req abci.RequestEndBlock) abci.ResponseEndBlock {
 }
 
 func (a *Application) CheckTx(txBytes []byte) abci.ResponseCheckTx {
-	ok := abci.ResponseCheckTx{Code: abci.CodeTypeOK}
-
 	var err error
 	defer func(begin time.Time) {
 		lvs := []string{"method", "CheckTx", "error", fmt.Sprint(err != nil)}
@@ -627,46 +616,82 @@ func (a *Application) CheckTx(txBytes []byte) abci.ResponseCheckTx {
 	// only happen on node restarts, and only if the node doesn't receive any txs from it's peers
 	// before a client sends it a tx.
 	if a.curBlockHeader.Height == 0 {
-		return ok
+		return abci.ResponseCheckTx{Code: abci.CodeTypeOK}
 	}
 
-	_, err = a.processTx(txBytes, true)
+	storeTx := store.WrapAtomic(a.Store).BeginTx()
+	defer storeTx.Rollback()
+
+	state := NewStoreState(
+		context.Background(),
+		storeTx,
+		a.curBlockHeader,
+		a.curBlockHash,
+		a.GetValidatorSet,
+	).WithOnChainConfig(a.config)
+
+	// Receipts & events generated in CheckTx must be discarded since the app state changes they
+	// reflect aren't persisted.
+	defer a.ReceiptHandlerProvider.Store().DiscardCurrentReceipt()
+	defer a.EventHandler.Rollback()
+
+	_, err = a.TxHandler.ProcessTx(state, txBytes, true)
 	if err != nil {
-		log.Error(fmt.Sprintf("CheckTx: %s", err.Error()))
+		log.Error("CheckTx", "err", err)
 		return abci.ResponseCheckTx{Code: 1, Log: err.Error()}
 	}
 
-	return ok
+	return abci.ResponseCheckTx{Code: abci.CodeTypeOK}
 }
+
 func (a *Application) DeliverTx(txBytes []byte) abci.ResponseDeliverTx {
-	var err error
-	isEvmTx := false
+	var txFailed, isEvmTx bool
 	defer func(begin time.Time) {
 		lvs := []string{
 			"method", "DeliverTx",
-			"error", fmt.Sprint(err != nil),
-			"evm", fmt.Sprintf("%t", isEvmTx),
+			"error", fmt.Sprint(txFailed),
+			"evm", fmt.Sprint(isEvmTx),
 		}
 		requestCount.With(lvs[:4]...).Add(1)
 		deliverTxLatency.With(lvs...).Observe(time.Since(begin).Seconds())
 	}(time.Now())
 
-	r, err := a.processTx(txBytes, false)
+	storeTx := store.WrapAtomic(a.Store).BeginTx()
+	defer storeTx.Rollback()
+
+	state := NewStoreState(
+		context.Background(),
+		storeTx,
+		a.curBlockHeader,
+		a.curBlockHash,
+		a.GetValidatorSet,
+	).WithOnChainConfig(a.config)
+
+	var r abci.ResponseDeliverTx
+
+	if state.FeatureEnabled(features.EvmTxReceiptsVersion3_1, false) {
+		r = a.deliverTx2(storeTx, txBytes)
+	} else {
+		r = a.deliverTx(storeTx, txBytes)
+	}
+
+	txFailed = r.Code != abci.CodeTypeOK
+	// TODO: this isn't 100% reliable when txFailed == true
+	isEvmTx = r.Info == utils.CallEVM || r.Info == utils.DeployEvm
+	return r
+}
+
+// This version of DeliverTx doesn't store the receipts for failed EVM txs.
+func (a *Application) deliverTx(storeTx store.KVStoreTx, txBytes []byte) abci.ResponseDeliverTx {
+	r, err := a.processTx(storeTx, txBytes, false)
 	if err != nil {
 		log.Error(fmt.Sprintf("DeliverTx: %s", err.Error()))
 		return abci.ResponseDeliverTx{Code: 1, Log: err.Error()}
 	}
-	if r.Info == utils.CallEVM || r.Info == utils.DeployEvm {
-		isEvmTx = true
-	}
 	return abci.ResponseDeliverTx{Code: abci.CodeTypeOK, Data: r.Data, Tags: r.Tags, Info: r.Info}
 }
 
-func (a *Application) processTx(txBytes []byte, isCheckTx bool) (TxHandlerResult, error) {
-	//TODO we should be keeping this across multiple checktx, and only rolling back after they all complete
-	// for now the nonce will have a special cache that it rolls back each block
-	storeTx := store.WrapAtomic(a.Store).BeginTx()
-
+func (a *Application) processTx(storeTx store.KVStoreTx, txBytes []byte, isCheckTx bool) (TxHandlerResult, error) {
 	state := NewStoreState(
 		context.Background(),
 		storeTx,
@@ -681,8 +706,6 @@ func (a *Application) processTx(txBytes []byte, isCheckTx bool) (TxHandlerResult
 
 	r, err := a.TxHandler.ProcessTx(state, txBytes, isCheckTx)
 	if err != nil {
-		storeTx.Rollback()
-		// TODO: save receipt & hash of failed EVM tx to node-local persistent cache (not app state)
 		return r, err
 	}
 
@@ -720,6 +743,64 @@ func (a *Application) processTx(txBytes []byte, isCheckTx bool) (TxHandlerResult
 	return r, nil
 }
 
+// This version of DeliverTx stores the receipts for failed EVM txs.
+func (a *Application) deliverTx2(storeTx store.KVStoreTx, txBytes []byte) abci.ResponseDeliverTx {
+	state := NewStoreState(
+		context.Background(),
+		storeTx,
+		a.curBlockHeader,
+		a.curBlockHash,
+		a.GetValidatorSet,
+	).WithOnChainConfig(a.config)
+
+	receiptHandler := a.ReceiptHandlerProvider.Store()
+	defer receiptHandler.DiscardCurrentReceipt()
+	defer a.EventHandler.Rollback()
+
+	r, txErr := a.TxHandler.ProcessTx(state, txBytes, false)
+
+	// Store the receipt even if the tx itself failed
+	var receiptTxHash []byte
+	if a.ReceiptHandlerProvider.Reader().GetCurrentReceipt() != nil {
+		receiptTxHash = a.ReceiptHandlerProvider.Reader().GetCurrentReceipt().TxHash
+		txHash := ttypes.Tx(txBytes).Hash()
+		// If a receipt was generated for an EVM tx add a link between the TM tx hash and the EVM tx hash
+		// so that we can use it to lookup relevant events using the TM tx hash.
+		if !bytes.Equal(txHash, receiptTxHash) {
+			a.childTxRefs = append(a.childTxRefs, evmaux.ChildTxRef{
+				ParentTxHash: txHash,
+				ChildTxHash:  receiptTxHash,
+			})
+		}
+		receiptHandler.CommitCurrentReceipt()
+	}
+
+	if txErr != nil {
+		log.Error("DeliverTx", "err", txErr)
+		// FIXME: Really shouldn't be using r.Data if txErr != nil, but need to refactor TxHandler.ProcessTx
+		//        so it only returns r with the correct status code & log fields.
+		// Pass the EVM tx hash (if any) back to Tendermint so it stores it in block results
+		return abci.ResponseDeliverTx{Code: 1, Data: r.Data, Log: txErr.Error()}
+	}
+
+	a.EventHandler.Commit(uint64(a.curBlockHeader.GetHeight()))
+	storeTx.Commit()
+
+	// FIXME: Really shouldn't be sending out events until the whole block is committed because
+	//        the state changes from the tx won't be visible to queries until after Application.Commit()
+	if err := a.EventHandler.LegacyEthSubscriptionSet().EmitTxEvent(r.Data, r.Info); err != nil {
+		log.Error("Emit Tx Event error", "err", err)
+	}
+
+	if len(receiptTxHash) > 0 {
+		if err := a.EventHandler.EthSubscriptionSet().EmitTxEvent(receiptTxHash); err != nil {
+			log.Error("failed to emit tx event to subscribers", "err", err)
+		}
+	}
+
+	return abci.ResponseDeliverTx{Code: abci.CodeTypeOK, Data: r.Data, Tags: r.Tags, Info: r.Info}
+}
+
 // Commit commits the current block
 func (a *Application) Commit() abci.ResponseCommit {
 	var err error

cmd/loom/config.go

@@ -220,6 +220,14 @@ func defaultGenesis(cfg *config.Config, validator *loom.Validator) (*config.Gene
 					Name:   features.EvmTxReceiptsVersion2Feature,
 					Status: chainconfig.FeatureWaiting,
 				},
+				&cctypes.Feature{
+					Name:   features.EvmTxReceiptsVersion3,
+					Status: chainconfig.FeatureWaiting,
+				},
+				&cctypes.Feature{
+					Name:   features.EvmTxReceiptsVersion3_1,
+					Status: chainconfig.FeatureWaiting,
+				},
 				&cctypes.Feature{
 					Name:   features.CoinVersion1_1Feature,
 					Status: chainconfig.FeatureWaiting,

e2e/tests/genesis.json

@@ -67,6 +67,14 @@
                         "name": "receipts:v2",
                         "status": "WAITING"
                     },
+                    {
+                        "name": "receipts:v3",
+                        "status": "WAITING"
+                    },
+                    {
+                        "name": "receipts:v3.1",
+                        "status": "WAITING"
+                    },
                     {
                         "name": "coin:v1.1",
                         "status": "WAITING"
@@ -86,6 +94,14 @@
                     {
                         "name": "evm:constantinople",
                         "status": "WAITING"
+                    },
+                    {
+                        "name": "receipts:v3",
+                        "status": "WAITING"
+                    },
+                    {
+                        "name": "receipts:v3.1",
+                        "status": "WAITING"
                     }
                 ]
             }

e2e/tests/receipts/genesis.json

@@ -78,6 +78,14 @@
                         "name": "coin:v1.1",
                         "status": "WAITING"
                     },
+                    {
+                        "name": "receipts:v3",
+                        "status": "WAITING"
+                    },
+                    {
+                        "name": "receipts:v3.1",
+                        "status": "WAITING"
+                    },
                     {
                         "name": "appstore:v3.1",
                         "status": "WAITING"

eth/polls/polls_test.go

@@ -259,6 +259,7 @@ func makeMockState(t *testing.T, receiptHandler *handler.ReceiptHandler) loomcha
 		},
 	}
 	state4 := common.MockStateAt(state, 4)
+
 	_, err := receiptHandler.CacheReceipt(state4, addr1, contract, mockEvent4, nil)
 	require.NoError(t, err)
 	receiptHandler.CommitCurrentReceipt()

eth/query/query_test.go

@@ -206,6 +206,7 @@ func testGetLogs(t *testing.T, v handler.ReceiptHandlerVersion) {
 			Address: addr1.MarshalPB(),
 		},
 	}
+
 	state := common.MockState(1)
 	state32 := common.MockStateAt(state, 32)
 	txHash, err := writer.CacheReceipt(state32, addr1, addr2, testEventsG, nil)

eth/subs/reset-hub.go

@@ -1,8 +1,9 @@
 package subs
 
 import (
-	"github.com/phonkee/go-pubsub"
 	"sync"
+
+	"github.com/phonkee/go-pubsub"
 )
 
 // hub implements Hub interface
@@ -39,6 +40,7 @@ func (h *ethResetHub) closeSubscription(id string) {
 
 // Publish publishes message to subscribers
 func (h *ethResetHub) Publish(message pubsub.Message) int {
+	// FIXME: wtf is this a read lock when it's writing to h.unsent?
 	h.mutex.RLock()
 	defer h.mutex.RUnlock()
 	count := 0

evm/loomevm.go

@@ -167,7 +167,7 @@ func (lvm LoomVm) Create(caller loom.Address, code []byte, value *loom.BigUInt)
 		var errSaveReceipt error
 		txHash, errSaveReceipt = lvm.receiptHandler.CacheReceipt(lvm.state, caller, addr, events, err)
 		if errSaveReceipt != nil {
-			err = errors.Wrapf(err, "trouble saving receipt %v", errSaveReceipt)
+			err = errors.Wrapf(err, "failed to create tx receipt: %v", errSaveReceipt)
 		}
 	}
 
@@ -212,9 +212,10 @@ func (lvm LoomVm) Call(caller, addr loom.Address, input []byte, value *loom.BigU
 		var errSaveReceipt error
 		txHash, errSaveReceipt = lvm.receiptHandler.CacheReceipt(lvm.state, caller, addr, events, err)
 		if errSaveReceipt != nil {
-			err = errors.Wrapf(err, "trouble saving receipt %v", errSaveReceipt)
+			err = errors.Wrapf(err, "failed to create tx receipt: %v", errSaveReceipt)
 		}
 	}
+
 	return txHash, err
 }
 

features/features.go

@@ -52,6 +52,9 @@ const (
 	// Enables saving of EVM tx receipts for EVM calls made from Go contracts
 	EvmTxReceiptsVersion3 = "receipts:v3"
 
+	// Enables saving of EVM tx receipts for failed EVM calls
+	EvmTxReceiptsVersion3_1 = "receipts:v3.1"
+
 	// Enables deployer whitelist middleware that only allows whitelisted accounts to
 	// deploy contracts & run migrations.
 	DeployerWhitelistFeature = "mw:deploy-wl"

noevm_receipt_writer.go

@@ -8,5 +8,7 @@ import (
 )
 
 type WriteReceiptHandler interface {
-	CacheReceipt(state State, caller, addr loom.Address, events []*types.EventData, err error) ([]byte, error)
+	CacheReceipt(
+		state State, caller, addr loom.Address, events []*types.EventData, err error,
+	) ([]byte, error)
 }

receipt_writer.go

@@ -12,5 +12,7 @@ type WriteReceiptHandler interface {
 	GetEventsFromLogs(
 		logs []*eth_types.Log, blockHeight int64, caller, contract loom.Address, input []byte,
 	) []*types.EventData
-	CacheReceipt(state State, caller, addr loom.Address, events []*types.EventData, err error) ([]byte, error)
+	CacheReceipt(
+		state State, caller, addr loom.Address, events []*types.EventData, err error,
+	) ([]byte, error)
 }

receipts/leveldb/leveldb.go

@@ -52,9 +52,8 @@ func WriteReceipt(
 	}
 	h := sha256.New()
 	h.Write(preTxReceipt)
-	txHash := h.Sum(nil)
+	txReceipt.TxHash = h.Sum(nil)
 
-	txReceipt.TxHash = txHash
 	txReceipt.Logs = append(txReceipt.Logs, CreateEventLogs(&txReceipt, block, events, eventHandler)...)
 	txReceipt.TransactionIndex = block.NumTxs - 1
 	return txReceipt, nil

rpc/query_server.go

@@ -748,6 +748,7 @@ func (s *QueryServer) EthGetTransactionReceipt(hash eth.Data) (*eth.JsonTxReceip
 	r := s.ReceiptHandlerProvider.Reader()
 	txReceipt, err := r.GetReceipt(txHash)
 	if err != nil {
+		// if the receipt is not found, create it from TxObj
 		resp, err := getReceiptByTendermintHash(snapshot, s.BlockStore, r, txHash)
 		if err != nil {
 			if strings.Contains(errors.Cause(err).Error(), "not found") {