Go-ethereum: core: duplicate nonce assignment (eth_sendTransaction)

[wildbunny]

eth_sendTransaction will sometimes return a hash, but then the transaction never makes it into a block.

[tgerring]

This can happen if the transaction is mined in a block whose chain does not become part of the main chain, just as with Bitcoin.

Can you provide some extra information, or perhaps an example transaction?

[wildbunny]

In bitcoin that only happens with a double spend. This happened with a regular transaction. I can give you a transaction hash, but the transaction itself is unrecoverable.

[obscuren]

Were you sending a lot transactions in one go?

[wildbunny]

Yes, three in quick succession - I should have mentioned that, sorry.

[obscuren]

Thank you. Yes, I'm aware of this issue. It will be fixed in 1.0.2

[wildbunny]

Glad to hear that :)

[obscuren]

As more people run in to this issue I suggest - as a temporary solution - that you rate limit your transaction until 1.0.2 is deployed.

[wildbunny]

Did I understand this is to do with identical nonce values on quickly submitted transactions? If so, can we submit a different nonce and be ok for fast successive transactions?

[obscuren]

@wildbunny That's correct and yes that'd work

[wildbunny]

Great - that's easy enough, I can just hash the parameters to sendTransaction and stick that in the nonce :)

[wildbunny]

@obscuren I've just had this happen to me again, 3 transactions sent with 1 second between them, this time each transaction had a different nonce and _none_ of them made it into the blockchain, yet sendTransaction returned a hash for each one.

[obscuren]

sendTransaction will always return a hash regardless of making it in to the chain. You simple cannot know in advance if a tx will or will not make it in to the chain (only a best guess). Did you supply a nonce yourself?

[wildbunny]

I supplied a different nonce myself for each transaction. IMO if geth returns a TXID it must do its best to auto resubmit the transaction into the chain should it not get included, as bitcoind and all other wallets do.

[obscuren]

IMO if geth returns a TXID it must do its best to auto resubmit the transaction into the chain should it not get included, as bitcoind and all other wallets do.

See https://github.com/ethereum/go-ethereum/pull/1669

The nonces you've supplied are you sure they were correct? Are you aware how Ethereum handles transaction nonces? The first transaction you're sending in your sequence must be exactly the same as eth.getTransactionCount(address) and all following transaction must have a subsequent number

[wildbunny]

Oh wow, ok. That's my bad, then. I had assumed nonces just needed to be unique, so I was using a hash of transaction details. Will I be safe to just call eth.getTransactionCount(address) and stuff that into the nonce for each transaction?

[obscuren]

I'd suggest you do something like this:

// recipients is an array of objects like [ {to: ...., value ....} ]
function batchTx(sender, recipients) {
    var nonce = eth.getTransactionCount(sender);
    for( var i = 0; i < recipients.length; i++ ) {
        eth.sendTransaction({from:sender, to:recipients[i].to, value:recipients[i].value, nonce:nonce+i});
    }
}

There's already a fix in on the develop branch (CAUTION: develop is considered unstable).

[wildbunny]

Ok, thanks I will try to follow this workaround :)

[wildbunny]

...as a side note, is it possible to have sendTransaction() fail when you give it a nonce it can't possibly accept?

[obscuren]

No; that's actually a few feature. This will allow you to queue up transactions by sending N+1 and finalise them with N :)

[sillytuna]

There is no guarantee of the queued transactions being accepted into blocks in that order though, correct? However, it'll allow transaction queueing at a node if I've understood correctly.

[jorisbontje]

With both geth 1.1.2 (stable) and 1.1.0-edaea698 (development) on a local test network with a single miner I am frequently seeing cases where transactions have the same nonce, resulting in the 2nd transaction to completely disappear. This suggests that this bug is not fixed on develop.

[fjl]

Sent transactions are queued locally until they are included in a block.
The order is defined by the nonce.

[fjl]

@jorisbontje we'll look into it

[jorisbontje]

to reproduce (run via web3, not via geth console):

var accounts = web3.eth.accounts;
for(var i = 0; i < accounts.length; i++) {
  var to = accounts[i % accounts.length];
  var tx = web3.eth.sendTransaction({from: accounts[0], to: to});
  var txData = web3.eth.getTransaction(tx);
  console.log(to, 'tx', tx, 'nonce', txData.nonce);
}

output:

tx 0x09d1d3e4df452a3246c0e80237ccdb1d1f8077db6989ce754af12a00d41179af nonce 950
tx 0xd5d93ef58d30f08c59bb6e3ffbde4b2934676265611c5214546f88da2b47615f nonce 951
tx 0x7c7212d1ab0ea307ce562f2632caf94983b268829d0dd82c8f765e1fd76140f1 nonce 952
tx 0xf94da86d0fb263dbb8b84d47c062f94ce3ef7d0e09fc0bb7dddf5ff3fd92640e nonce 953
tx 0x06199da9a0ac8c7bebe118a6461cfe88a4e5dd6db303f0356ab08eff3d525938 nonce 954
tx 0xf1b3891bc87ef7998764a895f8bb161c6436660f0526909d935544774b7cff94 nonce 954
tx 0x9af7f65a867d03758d264ef2c8d9800e43760945d52bbbcb7467ee98d2a9ad55 nonce 955
tx 0xb3805743376f5cf91efea8c1571ee510b7b4a9d5d1f8a3d63adb5387c19f7009 nonce 956
tx 0x4381a5b48b72132da5150ee4c66b6c9f7bf65aaadcec76689277ec984f70f463 nonce 957
tx 0xf943a317950222fea68aed68fbf25cff0b5847e70b64b60ebb500b3e9cdddd36 nonce 958

note that the nonce 954 appears twice in the output

[jorisbontje]

@fjl some more info to hopefully help pin this down!

As a test, we are sending 10 transactions to ourself in rapid succession, using the following test code.
Note that we are doing this through the rpc using web3, as through the geth console we didn't see this happen.

var accounts = web3.eth.accounts;
for(var i = 0; i < 10; i++) {
  var to = accounts[0];
  var tx = web3.eth.sendTransaction({from: accounts[0], to: to});
  var txData = web3.eth.getTransaction(tx);
  console.log(i+1, 'tx', tx, 'nonce', txData.nonce);
}

Shortened Output:

1 tx 0xe2f8073b0aa5dacf29befd6ed0e8deeb1cc5ff0b365e8bde1abfea0888e8408b nonce 63
2 tx 0x2c243930150f8ca9e8562457275c854b67ffa02f1f05b49af4de17b47459f1ea nonce 64
3 tx 0xfc021d03cf0f05b61d175ac39730a91b9ca37d9396bf504f27a37dbd847c7894 nonce 65
4 tx 0xbb50c06b99af53c7ab0206a1ea93e1e81e2f7b758f760eba84ef14caed73e2f5 nonce 66
5 tx 0x0fe598025c2591153800367d1aeb37e7c9f013c3415f1b9f6c103732e53ef75d nonce 67
6 tx 0x06bdd900cf8010391ba0cdb7903ff02175ba41b3a6ac94ec8551176bd75890ab nonce 68
7 tx 0x0be289d595c1c39056a9e648c40199d49910a6552eb939fc9f8e04da23996ff2 nonce 69
8 tx 0x26e552c1afd2f5dc1c2bffbcd393ee282b72d204615aa15077f1e88a6980d617 nonce 69
9 tx 0x83b1da808e4e7cb9c3ceed21972e944797453fa1d7bc3960c806dc995dd1ea72 nonce 70
10 tx 0x6f03aaea07e41678a70ce2fb7c506c129d09b0d8c713572543498e50e73478e9 nonce 71

geth is solo mining on a local development chain on version Geth/v1.1.0-90f1fe0e/darwin/go1.5
Geth is started as following:

geth --datadir="/tmp/embark" --logfile="/tmp/embark.log" --port 30304 --rpc --rpcport 8101 \
--rpcaddr localhost --networkid 52790 --rpccorsdomain "*" --minerthreads "1" --mine \
--genesis="config/genesis/dev_genesis.json" --rpcapi "eth,web3" --maxpeers 4 \
--password config/password --unlock eef6459e871cb640179e191205d7b19402d7d775

Now looking at core/transaction_pool.go there are two places where the nonce is adjusted (SetNonce):

1) within resetState https://github.com/ethereum/go-ethereum/blob/90f1fe0ed2399f90f01c09e61e244121ef7d148a/core/transaction_pool.go#L125
2) within addTx https://github.com/ethereum/go-ethereum/blob/90f1fe0ed2399f90f01c09e61e244121ef7d148a/core/transaction_pool.go#L263

resetState is called within the eventLoop once a ChainHeadEvent event is occurs (when a new block is found).
https://github.com/ethereum/go-ethereum/blob/90f1fe0ed2399f90f01c09e61e244121ef7d148a/core/transaction_pool.go#L99-L100

This seems to be exactly the behaviour we see below in the geth mining output, where between the 7th and 8th transaction a new block is found.
The nonce reuse happens; between 0x0be289d595c1c39056a9e648c40199d49910a6552eb939fc9f8e04da23996ff2 and 0x26e552c1afd2f5dc1c2bffbcd393ee282b72d204615aa15077f1e88a6980d617.

I0910 10:09:37.682744    4338 worker.go:540] commit new work on block 108 with 0 txs & 0 uncles. Took 326.386µs
I0910 10:09:38.889983    4338 xeth.go:987] Tx(0xe2f8073b0aa5dacf29befd6ed0e8deeb1cc5ff0b365e8bde1abfea0888e8408b) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:39.027092    4338 xeth.go:987] Tx(0x2c243930150f8ca9e8562457275c854b67ffa02f1f05b49af4de17b47459f1ea) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:39.155898    4338 xeth.go:987] Tx(0xfc021d03cf0f05b61d175ac39730a91b9ca37d9396bf504f27a37dbd847c7894) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:39.287562    4338 xeth.go:987] Tx(0xbb50c06b99af53c7ab0206a1ea93e1e81e2f7b758f760eba84ef14caed73e2f5) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:39.416264    4338 xeth.go:987] Tx(0x0fe598025c2591153800367d1aeb37e7c9f013c3415f1b9f6c103732e53ef75d) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:39.542605    4338 xeth.go:987] Tx(0x06bdd900cf8010391ba0cdb7903ff02175ba41b3a6ac94ec8551176bd75890ab) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:39.688290    4338 xeth.go:987] Tx(0x0be289d595c1c39056a9e648c40199d49910a6552eb939fc9f8e04da23996ff2) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:39.777104    4338 worker.go:322] 🔨  Mined block (#108 / 16d597e6). Wait 5 blocks for confirmation
I0910 10:09:39.778457    4338 worker.go:540] commit new work on block 109 with 7 txs & 0 uncles. Took 1.319444ms
I0910 10:09:39.778518    4338 worker.go:420] 🔨 🔗  Mined 5 blocks back: block #103
I0910 10:09:39.779695    4338 worker.go:540] commit new work on block 109 with 7 txs & 0 uncles. Took 1.12613ms
I0910 10:09:39.828435    4338 xeth.go:987] Tx(0x26e552c1afd2f5dc1c2bffbcd393ee282b72d204615aa15077f1e88a6980d617) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:39.966004    4338 xeth.go:987] Tx(0x83b1da808e4e7cb9c3ceed21972e944797453fa1d7bc3960c806dc995dd1ea72) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:40.102876    4338 xeth.go:987] Tx(0x6f03aaea07e41678a70ce2fb7c506c129d09b0d8c713572543498e50e73478e9) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:09:41.485080    4338 worker.go:322] 🔨  Mined block (#109 / 6dfbbf57). Wait 5 blocks for confirmation

Another test run to confirm this:

1 'tx' '0xdf3860558375dc3289a7b247ce4c6695ccb0fb82be1569847043319f36c3a00b' 'nonce' 72
2 'tx' '0x4232c160ce4d091bfe10b0d2ca048d557c086435c13ecad23de2e6837c1884da' 'nonce' 73
3 'tx' '0x99f0e52aac80253e78cf930035122ba553a981e12564fc1e8a52f2510b31ecef' 'nonce' 73
4 'tx' '0xd30de73803df20dc6d441456514468b3fd4ff8e11406ba79f091c65f7a03aa04' 'nonce' 74
5 'tx' '0x8fcfa48d9beb968a42b42232a991d502032d63b7d9b09b55b4aa867015d2a6bb' 'nonce' 75
6 'tx' '0x81f142794cfff1b12dd6bacfc2b9cb130afaf4d7f9825525403f2626495850ef' 'nonce' 75
7 'tx' '0xda389a9bd5755b32d446d67657761e9a649371411d0afc9a50b83ef842ea74f2' 'nonce' 76
8 'tx' '0xcc7b4043f2eda3ae5a4a544b201054e725c9f5435ab0c6878d0ea2fa180a2688' 'nonce' 77
9 'tx' '0xd272a8b3866b84190cd7b586a799ec5cd821e312032b6c5e9c2749589bcdd220' 'nonce' 78
10 'tx' '0x4b7d668ee24a4656190271ded6744ace192464b3bed0ea1554f0fd52a9128d8a' 'nonce' 79

geth logs:

I0910 10:39:51.329829    5691 worker.go:540] commit new work on block 232 with 0 txs & 0 uncles. Took 237.203µs
I0910 10:39:53.403461    5691 xeth.go:987] Tx(0xdf3860558375dc3289a7b247ce4c6695ccb0fb82be1569847043319f36c3a00b) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:53.526999    5691 xeth.go:987] Tx(0x4232c160ce4d091bfe10b0d2ca048d557c086435c13ecad23de2e6837c1884da) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:53.545005    5691 worker.go:322] 🔨  Mined block (#232 / 7ca351b8). Wait 5 blocks for confirmation
I0910 10:39:53.545895    5691 worker.go:540] commit new work on block 233 with 2 txs & 0 uncles. Took 859.046µs
I0910 10:39:53.545931    5691 worker.go:420] 🔨 🔗  Mined 5 blocks back: block #227
I0910 10:39:53.546545    5691 worker.go:540] commit new work on block 233 with 2 txs & 0 uncles. Took 571.261µs
I0910 10:39:53.656402    5691 xeth.go:987] Tx(0x99f0e52aac80253e78cf930035122ba553a981e12564fc1e8a52f2510b31ecef) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:53.783548    5691 xeth.go:987] Tx(0xd30de73803df20dc6d441456514468b3fd4ff8e11406ba79f091c65f7a03aa04) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:53.912093    5691 xeth.go:987] Tx(0x8fcfa48d9beb968a42b42232a991d502032d63b7d9b09b55b4aa867015d2a6bb) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:53.940754    5691 worker.go:322] 🔨  Mined block (#233 / 44e26e7e). Wait 5 blocks for confirmation
I0910 10:39:53.941436    5691 worker.go:540] commit new work on block 234 with 2 txs & 0 uncles. Took 651.43µs
I0910 10:39:53.941471    5691 worker.go:420] 🔨 🔗  Mined 5 blocks back: block #228
I0910 10:39:53.942163    5691 worker.go:540] commit new work on block 234 with 2 txs & 0 uncles. Took 646.11µs
I0910 10:39:54.041582    5691 xeth.go:987] Tx(0x81f142794cfff1b12dd6bacfc2b9cb130afaf4d7f9825525403f2626495850ef) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:54.167942    5691 xeth.go:987] Tx(0xda389a9bd5755b32d446d67657761e9a649371411d0afc9a50b83ef842ea74f2) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:54.296024    5691 xeth.go:987] Tx(0xcc7b4043f2eda3ae5a4a544b201054e725c9f5435ab0c6878d0ea2fa180a2688) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:54.422012    5691 xeth.go:987] Tx(0xd272a8b3866b84190cd7b586a799ec5cd821e312032b6c5e9c2749589bcdd220) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:54.547304    5691 xeth.go:987] Tx(0x4b7d668ee24a4656190271ded6744ace192464b3bed0ea1554f0fd52a9128d8a) to: 0xeef6459e871cb640179e191205d7b19402d7d775
I0910 10:39:57.953097    5691 worker.go:322] 🔨  Mined block (#234 / ea08292d). Wait 5 blocks for confirmation

Again, the nonce reuses cooccur exactly when the new blocks are found (between tx 2&3 and 5&6).