vochain: order transactions when creating new blocks (#1121)

refactor Vocdoni's Interaction with CometBFT

1. Implement transaction ordering during block creation.
2. Ensure blocks do not store invalid transactions.
3. Introduce mempool TTL mechanism and max attempts protection.
4. Implement Optimistic Execution for validators.
5. Resolve an app hash bug during block construction.

**Transaction Ordering**
  - Transactions are sorted by nonce for the same sender during the "Prepare proposal" phase of CometBFT callbacks.
  
**Block Transaction Validation**
  - A temporary state is constructed to execute proposal transactions, leading to hard-checks against this state. This eliminates the need for the previous soft-check approach.
  - `ProcessProposal` will return REJECT if any transaction in the block proposal is invalid.

**Mempool Enhancements**
  - Transactions will be removed from the mempool after a set duration (TTL).
  - After three unsuccessful attempts to include a transaction in a block, it will be removed from the mempool.

**Optimistic Execution**
  - If a block is executed during `ProcessProposal` by a validator and is accepted, its state is retained and not rolled back.
  - During `FinalizeBlock`, the system checks if the block was previously executed. If it was, there's no need for re-execution, potentially speeding up block production.

**Block Construction Bug**
  - An issue was identified where the app hash reported by `FinalizeBlock` was incorrectly computed.
  - Due to the new CometBFT callback structure, block execution and hash return are separated from saving to persistent storage.
  - The previous `State.Save()` was incompatible with this two-step process. It has been modified to now include `PrepareCommit()` and `Commit()` functions.

---

Signed-off-by: p4u <[email protected]>

Author: p4u

apiclient/account.go

@@ -69,18 +69,26 @@ func (c *HTTPclient) Account(address string) (*api.Account, error) {
 }
 
 // Transfer sends tokens from the account associated with the client to the given address.
+// The nonce is automatically calculated from the account information.
 // Returns the transaction hash.
 func (c *HTTPclient) Transfer(to common.Address, amount uint64) (types.HexBytes, error) {
 	acc, err := c.Account("")
 	if err != nil {
 		return nil, err
 	}
+	return c.TransferWithNonce(to, amount, acc.Nonce)
+}
+
+// TransferWithNonce sends tokens from the account associated with the client to the given address.
+// Returns the transaction hash.
+func (c *HTTPclient) TransferWithNonce(to common.Address, amount uint64, nonce uint32) (types.HexBytes, error) {
+	var err error
 	stx := models.SignedTx{}
 	stx.Tx, err = proto.Marshal(&models.Tx{
 		Payload: &models.Tx_SendTokens{
 			SendTokens: &models.SendTokensTx{
 				Txtype: models.TxType_SET_ACCOUNT_INFO_URI,
-				Nonce:  acc.Nonce,
+				Nonce:  nonce,
 				From:   c.account.Address().Bytes(),
 				To:     to.Bytes(),
 				Value:  amount,

cmd/end2endtest/account.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"os"
 	"strings"
+	"sync"
 	"time"
 
 	"github.com/ethereum/go-ethereum/common"
@@ -150,6 +151,8 @@ func testSendTokens(api *apiclient.HTTPclient, aliceKeys, bobKeys *ethereum.Sign
 	// both pay 2 for each tx
 	// resulting in balance 52 for alice
 	// and 44 for bob
+	// In addition, we send a couple of token txs to burn address to increase the nonce,
+	// without waiting for them to be mined (this tests that the mempool transactions are properly ordered).
 
 	txCost, err := api.TransactionCost(models.TxType_SEND_TOKENS)
 	if err != nil {
@@ -181,23 +184,47 @@ func testSendTokens(api *apiclient.HTTPclient, aliceKeys, bobKeys *ethereum.Sign
 	// try to send tokens at the same time:
 	// alice sends 1/4 of her balance to bob
 	// sends 1/3 of his balance to alice
-	amountAtoB := aliceAcc.Balance / 4
-	amountBtoA := bobAcc.Balance / 3
-
-	txhasha, err := alice.Transfer(bobKeys.Address(), amountAtoB)
-	if err != nil {
-		return fmt.Errorf("cannot send tokens: %v", err)
-	}
-	log.Infof("alice sent %d tokens to bob", amountAtoB)
-	log.Debugf("tx hash is %x", txhasha)
+	// Subtract 1 + txCost from each since we are sending an extra tx to increase the nonce to the burn address
+	amountAtoB := (aliceAcc.Balance) / 4
+	amountBtoA := (bobAcc.Balance) / 3
+
+	// send a couple of token txs to increase the nonce, without waiting for them to be mined
+	// this tests that the mempool transactions are properly ordered.
+	wg := sync.WaitGroup{}
+	wg.Add(1)
+	go func() {
+		log.Warnf("send transactions with nonce+1, should not be mined before the others")
+		// send 1 token to burn address with nonce + 1 (should be mined after the other txs)
+		if _, err = alice.TransferWithNonce(state.BurnAddress, 1, aliceAcc.Nonce+1); err != nil {
+			log.Fatalf("cannot burn tokens: %v", err)
+		}
+		if _, err = bob.TransferWithNonce(state.BurnAddress, 1, bobAcc.Nonce+1); err != nil {
+			log.Fatalf("cannot burn tokens: %v", err)
+		}
+		wg.Done()
+	}()
+	log.Warnf("waiting 6 seconds to let the burn txs be sent")
+	time.Sleep(6 * time.Second)
+	var txhasha, txhashb []byte
+	wg.Add(1)
+	go func() {
+		txhasha, err = alice.TransferWithNonce(bobKeys.Address(), amountAtoB, aliceAcc.Nonce)
+		if err != nil {
+			log.Fatalf("cannot send tokens: %v", err)
+		}
+		log.Infof("alice sent %d tokens to bob", amountAtoB)
+		log.Debugf("tx hash is %x", txhasha)
 
-	txhashb, err := bob.Transfer(aliceKeys.Address(), amountBtoA)
-	if err != nil {
-		return fmt.Errorf("cannot send tokens: %v", err)
-	}
-	log.Infof("bob sent %d tokens to alice", amountBtoA)
-	log.Debugf("tx hash is %x", txhashb)
+		txhashb, err = bob.TransferWithNonce(aliceKeys.Address(), amountBtoA, bobAcc.Nonce)
+		if err != nil {
+			log.Fatalf("cannot send tokens: %v", err)
+		}
+		log.Infof("bob sent %d tokens to alice", amountBtoA)
+		log.Debugf("tx hash is %x", txhashb)
+		wg.Done()
+	}()
 
+	wg.Wait()
 	ctx, cancel := context.WithTimeout(context.Background(), time.Second*40)
 	defer cancel()
 	txrefa, err := api.WaitUntilTxIsMined(ctx, txhasha)
@@ -216,12 +243,12 @@ func testSendTokens(api *apiclient.HTTPclient, aliceKeys, bobKeys *ethereum.Sign
 	_ = api.WaitUntilNextBlock()
 
 	// now check the resulting state
-	if err := checkAccountNonceAndBalance(alice, aliceAcc.Nonce+1,
-		aliceAcc.Balance-amountAtoB-txCost+amountBtoA); err != nil {
+	if err := checkAccountNonceAndBalance(alice, aliceAcc.Nonce+2,
+		aliceAcc.Balance-amountAtoB-(2*txCost+1)+amountBtoA); err != nil {
 		return err
 	}
-	if err := checkAccountNonceAndBalance(bob, bobAcc.Nonce+1,
-		bobAcc.Balance-amountBtoA-txCost+amountAtoB); err != nil {
+	if err := checkAccountNonceAndBalance(bob, bobAcc.Nonce+2,
+		bobAcc.Balance-amountBtoA-(2*txCost+1)+amountAtoB); err != nil {
 		return err
 	}
 

cmd/end2endtest/helpers.go

@@ -186,6 +186,10 @@ func (t *e2eElection) generateProofs(csp *ethereum.SignKeys, voterAccts []*ether
 		wg     sync.WaitGroup
 		vcount int32
 	)
+	// Wait for the next block to assure the SIK root is updated
+	if err := t.api.WaitUntilNextBlock(); err != nil {
+		return err
+	}
 	errorChan := make(chan error)
 	t.voters = new(sync.Map)
 	addNaccounts := func(accounts []*ethereum.SignKeys) {

cmd/node/main.go

@@ -1,6 +1,7 @@
 package main
 
 import (
+	"encoding/hex"
 	"fmt"
 	"io"
 	"net"
@@ -174,13 +175,29 @@ func newConfig() (*config.Config, config.Error) {
 	viper.SetEnvKeyReplacer(strings.NewReplacer(".", "_"))
 
 	// set FlagVars first
-	viper.BindPFlag("dataDir", flag.Lookup("dataDir"))
+	if err = viper.BindPFlag("dataDir", flag.Lookup("dataDir")); err != nil {
+		log.Fatalf("failed to bind dataDir flag to viper: %v", err)
+	}
 	globalCfg.DataDir = viper.GetString("dataDir")
-	viper.BindPFlag("chain", flag.Lookup("chain"))
+
+	if err = viper.BindPFlag("chain", flag.Lookup("chain")); err != nil {
+		log.Fatalf("failed to bind chain flag to viper: %v", err)
+	}
 	globalCfg.Vochain.Chain = viper.GetString("chain")
-	viper.BindPFlag("dev", flag.Lookup("dev"))
+
+	if err = viper.BindPFlag("dev", flag.Lookup("dev")); err != nil {
+		log.Fatalf("failed to bind dev flag to viper: %v", err)
+	}
 	globalCfg.Dev = viper.GetBool("dev")
-	viper.BindPFlag("pprofPort", flag.Lookup("pprof"))
+
+	if err = viper.BindPFlag("pprofPort", flag.Lookup("pprof")); err != nil {
+		log.Fatalf("failed to bind pprof flag to viper: %v", err)
+	}
+
+	if err = viper.BindPFlag("dbType", flag.Lookup("dbType")); err != nil {
+		log.Fatalf("failed to bind dbType flag to viper: %v", err)
+	}
+	globalCfg.Vochain.DBType = viper.GetString("dbType")
 
 	// use different datadirs for different chains
 	globalCfg.DataDir = filepath.Join(globalCfg.DataDir, globalCfg.Vochain.Chain)
@@ -267,7 +284,7 @@ func newConfig() (*config.Config, config.Error) {
 		}
 	}
 
-	if len(globalCfg.SigningKey) < 32 {
+	if globalCfg.SigningKey == "" {
 		fmt.Println("no signing key, generating one...")
 		signer := ethereum.NewSignKeys()
 		err = signer.Generate()
@@ -283,6 +300,10 @@ func newConfig() (*config.Config, config.Error) {
 		globalCfg.SaveConfig = true
 	}
 
+	if globalCfg.Vochain.MinerKey == "" {
+		globalCfg.Vochain.MinerKey = globalCfg.SigningKey
+	}
+
 	if globalCfg.SaveConfig {
 		viper.Set("saveConfig", false)
 		if err := viper.WriteConfig(); err != nil {
@@ -381,7 +402,8 @@ func main() {
 			log.Error(http.Serve(ln, nil))
 		}()
 	}
-	log.Infow("starting vocdoni node", "version", internal.Version, "mode", globalCfg.Mode)
+	log.Infow("starting vocdoni node", "version", internal.Version, "mode", globalCfg.Mode,
+		"chain", globalCfg.Vochain.Chain, "dbType", globalCfg.Vochain.DBType)
 	if globalCfg.Dev {
 		log.Warn("developer mode is enabled!")
 	}
@@ -497,9 +519,7 @@ func main() {
 		if err != nil {
 			log.Fatal(err)
 		}
-		if validator == nil {
-			log.Warnw("node is not a validator", "address", signer.Address().Hex())
-		} else {
+		if validator != nil {
 			// start keykeeper service (if key index specified)
 			if validator.KeyIndex > 0 {
 				srv.KeyKeeper, err = keykeeper.NewKeyKeeper(
@@ -511,12 +531,10 @@ func main() {
 					log.Fatal(err)
 				}
 				go srv.KeyKeeper.RevealUnpublished()
-			} else {
-				log.Warnw("validator keyIndex disabled")
+				log.Infow("configured keykeeper validator",
+					"address", signer.Address().Hex(),
+					"keyIndex", validator.KeyIndex)
 			}
-			log.Infow("configured vochain validator",
-				"address", signer.Address().Hex(),
-				"keyIndex", validator.KeyIndex)
 		}
 	}
 
@@ -571,6 +589,17 @@ func main() {
 	signal.Notify(c, os.Interrupt, syscall.SIGTERM)
 	<-c
 	log.Warnf("received SIGTERM, exiting at %s", time.Now().Format(time.RFC850))
+	height, err := srv.App.State.LastHeight()
+	if err != nil {
+		log.Warn(err)
+	}
+	hash, err := srv.App.State.MainTreeView().Root()
+	if err != nil {
+		log.Warn(err)
+	}
+	tmBlock := srv.App.GetBlockByHeight(int64(height))
+	log.Infow("last block", "height", height, "appHash", hex.EncodeToString(hash),
+		"time", tmBlock.Time, "tmAppHash", tmBlock.AppHash.String(), "tmHeight", tmBlock.Height)
 	os.Exit(0)
 }
 

dockerfiles/testsuite/env.gateway0

@@ -10,4 +10,4 @@ VOCDONI_VOCHAIN_NOWAITSYNC=True
 VOCDONI_METRICS_ENABLED=True
 VOCDONI_METRICS_REFRESHINTERVAL=5
 VOCDONI_CHAIN=dev
-VOCDONI_SIGNINGKEY=e0f1412b86d6ca9f2b318f1d243ef50be23d315a2e6c1c3035bc72d44c8b2f90
+VOCDONI_SIGNINGKEY=e0f1412b86d6ca9f2b318f1d243ef50be23d315a2e6c1c3035bc72d44c8b2f90 # 0x88a499cEf9D1330111b41360173967c9C1bf703f

dockerfiles/testsuite/env.seed

@@ -1,9 +1,9 @@
 VOCDONI_DATADIR=/app/run
 VOCDONI_MODE=seed
-VOCDONI_LOGLEVEL=info
+VOCDONI_LOGLEVEL=debug
 VOCDONI_DEV=True
 VOCDONI_VOCHAIN_PUBLICADDR=seed:26656
-VOCDONI_VOCHAIN_LOGLEVEL=debug
+VOCDONI_VOCHAIN_LOGLEVEL=info
 VOCDONI_VOCHAIN_GENESIS=/app/misc/genesis.json
 VOCDONI_VOCHAIN_NODEKEY=0x2060e20d1f0894d6b23901bce3f20f26107baf0335451ad75ef27b14e4fc56ae050a65ae3883c379b70d811d6e12db2fe1e3a5cf0cae4d03dbbbfebc68601bdd
 VOCDONI_METRICS_ENABLED=True

dockerfiles/testsuite/genesis.json

@@ -57,20 +57,8 @@
     ],
     "accounts":[
         {
-           "address":"0xccEc2c2D658261Fbdc40b04FEc06d49057242D39",
-           "balance":10000000
-         },
-         {
-           "address":"0x776d858D17C8018F07899dB535866EBf805a32E0",
-           "balance":10000000
-         },
-         {
-           "address":"0x074fcAacb8B01850539eaE7E9fEE8dc94549db96",
-           "balance":10000000
-         },
-	       {
            "address":"0x88a499cEf9D1330111b41360173967c9C1bf703f",
-           "balance":10000000
+           "balance":1000000000000
          }	
       ],
     "treasurer": "0xfe10DAB06D636647f4E40dFd56599da9eF66Db1c",

log/log.go

@@ -7,6 +7,7 @@ import (
 	"os"
 	"path"
 	"runtime/debug"
+	"strings"
 	"time"
 
 	"github.com/rs/zerolog"
@@ -89,11 +90,9 @@ func (*invalidCharChecker) Write(p []byte) (int, error) {
 	return len(p), nil
 }
 
-// Init initializes the logger. Output can be either "stdout/stderr/<filePath>".
-// Log level can be "debug/info/warn/error".
-// errorOutput is an optional filename which only receives Warning and Error messages.
 func Init(level, output string, errorOutput io.Writer) {
 	var out io.Writer
+	outputs := []io.Writer{}
 	switch output {
 	case "stdout":
 		out = os.Stdout
@@ -107,12 +106,16 @@ func Init(level, output string, errorOutput io.Writer) {
 			panic(fmt.Sprintf("cannot create log output: %v", err))
 		}
 		out = f
+		if strings.HasSuffix(output, ".json") {
+			outputs = append(outputs, f)
+			out = os.Stdout
+		}
 	}
 	out = zerolog.ConsoleWriter{
 		Out:        out,
 		TimeFormat: time.RFC3339Nano,
 	}
-	outputs := []io.Writer{out}
+	outputs = append(outputs, out)
 
 	if errorOutput != nil {
 		outputs = append(outputs, &errorLevelWriter{zerolog.ConsoleWriter{

statedb/treeupdate.go

@@ -150,33 +150,13 @@ func (u *TreeUpdate) SubTree(cfg TreeConfig) (treeUpdate *TreeUpdate, err error)
 	if treeUpdate, ok := u.openSubs.Load(cfg.prefix); ok {
 		return treeUpdate.(*TreeUpdate), nil
 	}
-	parentLeaf, err := u.tree.Get(u.tree.tx, cfg.parentLeafKey)
-	if err != nil {
-		return nil, err
-	}
-	root, err := cfg.parentLeafGetRoot(parentLeaf)
-	if err != nil {
-		return nil, err
-	}
 	tx := subWriteTx(u.tx, path.Join(subKeySubTree, cfg.prefix))
 	txTree := subWriteTx(tx, subKeyTree)
 	tree, err := tree.New(txTree,
 		tree.Options{DB: nil, MaxLevels: cfg.maxLevels, HashFunc: cfg.hashFunc})
 	if err != nil {
 		return nil, err
 	}
-	lastRoot, err := tree.Root(txTree)
-	if err != nil {
-		return nil, err
-	}
-	if !bytes.Equal(root, lastRoot) {
-		panic(fmt.Sprintf("root for %s mismatch: %x != %x", cfg.kindID, root, lastRoot))
-		// Note (Pau): since we modified arbo to remove all unecessary intermediate nodes,
-		// we cannot set a past root.We should probably remove this code.
-		//if err := tree.SetRoot(txTree, root); err != nil {
-		//	return nil, err
-		//}
-	}
 	treeUpdate = &TreeUpdate{
 		tx: tx,
 		tree: treeWithTx{
@@ -331,6 +311,15 @@ func propagateRoot(treeUpdate *TreeUpdate) ([]byte, error) {
 // version numbers, but overwriting an existing version can be useful in some
 // cases (for example, overwriting version 0 to setup a genesis state).
 func (t *TreeTx) Commit(version uint32) error {
+	if err := t.CommitOnTx(version); err != nil {
+		return err
+	}
+	return t.tx.Commit()
+}
+
+// CommitOnTx do as Commit but without committing the transaction to database.
+// After CommitOnTx(), caller should call SaveWithoutCommit() to commit the transaction.
+func (t *TreeTx) CommitOnTx(version uint32) error {
 	root, err := propagateRoot(&t.TreeUpdate)
 	if err != nil {
 		return fmt.Errorf("could not propagate root: %w", err)
@@ -350,7 +339,7 @@ func (t *TreeTx) Commit(version uint32) error {
 	if err := setVersionRoot(t.tx, version, root); err != nil {
 		return fmt.Errorf("could not set version root: %w", err)
 	}
-	return t.tx.Commit()
+	return nil
 }
 
 // Discard all the changes that have been made from the TreeTx.  After calling