fix(mempool/tests): Reduce tests duration (cometbft#2263)

- Do not print the whole transaction in log messages. In particular, `TestMempool_CheckTxChecksTxSize` sometimes timeouts because it logs the whole transaction, which can be huge in this test. - Decrease the timeouts of some tests that are unnecessarily high. - Remove verbose or redundant debug log messages. --- #### PR checklist - [ ] Tests written/updated - [ ] Changelog entry added in `.changelog` (we use [unclog](https://github.com/informalsystems/unclog) to manage our changelog) - [ ] Updated relevant documentation (`docs/` or `spec/`) and code comments - [ ] Title follows the [Conventional Commits](https://www.conventionalcommits.org/en/v1.0.0/) spec
fabiotudone-da · Feb 8, 2024 · 858ac4e · 858ac4e
1 parent 89dea4c
commit 858ac4e
Show file tree

Hide file tree

Showing 3 changed files with 10 additions and 13 deletions.
diff --git a/mempool/clist_mempool.go b/mempool/clist_mempool.go
@@ -250,10 +250,8 @@ func (mem *CListMempool) TxsWaitChan() <-chan struct{} {
 // Safe for concurrent use by multiple goroutines.
 func (mem *CListMempool) CheckTx(tx types.Tx) (*abcicli.ReqRes, error) {
 	mem.updateMtx.RLock()
-	mem.logger.Debug("Locked updateMtx for read", "tx", tx)
 	// use defer to unlock mutex because application (*local client*) might panic
 	defer mem.updateMtx.RUnlock()
-	defer mem.logger.Debug("Released updateMtx for read", "tx", tx)
 
 	txSize := len(tx)
 
@@ -280,14 +278,14 @@ func (mem *CListMempool) CheckTx(tx types.Tx) (*abcicli.ReqRes, error) {
 	}
 
 	if added := mem.addToCache(tx); !added {
-		mem.logger.Debug("Not cached", "tx", tx)
+		mem.logger.Debug("Not cached", "tx", tx.Hash())
 		mem.metrics.AlreadyReceivedTxs.Add(1)
 		// TODO: consider punishing peer for dups,
 		// its non-trivial since invalid txs can become valid,
 		// but they can spam the same tx with little cost to them atm.
 		return nil, ErrTxInCache
 	}
-	mem.logger.Debug("Cached", "tx", tx)
+	mem.logger.Debug("Cached", "tx", tx.Hash())
 
 	reqRes, err := mem.proxyAppConn.CheckTxAsync(context.TODO(), &abci.CheckTxRequest{
 		Tx:   tx,
@@ -341,7 +339,6 @@ func (mem *CListMempool) addTx(memTx *mempoolTx) {
 	mem.txsMap.Store(memTx.tx.Key(), e)
 	mem.txsBytes.Add(int64(len(memTx.tx)))
 	mem.metrics.TxSizeBytes.Observe(float64(len(memTx.tx)))
-	mem.logger.Debug("Clisted", "tx", memTx.tx)
 }
 
 // RemoveTxByKey removes a transaction from the mempool by its TxKey index.
@@ -453,7 +450,7 @@ func (mem *CListMempool) resCbFirstTime(
 func (mem *CListMempool) resCbRecheck(req *abci.Request, res *abci.Response) {
 	switch r := res.Value.(type) {
 	case *abci.Response_CheckTx:
-		tx := req.GetCheckTx().Tx
+		tx := types.Tx(req.GetCheckTx().Tx)
 		memTx := mem.recheckCursor.Value.(*mempoolTx)
 
 		// Search through the remaining list of tx to recheck for a transaction that matches
@@ -468,8 +465,8 @@ func (mem *CListMempool) resCbRecheck(req *abci.Request, res *abci.Response) {
 
 			mem.logger.Error(
 				"re-CheckTx transaction mismatch",
-				"got", types.Tx(tx),
-				"expected", memTx.tx,
+				"got", tx.Hash(),
+				"expected", memTx.tx.Hash(),
 			)
 
 			if mem.recheckCursor == mem.recheckEnd {
@@ -491,7 +488,7 @@ func (mem *CListMempool) resCbRecheck(req *abci.Request, res *abci.Response) {
 
 		if (r.CheckTx.Code != abci.CodeTypeOK) || postCheckErr != nil {
 			// Tx became invalidated due to newly committed block.
-			mem.logger.Debug("tx is no longer valid", "tx", types.Tx(tx).Hash(), "res", r, "err", postCheckErr)
+			mem.logger.Debug("tx is no longer valid", "tx", tx.Hash(), "res", r, "err", postCheckErr)
 			if err := mem.RemoveTxByKey(memTx.tx.Key()); err != nil {
 				mem.logger.Debug("Transaction could not be removed from mempool", "err", err)
 			}

diff --git a/mempool/clist_mempool_test.go b/mempool/clist_mempool_test.go
@@ -82,7 +82,7 @@ func newMempoolWithAppAndConfig(cc proxy.ClientCreator, cfg *config.Config) (*CL
 
 func ensureNoFire(t *testing.T, ch <-chan struct{}) {
 	t.Helper()
-	timer := time.NewTimer(time.Duration(500) * time.Millisecond)
+	timer := time.NewTimer(100 * time.Millisecond)
 	select {
 	case <-ch:
 		t.Fatal("Expected not to fire")
@@ -374,7 +374,7 @@ func TestTxsAvailable(t *testing.T) {
 	defer cleanup()
 	mp.EnableTxsAvailable()
 
-	timeoutMS := 500
+	timeoutMS := 100
 
 	// with no txs, it shouldn't fire
 	ensureNoFire(t, mp.TxsAvailable())

diff --git a/mempool/reactor.go b/mempool/reactor.go
@@ -166,9 +166,9 @@ func (memR *Reactor) Receive(e p2p.Envelope) {
 			reqRes, err := memR.mempool.CheckTx(tx)
 			switch {
 			case errors.Is(err, ErrTxInCache):
-				memR.Logger.Debug("Tx already exists in cache", "tx", tx.String())
+				memR.Logger.Debug("Tx already exists in cache", "tx", tx.Hash())
 			case err != nil:
-				memR.Logger.Info("Could not check tx", "tx", tx.String(), "err", err)
+				memR.Logger.Info("Could not check tx", "tx", tx.Hash(), "err", err)
 			default:
 				// Record the sender only when the transaction is valid and, as
 				// a consequence, added to the mempool. Senders are stored until