Transactions get stuck in "In queue: Future" state

[bittylicious]

I'm running:

• Which Parity version?: 0.0.0

Parity/v1.8.11-stable-21522ff86-20180227/x86_64-linux-gnu/rustc1.23.0

• Which operating system?: Windows / MacOS / Linux

Linux Debian 9

• How installed?: via installer / homebrew / binaries / from source

Official .deb

• Are you fully synchronized?: no / yes

Yes

• Which network are you connected to?: ethereum / ropsten / kovan / ...

ethereum

• Did you try to restart the node?: no / yes

Yes (not on this time, but it hasn't worked in the past)

Transactions are, for no reason that we can see, getting stuck in the "In queue: Future" state.

I have not been able to determine why this happens, but when it affects one Parity account, it causes all subsequent transactions from that one account to also be queued.

These transactions are sent in a very simple way via the API, which is not specifying any sort of nonce or gas price (just a maximum amount of gas to use).

In this instance, the account in question has plenty of Ether available, and is visible at https://etherscan.io/address/0x12dcb828854dbeb8252c681acb675715fcdb958d

The first transaction to get stuck has a txnid of 52e894f9febe93c2ae0cefe182ed8796bb9a832f32f7bc5276de51380411c125 but this isn't yet visible on etherscan. This, combined with the state, means it's very likely that the transaction hasn't attempted to be broadcast by my Parity node.

This has happened before, where (for no really understandable reason) depositing some extra Ether to the account we're sending from resulted in transactions being broadcast correctly and moved out of this state. However, I can't see any reason it should go into this state in the first place.

I am running Parity/v1.8.11-stable-21522ff86-20180227/x86_64-linux-gnu/rustc1.23.0 with debugging flags as "-lown_tx=trace"

The only relevant output I can see for this first transaction getting stuck is as follows:

2018-03-29 11:08:51 UTC  TRACE own_tx  Importing transaction: PendingTransaction { transaction: SignedTransaction { transaction: UnverifiedTransaction { unsigned: Transaction { nonce: 18441, gas_price: 5000000000, gas: 23100, action: Call(a6167dab2acc0fa11ced95b8d7d5fcbcd4c2bc72), value: 3000000000000000000, data: [] }, v: 38, r: 47158910981751947555109704884847244632349549790191905752898583045575923030660, s: 17994044390191179838260533438189386148423159785304058234240592709904970029287, hash: 52e894f9febe93c2ae0cefe182ed8796bb9a832f32f7bc5276de51380411c125 }, sender: 12dcb828854dbeb8252c681acb675715fcdb958d, public: Some(2a423d2f7fe46bd0e8a7ddbcc5ce7a0bb3e7271034f9d35d939da7b8fb265d9b6b38784a105895b7dcd97024803e4200cd462df7436c53c45570fe165cebb15c) }, condition: None }
2018-03-29 11:08:51 UTC  DEBUG own_tx  Imported to Future (hash 52e894f9febe93c2ae0cefe182ed8796bb9a832f32f7bc5276de51380411c125)
2018-03-29 11:08:51 UTC  TRACE own_tx  Status: TransactionQueueStatus { pending: 8192, future: 622 }

Sadly, this doesn't seem to give much of a clue as to why this has gone into the "future" state.

[Tbaut]

@bittylicious thanks a lot for the report. As advised on the chat, could you please upgrade to a newer Parity version (at least 1.9.5) and tell us if this happen again ?

[bittylicious]

I've upgraded to 1.9.5 and the transaction has not been broadcast yet.

Note that I cannot confirm that Parity still "knows" this transaction as I'm having trouble accessing the WebUI via a SSH tunnel (a separate problem). Is there perhaps a command to run via (say) the IPC or JSON interface to check the status of a transaction or the queue?

[bittylicious]

The few transactions that were stuck appeared to be stuck for around 12-16 hours. However, they appeared to be broadcast after this huge delay for some reason.

I have restarted the node with --no-persistent-txqueue to clear the remaining transaction (and re-send it) and restarted again as normal. So, I now have a clean slate and if this happens again, I should have some debug to show you.

[bittylicious]

I can confirm this is still an issue with Parity 1.9.5 as another transaction just got stuck in the "In queue: Future" state. In fact, lots of them have gotten stuck:

The first transaction that had an entry of Imported to Future and no corresponding Imported to Current (yet) is 6b38812277f0d36740d13a67bafdabee3346c4dd93041a775036c68e433c947d. This is from 0x5ff5436967c15ef244ab340c4154e4a7d931a263. The debug lines around this are:

2018-03-30 15:55:20 UTC Verifier #3 INFO import  Imported #5349732 bffd…0d52 (55 txs, 6.03 Mgas, 175.11 ms, 12.92 KiB)
2018-03-30 15:55:26 UTC Verifier #7 INFO import  Imported #5349733 84d1…1fff (182 txs, 8.00 Mgas, 528.11 ms, 29.24 KiB)
2018-03-30 15:55:39 UTC Verifier #0 INFO import  Imported #5349735 e7ad…0be0 (95 txs, 7.06 Mgas, 609.77 ms, 22.59 KiB) + another 1 bloc
k(s) containing 165 tx(s)
2018-03-30 15:55:54 UTC IO Worker #2 INFO import     8/25 peers      5 MiB chain  102 MiB db  0 bytes queue   51 KiB sync  RPC:  0 conn
,  0 req/s, 227 µs
2018-03-30 15:55:54 UTC Verifier #6 INFO import  Imported #5349736 6a64…97ff (9 txs, 0.34 Mgas, 26.53 ms, 1.96 KiB)
2018-03-30 15:56:07 UTC Verifier #2 INFO import  Imported #5349737 f1db…b48a (64 txs, 2.42 Mgas, 139.00 ms, 10.03 KiB)
2018-03-30 15:56:10 UTC Verifier #5 INFO reorg  Reorg to #5349737 65b0…22d3 (f1db…b48a #5349736 6a64…97ff )
2018-03-30 15:56:18 UTC  TRACE own_tx  Importing transaction: PendingTransaction { transaction: SignedTransaction { transaction: UnverifiedTransaction { unsigned: Transaction { nonce: 1146, gas_price: 5000000000, gas: 23100, action: Call(603e4d7b370d8966a41a8b29fe0f8205f4ed9a35), value: 1900000000000000000, data: [] }, v: 38, r: 8426894158576097801638055086074387204245236839062348773405913232721545414278, s: 43528796935105261281754286302085954111799827656658322911274770334132998792628, hash: 6b38812277f0d36740d13a67bafdabee3346c4dd93041a775036c68e433c947d }, sender: 5ff5436967c15ef244ab340c4154e4a7d931a263, public: Some(3a9913c31174a01edd07826fbf3434bec92023335c437997c54224537888852d96ad10b686a647d1a3b161155f84a61b323d99e3f1d1a866a0908284183f5f27) }, condition: None }
2018-03-30 15:56:18 UTC  DEBUG own_tx  Imported to Future (hash 6b38812277f0d36740d13a67bafdabee3346c4dd93041a775036c68e433c947d)

I'm not sure if the reorg there is a red herring or not, but it's at least an interesting coincidence.

All subsequent transactions from this account got stuck also in the "In queue: future" state as well.

Let me know if you want any other info from the debug log, or generally for help in trying to push these through.

[ValeryDubrava]

I have the same version on Parity v1.9.5-20180321 stable.
Simple reproduce steps:

1. Create transaction with low gas (e.g. 20000)
2. Try to send transaction (enter password and click send)
3. Reject that transaction
4. Create new one with correct gas
5. Look in the queue - transaction in future

It happened because nonce was incremented, but transaction did not send

[Tbaut]

The queue future means a nonce problem you're right @ValeryDubrava.
It is mostly due to another transaction being stuck before for another reason (gas limit reached, data>300Kb, not enough gas...). To reset the transaction queue and make sure the transaction will get through, you should launch parity with the flag --no-persistent-txqueue.

[bittylicious]

This should not be closed.

This is an issue. It may be a nonce issue, but the best guess is that Parity's nonce incrementor isn't working as it should be in these instances.

When I'm using Parity, I never specify a nonce and I'm not aware of any transactions getting rejected, yet this happens. As shown in my log, possibly this has something to do with a reorg happening.

[tomusdrw]

@bittylicious New transaction pool implementation has been merged recently (see #8074) and it also contains re-worked nonce management. Please re-open if the issue happens again on 1.11 and provide logs by running with -ltxqueue=debug

[bittylicious]

That is good news! I can't test until this is stable but I look forward to that day. Thank you for the update.

[mason]

I confirm that I also have the same issue. I think what happened was that I was trying to transfer a token and ran out of gas. then I tried to do another transaction (eth or token transfer) and they all got stuck.

--no-persistent-txqueue fixed it for me

I'm running:

Which Parity version?: 0.0.0
Parity 1.10.2-beta

Which operating system?: Windows / MacOS / Linux
windows

How installed?: via installer / homebrew / binaries / from source
installer

Are you fully synchronized?: no / yes
Yes

Which network are you connected to?: ethereum / ropsten / kovan / ...
ethereum

Did you try to restart the node?: no / yes
yes

[bittylicious]

@TinyCalf I'm not a Parity dev but I would be surprised if this is the problem.

I strongly think it's nonce related, as usually when I get a transaction stuck in this state, if I edit/re-sign any transaction coming from the same account, it usually pushes the others though (this can only be done easily via Parity 0.8). To me, this implies that a nonce is getting skipped, and re-signing fills in the gap allowing the later transactions through.

[TinyCalf]

@bittylicious I am sorry that I get the nonce of a wrong address to get a wrong conclusion, after i get the correct nonce, it succeed. I met your problem before, so I get the nonce every time I send a transaction. Seems alright right now, but I'm still looking on it.

[antonioshadji]

same issue with 1.10.4. --no-persistent-txqueue fixed it for me

[bittylicious]

Hi,

We're running the latest 1.11 right now.

We're seeing similar issues where a transaction ID is generated, yet it isn't actually going into any blocks on the network. The node is well connected (16 connections), and this time we're not seeing it listed technically as pending in the TX queue viewer, but other than that, the symptoms are the same.

Here are two log entries for transactions that never appeared to actually go out:

Transaction 0x94864772c808c604fdfbbc1b404d24c782f1dc7c4263755b267c0a452baa9eee:

2018-08-08 09:16:45 UTC  TRACE own_tx  Importing transaction: PendingTransaction { transaction: SignedTransaction { transaction: UnverifiedTransaction { unsigned: Transaction { blahblah }, sender: 0x2773a4d62ca464438236fb8799ab6da8b32446a3, public: Some(0xab2fce043010cff908dfa257a24e7b62c6db74e407f7ffcf95218d76216a3e52ed93888dc66a158ae166f22dd7063bae4053985c9a44538af8a37fe7a6584148) }, condition: None }
2018-08-08 09:16:45 UTC  DEBUG own_tx  Imported to the pool (hash 0x94864772c808c604fdfbbc1b404d24c782f1dc7c4263755b267c0a452baa9eee)
2018-08-08 09:16:56 UTC Verifier #5 INFO import  Imported #6109659 0x360c…bbf2 (233 txs, 7.97 Mgas, 1185 ms, 33.75 KiB)
2018-08-08 09:17:02 UTC Verifier #6 INFO import  Imported #6109660 0xf390…7ff5 (151 txs, 7.97 Mgas, 449 ms, 27.30 KiB)
2018-08-08 09:17:05 UTC Verifier #7 INFO import  Imported #6109661 0xc558…f9dc (25 txs, 7.98 Mgas, 196 ms, 4.52 KiB)
2018-08-08 09:17:15 UTC IO Worker #2 INFO import    22/50 peers      4 MiB chain  107 MiB db  0 bytes queue   99 KiB sync  RPC:  0 conn,  0 req/s, 1151 µs
2018-08-08 09:17:50 UTC IO Worker #3 INFO import    22/50 peers      4 MiB chain  107 MiB db  0 bytes queue   99 KiB sync  RPC:  0 conn,  0 req/s, 1151 µs
2018-08-08 09:17:52 UTC IO Worker #0 INFO own_tx  Transaction mined (hash 0x94864772c808c604fdfbbc1b404d24c782f1dc7c4263755b267c0a452baa9eee)

Transaction 0xd840a3720a83d5da6db096ac43af83d81f6459557e5f43154063826db9e59cf4:

2018-08-08 14:23:09 UTC  TRACE own_tx  Importing transaction: PendingTransaction { transaction: SignedTransaction { transaction: UnverifiedTransaction { unsigned: Transaction { blah }, condition: None }
2018-08-08 14:23:09 UTC  DEBUG own_tx  Imported to the pool (hash 0xd840a3720a83d5da6db096ac43af83d81f6459557e5f43154063826db9e59cf4)
2018-08-08 14:23:10 UTC  TRACE own_tx  Importing transaction: PendingTransaction { transaction: SignedTransaction { transaction: UnverifiedTransaction { unsigned: Transaction { nonce: 0x2cd, gas_price: 0xf5de81400, gas: 0x5a3c, action: Call(0x519f269c29800ad9624dc62a482c4eef4814046d), value: 0x16345785d8a0000, data: [] }, v: 38, r: 0x5897ced2d29a711191550ea88c14bc4d4d7158e8632ec5519034ffb87a410bea, s: 0xc91bbe000e2b3019566743d756504a0053f6b47b824acfdf3cfc602035aa6ae, hash: 0xb93d8d92125983db7cff990fec29ae3b50ea56d4a7c306b4392d9ec43121dec6 }, sender: 0xded61d6b85bea039c3947c086d1e0ab199cec645, public: Some(0x060105590c7537efc62545e857468feca198f3ea2dfbf8634c61cc5991a26227e5214c7b808b5d150e9b5109881efcfda1ce93e077fa3d437635e6870335c239) }, condition: None }
2018-08-08 14:23:10 UTC  DEBUG own_tx  Imported to the pool (hash 0xb93d8d92125983db7cff990fec29ae3b50ea56d4a7c306b4392d9ec43121dec6)
2018-08-08 14:23:16 UTC IO Worker #1 INFO import  Syncing #6110928 0x02b4…edf0     0 blk/s    4 tx/s   0 Mgas/s      0+    0 Qed  #6110920   13/50 peers      6 MiB chain  119 MiB db  0 bytes queue  105 KiB sync  RPC:  0 conn, 14 req/s, 501 µs
2018-08-08 14:23:26 UTC IO Worker #2 INFO import  Syncing #6110928 0x02b4…edf0     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #6110913   14/50 peers      6 MiB chain  119 MiB db  0 bytes queue  109 KiB sync  RPC:  0 conn, 41 req/s, 256 µs
2018-08-08 14:23:27 UTC Verifier #2 INFO import  Imported #6110929 0xb83c…3351 (134 txs, 8.00 Mgas, 454 ms, 23.42 KiB) + another 2 block(s) containing 122 tx(s)
2018-08-08 14:23:30 UTC Verifier #6 INFO import  Imported #6110930 0x8044…f454 (66 txs, 7.99 Mgas, 265 ms, 11.06 KiB)
2018-08-08 14:23:56 UTC IO Worker #0 INFO import  Syncing #6110931 0x9a82…7c34     0 blk/s    2 tx/s   0 Mgas/s      0+    0 Qed  #6110928   13/50 peers      6 MiB chain  119 MiB db  0 bytes queue   99 KiB sync  RPC:  0 conn,  0 req/s, 404 µs
2018-08-08 14:24:06 UTC IO Worker #0 INFO import  Syncing #6110931 0x9a82…7c34     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #6110923   14/50 peers      6 MiB chain  119 MiB db  0 bytes queue  105 KiB sync  RPC:  0 conn,  0 req/s, 404 µs
2018-08-08 14:24:16 UTC IO Worker #0 INFO import  Syncing #6110932 0xddf9…bc03     0 blk/s    6 tx/s   0 Mgas/s      0+    0 Qed  #6110926   13/50 peers      6 MiB chain  118 MiB db  0 bytes queue  104 KiB sync  RPC:  0 conn,  0 req/s, 404 µs
2018-08-08 14:24:26 UTC IO Worker #2 INFO import  Syncing #6110933 0xc035…77aa     0 blk/s    7 tx/s   0 Mgas/s      0+    0 Qed  #6110886   13/50 peers      5 MiB chain  118 MiB db  0 bytes queue  129 KiB sync  RPC:  0 conn,  2 req/s, 438 µs
2018-08-08 14:24:36 UTC IO Worker #0 INFO import  Syncing #6110933 0xc035…77aa     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #6110920   13/50 peers      5 MiB chain  118 MiB db  0 bytes queue   99 KiB sync  RPC:  0 conn, 27 req/s, 342 µs
2018-08-08 14:24:46 UTC IO Worker #0 INFO import  Syncing #6110934 0x1c58…f288     0 blk/s   13 tx/s   0 Mgas/s      0+    0 Qed  #6110925   13/50 peers      5 MiB chain  118 MiB db  0 bytes queue   99 KiB sync  RPC:  0 conn,  3 req/s, 342 µs
2018-08-08 14:25:05 UTC Verifier #4 INFO import  Imported #6110935 0x541f…a03d (74 txs, 7.99 Mgas, 379 ms, 13.88 KiB) + another 4 block(s) containing 334 tx(s)
2018-08-08 14:25:08 UTC Verifier #3 INFO import  Imported #6110936 0x6c74…609f (109 txs, 8.00 Mgas, 515 ms, 19.60 KiB)
2018-08-08 14:25:21 UTC IO Worker #2 INFO import    13/50 peers      5 MiB chain  117 MiB db  0 bytes queue   99 KiB sync  RPC:  0 conn,  0 req/s, 342 µs
2018-08-08 14:25:26 UTC Verifier #2 INFO import  Imported #6110937 0xd08f…394f (184 txs, 7.98 Mgas, 823 ms, 29.01 KiB)
2018-08-08 14:25:30 UTC Verifier #6 INFO import  Imported #6110938 0xfcf2…0241 (119 txs, 7.99 Mgas, 414 ms, 18.69 KiB)
2018-08-08 14:25:45 UTC Verifier #7 INFO import  Imported #6110939 0x2894…74ed (64 txs, 7.99 Mgas, 223 ms, 31.86 KiB)
2018-08-08 14:25:56 UTC IO Worker #2 INFO import    13/50 peers      6 MiB chain  118 MiB db  0 bytes queue   99 KiB sync  RPC:  0 conn, 14 req/s, 881 µs
2018-08-08 14:25:58 UTC IO Worker #1 INFO own_tx  Transaction mined (hash 0xb93d8d92125983db7cff990fec29ae3b50ea56d4a7c306b4392d9ec43121dec6)
2018-08-08 14:25:58 UTC IO Worker #1 INFO own_tx  Transaction mined (hash 0xd840a3720a83d5da6db096ac43af83d81f6459557e5f43154063826db9e59cf4)

Any ideas why this is happening?

[Tbaut]

As discussed in the chat. Please open a dedicated issue if you can reproduce. Also have a look at the article about how the transaction queue works in Parity Ethereum

[gituser]

@bittylicious check this issue - #9040 most likely you're experiencing something related to the nonce increment.

Check your pending transaction's nonce on your node and check if there is a gap in nonce between the stuck ones and the one that has been mined last.

[bittylicious]

@gituser I'm pretty sure these transactions don't appear in the pending transaction list.

We have a script that emails us on the hour when there are pending tranactions that are more than ten minutes old. It didn't email us when these occurred, so they were fully dropped I believe and the nonce gap remained.

[bittylicious]

I can confirm I still get this issue with the latest 2.1.10-stable. I don't have time to look at the logs right now, but I have a transaction again with a transaction ID yet it never appears to actually be broadcast.