Ganache unpredictably drop transactions

[xumy29]

I use "go-ethereum/ethclient" to interact with ganache, for every second, a client will send several transactions (in several threads) to ganache by the API SendTransaction. All the transactions will call the same smart contract. Then I check the log file of ganache, it seems that ganache will drop some of the pending transactions while packing blocks (and never pack them). I have ruled out causes caused by nonce, gasLimit, gasPrice, etc, because I don't get any error as return of the API SendTransaction, neither any error msg in the log file of ganache. Besides, in the log, I see the RPC record of every transaction the client sent. I wonder if this works as expected. If ganache will drop some transactions, what is the criteria ? Is there something concrete I can do to keep the transaction from being dropped? I would be very grateful if someone could help me resolve my confusion.

[xumy29]

ganache.log Here's the log file of ganache. One can find that from block number 11, the number of transactions packed is less than the pending transactions.

[jeffsmale90]

@xumy29 thanks for raising the issue. As far as I can tell, this isn't expected behaviour.

It sounds like it's related to #2489 where a race condition causes Ganache to use the same nonce. This is especially problematic when there's a high load of requests.

Can you please confirm that you are providing the nonce yourself, and that it is correctly incrementing the nonce for each transaction sent?

Are you able to provide a complete reproduction so that I might debug this myself?

Thanks.

[xumy29]

@jeffsmale90 Thanks for your reply. I can't put all my code here since it's a bit much. Here's the simplified code of my program, in which I have 8 accounts and correspondingly, 8 clients and 8 go-routines sending transactions to ganache at intervals. I provide the nonce myself, and use mutex lock to avoid the race condition, and don't see errors about that during executing. So I don't think it's the nonce's matter. My ganache is set to propose a block for every 10 seconds, and the version information is ganache v7.9.0 (@ganache/cli: 0.10.0, @ganache/core: 0.10.0)

var (
    lastNonce map[uint32]uint64 = make(map[uint32]uint64)
    call_lock      sync.Mutex
    lowestGasPrice *big.Int = big.NewInt(0)
        clients []*ethclient.Client
)

func main() {
    for true {
        time.Sleep(3 * time.Second)
        for i := 0; i < 8; i++ {
            go func(id int) {
                CallContract(clients[id], contractAddr, contractABI, data)
            }(i)
        }
    }
}

func CallContract(client *ethclient.Client, contractAddr common.Address, abi *abi.ABI, data MyData) error {
    call_lock.Lock()
    defer call_lock.Unlock()

    callData, err := abi.Pack("myMethod", data)
    if err != nil {
        return err
    }

    // construct signer by private key
    privateKey, err := myPrivateKey(data.ID)
    if err != nil {
        return err
    }
    auth, err := bind.NewKeyedTransactorWithChainID(privateKey, big.NewInt(chainID))
    if err != nil {
        return err
    }

    // set transaction arguments
    auth.GasLimit = uint64(30000000) 
    auth.Value = big.NewInt(0)  

    var nonce uint64
    _, ok := lastNonce[data.ID]
    if !ok {
        nonce, err = client.PendingNonceAt(context.Background(), auth.From)
        if err != nil {
            return err
        }
        lastNonce[data.ID] = nonce
    } else {
        nonce = lastNonce[data.ID] + 1
        lastNonce[data.ID] = nonce
    }

    if lowestGasPrice.Uint64() == 0 {
        gasPrice, err := client.SuggestGasPrice(context.Background())
        if err != nil {
            return err
        }
        lowestGasPrice = gasPrice
    }

    // mustSend：loop until the transaction is successfully sent out
    for true {
        tx := types.NewTransaction(nonce, contractAddr, big.NewInt(0), auth.GasLimit, lowestGasPrice, callData)

        signedTx, err := auth.Signer(auth.From, tx)
        if err != nil {
            return err
        }

        err = client.SendTransaction(context.Background(), signedTx)
        if err != nil {
            if err.Error() != "transaction underpriced" {
                return err
            } else {
                toAdd := new(big.Int).Div(lowestGasPrice, big.NewInt(10))
                lowestGasPrice = new(big.Int).Add(lowestGasPrice, toAdd)
            }
        } else {
            break
        }
    }

    return nil
}

[xumy29]

@jeffsmale90 any idea? I still can't debug it.

[jeffsmale90]

Hey @xumy29 sorry, I've not had a chance to look into this, as I'm working through a significant PR. I'll hopefully get onto this next week.

Thanks!

[xumy29]

It appears to be a bug specific to Ganache, since when I switch to using Geth instead, the issue doesn't arise.

[davidmurdoch]

@xumy29 can you try starting ganache with the flag --chain.asyncRequestProcessing=false and let me know if ganache starts behaving?

[xumy29]

@davidmurdoch still have the same problem, my command is

ganache  --gasLimit 30000000 --gasPrice 20000000000  > ganache.log --chain.asyncRequestProcessing=false --blockTime 10 --verbose --account=0xd12c928f281ed4a05f6dbf434bbbac5706826d9b2e3966077ef580df14073eb3,100000000000000000000000 --account=0x635ccd7f8cb78b293486ee535a8aac38d33b400e4833ed07d39d2841995e0cd6,100000000000000000000000 --account=0x831d55e90f4a55085ccf8a9acf849d9a6ce00f46fb430e47118d23af308e1486,100000000000000000000000 --account=0xd2c42ed9778acdf7f86ce013f5437cfa463f417c0523e5ceaa9e1f8ed48eef5e,100000000000000000000000 --account=0x26ea2b1eebb43a50c0fc5f5451073ec0831f85621765fabad93a61132cb14d21,100000000000000000000000 --account=0x1d41896df03f6971785b1e3927daa4eed3df9113a267d953b10bfd34775a1ef4,100000000000000000000000 --account=0x127ab599973981d4282221e339386b34c15a6b1685e0062ce388afb2ac3f1610,100000000000000000000000 --account=0x0406fd4b37b0fef67a4cd1ca447452a0fbe81ec972e8437c2d278614295d2412,100000000000000000000000 --account=0xa8f1cfa29a4562a35667a51d7cf71239c6d6820130bc7cb52d0c83713d1cad75,100000000000000000000000 --account=0x8174bb5838f5c68db4cd36232e963bcf0a6aff1ec9b21230cd090951564e6262,200000000000000000000000

[davidmurdoch]

@xumy29 is the > ganache.log in the middle of this command a typo?

[xumy29]

@davidmurdoch No, this means that the log output will be redirected to the file "genesis.log".

[davidmurdoch]

Got it; it's strange to see the redirect in the middle of a command like that (I didn't even realize that works). I'm not sure what's going on here. Seems like a bug in Ganache.