Improve transaction handling for Parachains

[bkchr]

The transaction pool is designed to send out events about inclusion of a transaction in a block when the transaction got included in a block that is seen as best block of the local node. If this block then for example is removed from the best chain (because we forked), a retracted event is sent. On parachains a block at the tip of the chain isn't imported as best block. Setting the best block happens asynchronously as it depends on what is the best relay chain block and which parachain block got included in this relay chain block. This means that instead of waiting ~6 seconds on the relay chain we have to wait at least 12 seconds on a Parachain.

To improve the situation we should directly send the inclusion event when the transaction appears in any block. It should not be important if the block is a best block or not. I also don't see any real benefit in sending a retracted event (we should check the new RPC spec, but I doubt that it is still send there) and we should be able to omit it.

[bkchr]

This change is also important to have ready_at return directly when we build a new block. Currently we don't start the maintenance as we don't have seen the block import yet. A consequence of running maintenance for every block could be that we invalidate transactions on one fork, but they are not yet included in another fork. I don't think that the transaction pool currently supports "fork handling". We should look into this when working on this feature.

[rphmeier]

It's also worth noting that collators will build forks deliberately, if there are relay chain forks.

And now, with asynchronous backing, may build on top of blocks which themselves aren't the best (and sometimes multiple blocks immediately in a row).

I'm not really familiar with the details of the transaction pool but it sounds like the solution here should work for those requirements as well.

[michalkucharczyk]

(we should check the new RPC spec, but I doubt that it is still send there)

Forgive dumb question, where is new spec? Is it here and here?

[bkchr]

Yes this is the new spec. I already opened a proper issue here: https://github.com/paritytech/json-rpc-interface-spec/issues/87

[bkchr]

While looking into async backing we have seen that the transaction pool is sometimes rejecting transactions when building a fork. Let's assume you build block X that includes two transactions from account A. After having build the block and removing the transactions of block X from the tx pool, we start building block X' (a fork of X). Account A still has some transactions in the tx pool, but their nonce doesn't match the chain state of Y (parent of X and X') as the tx pool thinks that we already included the transactions. While the tx pool is right that we already have included them in a block, we actually have done this in a fork and thus the assumption isn't correct and will lead to apply_extrinsic returning Error::Future (because the nonce is too high).

To solve this issue we need to make the transaction pool fork aware. This means that if we are building X or X', we both times use the transaction that are valid in the view of Y.

[bernardoaraujor]

some extra info on this:

we are working on a parachain project that will need to use the available blockspace as efficiently as possible

since async-backing was made available, we have been doing extensive testing to have empirical numbers of throughput for different kinds of extrinsics

we have been using evm-tps to spam the parachain with extrinsics. despite the fact that this tool's name suggests our scope is limited to EVM, it also allows for spamming of non-EVM/pure-Substrate extrinsics.

the parachain codebase is using polkadot-sdk v1.2.0.

when we spam the parachain with multiple transferKeepAlive extrinsics (pallet-balances), the transaction pool eventually drops all transactions.

here's how we've been monitoring the pool while we spam (it checks author_pendingExtrinsics every 1s):

$ while true; do curl -sS -H "Content-Type: application/json" -d '{"id":1, "jsonrpc":"2.0", "method": "author_pendingExtrinsics"}' http://localhost:9933 | jq -r '.result | length'; sleep 1; done

and this is what we see:

3827
3827
3827
3827
0         # there's no block with 3827 xts
0
0
0
0
0

[bkchr]

@bernardoaraujor please run with -ltxpool=trace and check why the transactions are removed.

[bernardoaraujor]

up until this point, everything seems normal:

2023-11-09 17:22:18.014 DEBUG tokio-runtime-worker txpool: [Parachain] [0x505bff87d0eea59aef4e89a67b47402950c938212824192e581239d8a04aa178] Importing to ready
2023-11-09 17:22:18.014 TRACE tokio-runtime-worker txpool: [Parachain] [0x2d5bd826541a855f48dd2e40ab0860236c99ecc73f49341eb32287e4e30534a0] WaitingTransaction { imported_at: Instant { tv_sec: 19636, tv_nsec: 211760166 }, transaction: Transaction { hash: 0x2d5bd826541a855f48dd2e40ab0860236c99ecc73f49341eb32287e4e30534a0, priority: 1459, valid_till: 42, bytes: 116, propagate: true, source: TransactionSource::External, requires: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac8d010000], provides: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac8e010000], data: 84fe0ffff4f3e12fb08bac1f573b37d8f4a33734aca89955beb362b214c6b0633c76514a830e5d4a6040e2a70a5d98e90f531e9b19610c7abe3e2ab3995886350042e2a357a13dc746d1812ee1142c8d0225eaaad101b4003906000a038d17e4815b18abb0ff1e3af016bc3f82c9102e1804}, missing_tags: {}}
2023-11-09 17:22:18.014 DEBUG tokio-runtime-worker txpool: [Parachain] [0x2d5bd826541a855f48dd2e40ab0860236c99ecc73f49341eb32287e4e30534a0] Importing to ready
2023-11-09 17:22:18.014 TRACE tokio-runtime-worker txpool: [Parachain] [0x4823539cdd4a7f4e37ef6e0b2d0333bfe23b2c380cfa41b50b81451c91ccadf1] WaitingTransaction { imported_at: Instant { tv_sec: 19636, tv_nsec: 211781125 }, transaction: Transaction { hash: 0x4823539cdd4a7f4e37ef6e0b2d0333bfe23b2c380cfa41b50b81451c91ccadf1, priority: 1459, valid_till: 42, bytes: 116, propagate: true, source: TransactionSource::External, requires: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac8e010000], provides: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac8f010000], data: 84fe0ffff4f3e12fb08bac1f573b37d8f4a33734acf8c300220a1e272dc4804b4562542ebb55023aecf0454ef98445d7c5ab9f43ec71486b17289018fbb286e994e451ce5e1555cc00151306ed9e38c3eccb60895501b4003d06000a038d17e4815b18abb0ff1e3af016bc3f82c9102e1804}, missing_tags: {}}
2023-11-09 17:22:18.014 DEBUG tokio-runtime-worker txpool: [Parachain] [0x4823539cdd4a7f4e37ef6e0b2d0333bfe23b2c380cfa41b50b81451c91ccadf1] Importing to ready
2023-11-09 17:22:18.014 TRACE tokio-runtime-worker txpool: [Parachain] [0xc913886ee07600e46ae886ae9fb1245f84c7279ddcfb7bf14e8bc675986b1f37] WaitingTransaction { imported_at: Instant { tv_sec: 19636, tv_nsec: 211795666 }, transaction: Transaction { hash: 0xc913886ee07600e46ae886ae9fb1245f84c7279ddcfb7bf14e8bc675986b1f37, priority: 1459, valid_till: 42, bytes: 116, propagate: true, source: TransactionSource::External, requires: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac8f010000], provides: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac90010000], data: 84fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac8e0998798c574f2d807ce59b1d3d9f1f3c0d02248c0896bc196b66c7456d65793b8817ca50ec886bcf8298b6f2246bdd74fea9242f14e6a0fab63c3000113cb501b4004106000a038d17e4815b18abb0ff1e3af016bc3f82c9102e1804}, missing_tags: {}}
2023-11-09 17:22:18.014 DEBUG tokio-runtime-worker txpool: [Parachain] [0xc913886ee07600e46ae886ae9fb1245f84c7279ddcfb7bf14e8bc675986b1f37] Importing to ready
2023-11-09 17:22:18.014 TRACE tokio-runtime-worker txpool: [Parachain] [0x67d948c5cbcb4fcb3804fbc6c256a89215f4796f9f8f319dd372ba0986cf6351] WaitingTransaction { imported_at: Instant { tv_sec: 19636, tv_nsec: 211807125 }, transaction: Transaction { hash: 0x67d948c5cbcb4fcb3804fbc6c256a89215f4796f9f8f319dd372ba0986cf6351, priority: 1459, valid_till: 42, bytes: 116, propagate: true, source: TransactionSource::External, requires: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac90010000], provides: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac91010000], data: 84fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac712c8ea67d33439c8c83f5531a8eab15599f97d552f6ecb785146cea0fb713ab1d10eda32d14187fbdaaf49d4f1cdcb265cd5e9060b7751a66f5b5375c0f506400b4004506000a038d17e4815b18abb0ff1e3af016bc3f82c9102e1804}, missing_tags: {}}
2023-11-09 17:22:18.014 DEBUG tokio-runtime-worker txpool: [Parachain] [0x67d948c5cbcb4fcb3804fbc6c256a89215f4796f9f8f319dd372ba0986cf6351] Importing to ready
2023-11-09 17:22:18.014 TRACE tokio-runtime-worker txpool: [Parachain] [0xa62e2aacaf621cfc7cefd56c711778ad8c5cd93694e86c4c5453133ff21e82cb] WaitingTransaction { imported_at: Instant { tv_sec: 19636, tv_nsec: 211818666 }, transaction: Transaction { hash: 0xa62e2aacaf621cfc7cefd56c711778ad8c5cd93694e86c4c5453133ff21e82cb, priority: 1459, valid_till: 42, bytes: 116, propagate: true, source: TransactionSource::External, requires: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac91010000], provides: [fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac92010000], data: 84fe0ffff4f3e12fb08bac1f573b37d8f4a33734ac88c3d94ab9031879fc15290f1e8005f27d290d181d670daaa1e8190266b3589d7f837b453ccc75268ce0ec47454548a03124fe374db5b18e4914569d35529db000b4004906000a038d17e4815b18abb0ff1e3af016bc3f82c9102e1804}, missing_tags: {}}
2023-11-09 17:22:18.014 DEBUG tokio-runtime-worker txpool: [Parachain] [0xa62e2aacaf621cfc7cefd56c711778ad8c5cd93694e86c4c5453133ff21e82cb] Importing to ready
2023-11-09 17:22:18.014 DEBUG tokio-runtime-worker txpool: [Parachain] Resubmitted. Took 22 ms. Status: PoolStatus { ready: 7953, ready_bytes: 922548, future: 0, future_bytes: 0 }
2023-11-09 17:22:18.014 DEBUG tokio-runtime-worker txpool: [Parachain] Revalidated 20 transactions. Left in the queue for revalidation: 20.

then:

2023-11-09 17:22:18.016  INFO tokio-runtime-worker babe: [Relaychain] 👶 New epoch 2 launching at block 0x33c3…9f11 (block slot 283260223 >= start slot 283260223).
2023-11-09 17:22:18.016  INFO tokio-runtime-worker babe: [Relaychain] 👶 Next epoch starts at slot 283260238
2023-11-09 17:22:18.020 DEBUG tokio-runtime-worker txpool: [Relaychain] resolve hash: 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11 finalized: false tree_route: (common HashAndNumber { number: 30, hash: 0x07569ee49344becd3dac36a5b18d46eab6f1ad0896239b913ee581aa488c7e8c }, last Some(HashAndNumber { number: 31, hash: 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11 })) best_block: 0x07569ee49344becd3dac36a5b18d46eab6f1ad0896239b913ee581aa488c7e8c finalized_block:0x3d7374f3f6fb1fc2b3593b1b7e2bb4754dc6be11649b93cb2ccb0379f70ae284
2023-11-09 17:22:18.020 TRACE tokio-runtime-worker txpool: [Relaychain] handle_enactment tree_route: TreeRoute { route: [HashAndNumber { number: 30, hash: 0x07569ee49344becd3dac36a5b18d46eab6f1ad0896239b913ee581aa488c7e8c }, HashAndNumber { number: 31, hash: 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11 }], pivot: 0 }
2023-11-09 17:22:18.020 TRACE tokio-runtime-worker txpool: [Relaychain] Pruning transactions: [0xe4aa473edf1d86aace4f7637b6c3f016a120c866fbcdac8f5296eb4a8b195bf5, 0x899e2eaabfbb2a27aa09004df564ab4d514fb4c36562a883edf28063ccb07017]
2023-11-09 17:22:18.020 DEBUG tokio-runtime-worker txpool: [Relaychain] Starting pruning of block 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11 (extrinsics: 2)   
2023-11-09 17:22:18.020 TRACE tokio-runtime-worker txpool: [Relaychain] txpool is empty, skipping validation for block 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11
2023-11-09 17:22:18.020 TRACE tokio-runtime-worker txpool: [Relaychain] txpool is empty, skipping validation for block 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11
2023-11-09 17:22:18.020 DEBUG tokio-runtime-worker txpool: [Relaychain] Pruning at 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11
2023-11-09 17:22:18.020 TRACE tokio-runtime-worker txpool: [Relaychain] Pruning at 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11. Resubmitting transactions.
2023-11-09 17:22:18.020 DEBUG tokio-runtime-worker txpool: [Relaychain] [0xe4aa473edf1d86aace4f7637b6c3f016a120c866fbcdac8f5296eb4a8b195bf5] Pruned at 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11
2023-11-09 17:22:18.020 DEBUG tokio-runtime-worker txpool: [Relaychain] [0x899e2eaabfbb2a27aa09004df564ab4d514fb4c36562a883edf28063ccb07017] Pruned at 0x33c31f244a7641ff2f82cbeefbf07d7ec169640e05640e2c462b1d78776f9f11
2023-11-09 17:22:18.020  INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #31 (0x33c3…9f11)
2023-11-09 17:22:18.025  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xe8cea3d760252f9c73f884648c0f6cefda3f847d99eafa7e2b6ede41fee0b135
2023-11-09 17:22:18.026  INFO tokio-runtime-worker skunert: [Parachain] post_dispatch: Unspent weight: ref_time: 0, proof_size: 0
2023-11-09 17:22:18.026  INFO tokio-runtime-worker skunert: [Parachain] post_dispatch: Unspent weight: ref_time: 0, proof_size: 0
2023-11-09 17:22:18.026 TRACE tokio-runtime-worker txpool: [Parachain] Transaction pool already processed block  #14
2023-11-09 17:22:18.027 DEBUG tokio-runtime-worker txpool: [Parachain] [0x22c4f534b725af6e885835b78023f157f0178388dda9a3c4bd993aa1550b0768] Reported as invalid. Will skip sub-chains while iterating.
2023-11-09 17:22:18.027 DEBUG tokio-runtime-worker txpool: [Parachain] [0xe1d87232be31c96fa0552d46bb62c916ae9134b13e2a6b8a7e9aa49747af9263] Reported as invalid. Will skip sub-chains while iterating.
2023-11-09 17:22:18.027 DEBUG tokio-runtime-worker txpool: [Parachain] [0x4ebf5b545735313724848fd281ecf7210862d0c73c037da29de977886e3e6fc0] Reported as invalid. Will skip sub-chains while iterating.
2023-11-09 17:22:18.027 DEBUG tokio-runtime-worker txpool: [Parachain] [0x7b195df33a155982f2f2b024b797ecf75d7086e60b635ef18087042db0d275d3] Reported as invalid. Will skip sub-chains while iterating.
2023-11-09 17:22:18.027 DEBUG tokio-runtime-worker txpool: [Parachain] [0xd60a310b314cf0ca0951cbfc042029b2244ed827575a368510f4662e2526aee0] Skipping invalid child transaction while iterating.
2023-11-09 17:22:18.027 DEBUG tokio-runtime-worker txpool: [Parachain] [0x15f4416c8b1e16e4c3f85967defa1af06e77d035bf53b17498749e280a440b49] Reported as invalid. Will skip sub-chains while iterating.
2023-11-09 17:22:18.027 DEBUG tokio-runtime-worker txpool: [Parachain] [0xf1be885b3a50e5fcc2c22c1f0d3eeca47ed504574894dc769165ce6c7381b4b5] Reported as invalid. Will skip sub-chains while iterating.
2023-11-09 17:22:18.027 DEBUG tokio-runtime-worker txpool: [Parachain] [0x1c522b9a8d5cd3960fdb1516aa0c2b0581aa512a62c0c53df7ff766118d742ef] Skipping invalid child transaction while iterating.
2023-11-09 17:22:18.028 DEBUG tokio-runtime-worker txpool: [Parachain] [0xc450054353e47874270d9741566e59b85e1952cde12cdb6c6d3b14001f13da39] Reported as invalid. Will skip sub-chains while iterating.
...
2023-11-09 17:22:18.039 DEBUG tokio-runtime-worker txpool: [Parachain] Removing invalid transactions: [0x22c4f534b725af6e885835b78023f157f0178388dda9a3c4bd993aa1550b0768, 0xe1d87232be31c96fa0552d46bb62c916ae9134b13e2a6b8a7e9aa49747af9263, 0x4ebf5b545735313724848fd281ecf7210862d0c73c037da29de977886e3e6fc0, 0x7b195df33a155982f2f2b024b797ecf75d7086e60b635ef18087042db0d275d3, 0x15f4416c8b1e16e4c3f85967defa1af06e77d035bf53b17498749e280a440b49, 0xf1be885b3a50e5fcc2c22c1f0d3eeca47ed504574894dc769165ce6c7381b4b5, 0xc450054353e47874270d9741566e59b85e1952cde12cdb6c6d3b14001f13da39, 0xa3d1bcf17cf6b3f27ac523cd93c16eb4dfdce85f4b5e5dbe71102001bda5f8d0, 0xf9c9b17268dafb6870e0e73e8cd40b6257655ca3a72898e6e0aebad560fcb22f, 0x64f7dfad602cdb1d47adf72cf5206fa2c267b763ad4a1fa60042df5f03c1b29e, 0xbca3364c1a49f485570987d8aa99de837b7c8fa838a638e2ea2161345c9f5368, 0x1e4a58031044a71b2b18f0c7152b4ad7b2fe893b9add7c1bfb926a9ff4fafaf6, 0x2541716b5a2d8c5e89d362604e8606d664e919f0ee6d24add6ddbd4612c2b5d9, 0xb0407b9456a08fa52ee6a17474da2266e3e7019dcc85060d4eac74bf0aeb6258, 0xcd168f56b8617c3190b490372d8c9664e368472f142e0de50136d0e8d4d733b7, 0xabe6164790ca49d33b420486631c4f54969ba63b8180f4303a5528ac91adf5ee, 0x632e984d31d43291a5de279c96740bd3732e1003bb9f4488ef92fe6936b1ddca, 0x99529ffcc85a4029f2c154079f322c579a713b6bc764b203340b04ced876f8d9, 0x1cb03d1d470afc9da072c9a0c87a57e85e54f52c1586c0a9238504ca04607b92, 0x869e88f4d2cebba7e30446fe410c9dcddcf02c900a1f5bc1d2e698cd02510926, 0xe283fd984334c6363508570f30961d341bdbc57b9a16ca3f185de6569c1d722a, 0x8684235d918d5feccb9060c23c6cbedbf2b48cce4da09424f7eccefbec47d00e, 0x3aadd6b296bc4dfc94935923b3e4b582fd058b35cd0d522698f24f5cfca816bc, 0xc901cd3485f54adb0022390e1fc2334c0736418c883ed63f95b0b2c49d745ca0, 0x8f79d75fd4f6806425e56c24479309ac2075cc2963fbcca8560d20ac4320a537, 0x7444645b549aa6e5fcd7889707fef3fc5d2a23c12f1b98e65c9c21d51b0740e6, 0x4e552548f7978313125b15619225d7040373f405704906dd397b38547cdd78e5, 0x1d6586c9b420adee2ae7ff423d60a34596c575b7e1188f3ba6c0f7e1f711e284, 0xf10833bb0270c029b2cc6676cdc805ee6f37988f745d255af618ccbae3ed5fd5, 0x0c90cf00236fb970e877fb05eed7a2c366a6d31d06c2208b740e65f8b8f229ee, 0xe036ac63ef29b56a38ec3be0ad6c0a57d6600130178cc4c5a723f0f89dfd1b54, 0x2b5cb4a35b0afdf10f4015364dc32db64429c70b67001deb685f611bb307b3d5, 0x9f40e1db88fb5f890a26c5fb57117f653003ff225a9fad9c3fc97d5c3ba72b0f, 0x9795b2311e1966d703a14025f977f9642a7b03e92b7e4b04c3c5daf66f6113f9, 0x9b31b037162b4386347e78ee91c7a710106e136c8dab5f9ddbe4f31d8c868c71, 0x2200b56c2f8fb9cde54009a82e437e8efa684eef26e11a57db2e538fba617864, 0x45b25653eb359ce63d19e6afcbf7d4deb9896367ad87e9050195db807c891cef, 0x35691f5dbe3656c4ce9160283c33461e1fe2af16bf38d295275cc8533ebfa797, 0x51d08524ae55afa476733321465a211cfb796a158562f5ddaade79c4feb3514a, 0x8633a55a07727f5a51c011eda7c7a8b9e38c7ccb44f00361cb15ec97f3948a4e, 0x663b4cb4325303d8512694a2f3c79565c1b6e51b38f9b540f7cd53136a0824be, 0x24245823aae09ba0fa017d1b02c526a766c767c3f44d3bc25eb145ae9d103734, 0x05b9854e7e44c48e2ec76a8a2500e73a4e19c4dbdc5b4162029640b4cdf80903, 0x1a92e4d9c164305622c64949163151ed587e6420808500f4278561413041444c, 0x23b0054df204dd4f81f0aeef6dad7d26e24305e75dd5bb2ac96877f268027aff, 0x3a238b7b426197d26e3279070f85cabe60aee101190a85bfe38dc7ea0ef5c473, 0xa982566c5743b877364195226882b05c0ca2b8d8ee78bb2f03a101c16d8d41bc, 0x61549d593adc54b6e0b26a697bd24af4d5a3d74405ebd245ed23b35ff5a0f889, 0xc5a528279e84f50a30b8c4c6c28ee990a0f1374bfea4ac0604042207a79ab92a, 0x3e1166b95258541c64bff0ab2dcd883218688904216bc857a2b04e946c88913e, 0xf4a9ea5c0d4c0f05910eb549324866111dc41c501c17a42bef1de43c995783a8, 0x092556a14ba2914fdb00111031f25a398b02fa5cd490804bf0ef4171f920ac3b, 0xd5054037bf7e5d9b6ae301d8c8ba8f8cf94c987cd8a97cb4cc1f7b99a32ad832, 0x107f623e3e0705b045565ae68856d2e391a114db1887b576231c765f12d0ca10, 0x6cec6359759c5d915e2e2c0a5c7e4e46e6c4212ae5d8b752366f22353a2e3002, 0x6903fe51b94c9963a0ee74c5d356a1eccb2d5934436f6854c48516ddf8a399f1, 0x8ada451406fb3da6a41e7a11b7b17bd5166aebb5a967768561921dd684528480, 0xc661133ebe4b12d52d4b40a0185894d8ebbb174e7a4bf7c781146d4050957af6, 0xb4e8a5460a2dd8b5a5da60ef2113bf2e4a6e81d651a7447405f232e082420432, 0x587be78f66931f2be7a1c420c7693751334f2c89c64eaa298aba91fabb6e988b, 0x4cfec8b41995aa89b4b3b11f318213db386c72132ebccf82d4828b27fec8755d, 0xc59afd59942a5f677273123c8fdc13c2bbc4970832f0368be9ffff947bd28a2f, 0x4be809cababa18e4891ae3ec07ba31ca3024208cb740aa3502dc705a505e1a6f, 0x55fae4f3f44d8da8ab954f00e70fe0f0d053400e7db1242a7da45e787b13c764, 0xfa5ea3f2aad46d89069c494bb001c35f5731b726a4bf83e21cd721dbd1cd870d, 0x2341b54ab1eddeaa9ec2523eacd86c7ede83d77870e7ac93e2da56a4c7e64f6f, 0xb5ed10a313f8af3d7baa873294d7e90f474f7056fc18e975e8f89a5a311d5c5c, 0xe1088cd80f6b91d39a75f4c2b7fb7d49a965ebfbf1be5c60963e73b015661f07, 0x666fec58de1bd79f03cd4d3732e8791cb9b242fcafc70d50fc72fe556e380b3f, 0xd7f225f61bb70ed3652417476682b3454fe94736cbabd1f16723673aea933e1b, 0x013ab17df68c547d583275a682b3edcac23cb5c5bca9a5cb077db85969fd55df, 0x2e35ecb8aa80bd688c3662368efe7ae7d4bfbe257014409e11e17590ba142842, 0x55e23dcd7608f75eec53b62542d1964bc579ae14dcea775fa43e9dc694ee0bd4, 0x6de06da5aa82ce506507247eff83e32d177174e9dcb8cf807caa15c0ee351f39, 0x5e4739658c3d102d2585c46a4a779924a9a60cc353c3d21be6f4c4f437f7cbb6, 0x59d8bb4d8725eaf578528bc07c68d6f63d7af57d82068932a8b98dc1dfdd01e7, 0x560a3c696726497f0ba5722f9fa20801946e9894d23c70d766afc36db3ae9e90, 0x7f056c8c4fc5ad2b60a0f0392cd15979001ae95d8d2b47e1164bcc2f66f8ed99, 0xb86993dbeb40c970a3df320899e2ac3b5b07021ed4930b48af375bbc7fb15d3f, 0x4412ff0edbef7790a8d0a63a0c7e7cf2bffd18d0407d5c5bb0340ceccf3121f1, 0x0415749c49cea625d794be70f6f652ca0019774c004f85863086868d8fa39d0b, 0xdbf7b5e48488864b6c3c2fd64bffb68a26dc775e6cbe604de2ff589b69b8e568, 0x3d24d20a8d37ae6266b2cd6eb6e1c14f78f3da471dfd856412155a90b780269c, 0x40d9bb6c7bb2a47fbb0ebeff95e1302e721b160881ad1e73da30ecc7564652a5, 0x2efe1728c94389fcc81ac0d114baf0d68dc397a35835e28704ef6ca2fb05e9b8, 0x8e5dd47cb9378b7ea0bc59e2d60011ad656532218966b0cc474ea9ac73d3d443, 0xce3aec9a413bbb866f709a0a2e00227e47a7d5d722b34a0cb8736d0a1cd0e272, 0x99c3179331a99c4397a83bd1433dfdd2acd64140e69ee2bf372c5c2e2c7dc581, 0x85112bc9f51a06919bc5132b963b8c4f46e11c59bc0e51e511fb1f7b8c38a5e6, 0x935a66b3673706a72dc877eede5a242e9aff41f3e4b425656dab3e7314da7707, 0xf0020dcc3b5a516a7a6db0410fb6713e4ba6927e76cb1cf4183864d1642e5267, 0xc7856e0dde728a412a1c497fb3f35afd2366e5ec9ce54006f1e4b048476d6be8, 0x7907d86c2fc1d3b5ebcadbeed1f60fa0d0d946cf41bbec53d8d7dfd769abef36, 0x1c7a0f4622e4535383cb99ec8a12760e97731c05b094530fbba71ebf068fede2, 0xcf1078392f907090e823cc2662117233ed685aceb91d77ba9d725a4c3546b357, 0x9dfb8cfb6b90d6adb54c5f9f1932ced8444abb91c63c28a5b01392e9c68fe742, 0xdb987afea8f810c2903eb13f6bc007a05a462753a13fae166d4dcdc5c83cc96d, 0xed9366dfd4aef82ee1515a20cc49860b06454d14caf0c5c5b46476a58679601b, 0xd7708399189922d05da3f669317a10d0e74191e3c05aeae92bbf45a60c486da5, 0x37195b0d66abf1afe635283776c5539638174c5db2b02dc032cde07a193c00b4]
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0x37195b0d66abf1afe635283776c5539638174c5db2b02dc032cde07a193c00b4] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0x064e4445eaa0b41a4b558631635bb333cfe75dd8448cfad430fa49fbdc6ac22e] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0xb589fd9e4aac2f29a780143abb332b7dfdfb65cc7562560cbd132cd47989f291] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0x259651a767b746c75a9463e3b61521775e5bd7f9d91c87236ef8251e88fbe034] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0x1ce94f2dda858eccff4a096facf155f1517aeaab702969ec0f8b47ed2bc75a36] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0x03ae9287f819a3b7b7a2b1d0e3c3d24a525d75ccf4e521d293bc6cf7835808ee] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0x5bb2b014407d60458fefcc3fad705230d6bb438e7299876f799be6fa88d688ee] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0xee06f8a85e4b44543cedd50b2fc36d619dc74345b9e3b2c1bee6243d98263850] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0xcd575fc69bfa9b39787948ca92cd7c71a2f0129ad2f4a4e938bf1cfcc0c1f9fe] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0xa2df34ce378e2ffd82a2ac527f9a75bc78243d1e3e034c2913c614bb2cdc6adc] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0xa1edf60850286faa49a207a8bd0a9c21860320e073f445b970e04abcd1ff98da] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0xb71838528ef676d2318fe092c6a3087255dbe40c85b4f45a6621c06abfcf9fe0] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0xab2dd34f6c0a3f4061dac8c0e96901ceb9d446eedbf3aa53e3c15537b3615c14] Removed as part of the subtree.
2023-11-09 17:22:18.039 TRACE tokio-runtime-worker txpool: [Parachain] [0x0d6b88c27b7bf6ccabbfb8434835f5775eec2dc24ed460f6d10d9c352e5052b3] Removed as part of the subtree.
...
2023-11-09 17:22:18.054 DEBUG tokio-runtime-worker txpool: [Parachain] Removed invalid transactions: [Transaction { hash: 0x37195b0d66abf1afe635283776c5539638174c5db2b02dc032cde07a193c00b4, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c60010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92cfd81871d11a8e1eccc4452bdff9a96593b13237194a6274d4f117c4c45f918fd6204ebc1a8259f2ee197f1f43bcc3a026a654f76f69a8bf71bc4ccf6496e0b7a00a4008105000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0x064e4445eaa0b41a4b558631635bb333cfe75dd8448cfad430fa49fbdc6ac22e, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c60010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c61010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c5d3bf369b9c7d111dd13c42f86ade0ceab5337203d9b7028a163a8c0259096bd6c385d98b6a9a346cffb1f2021daecb794916c78b3ca137caa597edac51027f901a4008505000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xb589fd9e4aac2f29a780143abb332b7dfdfb65cc7562560cbd132cd47989f291, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c61010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c62010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92cbd8ef0be14ef74eeff12ea408f6aa60141bea59c59f242caf54c83b518aa573b714eab7965acfcbc47d658817d998c61cc6e6bb50fd036aee57beebe9630a9e001a4008905000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0x259651a767b746c75a9463e3b61521775e5bd7f9d91c87236ef8251e88fbe034, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c62010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c63010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92ca8789f959db5ac385a2784a7130119b83277823e10ce43851cc9b9ce6e6ba6a66c768606e88e18040220f689c0f3d7ad4a47fc1f7ec9627fe40c34ddf29bc15c01a4008d05000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0x1ce94f2dda858eccff4a096facf155f1517aeaab702969ec0f8b47ed2bc75a36, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c63010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c64010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92cdadeadb24a45bb0c6f759758f45e1cacb95caac8dcc4729ab04148e8ff9da9f05edc89e8e1ad94d0307c8bf89cc8c1d0572815dfb4dc2f7ac130064eee153d2f01a4009105000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0x03ae9287f819a3b7b7a2b1d0e3c3d24a525d75ccf4e521d293bc6cf7835808ee, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c64010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c65010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c6c95853487337b499b42681ebe2debc9b3297d2f14c9377d94cf61b93ed44aec2493d3777a27514ac424e484b0b6da7f93f7703c370b590098cd0e52977caf8400a4009505000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0x5bb2b014407d60458fefcc3fad705230d6bb438e7299876f799be6fa88d688ee, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c65010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c66010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c82b3c83d287029d77103481dcb271cfc499ca378112174e5407dd30569bd5b182eb7aebedd8c785647e28e5bbdf260d3bfbfd522154c6bd3ac17155755dac74b00a4009905000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xee06f8a85e4b44543cedd50b2fc36d619dc74345b9e3b2c1bee6243d98263850, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c66010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c67010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c063a5e629b13cfe5e74c8ed5279b1583db9de9701bd99af67d92243d0585ea2c14beb06633b4ae654d6c623ffc952fc02c0f5bb152ecd70749b73737d957942b01a4009d05000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xcd575fc69bfa9b39787948ca92cd7c71a2f0129ad2f4a4e938bf1cfcc0c1f9fe, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c67010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c68010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c1537670c448e56c09abaf4eb2b2a76b1517338ea698dad2143c73a8cf404a1ea76cfd93e6484fe928d8b55b0ff7573834e5bfaf92014227b7a00bf1cf635452201a400a105000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xa2df34ce378e2ffd82a2ac527f9a75bc78243d1e3e034c2913c614bb2cdc6adc, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c68010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c69010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c8e63a35b9d5b15309b4020e50cda15a77c9d5a781ee7c29f6da6f6c3635ff91553cab79e50e54e5463b9f9e6e07f74988a9fd1ad06180d0ca354ec32ee399d5400a400a505000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xa1edf60850286faa49a207a8bd0a9c21860320e073f445b970e04abcd1ff98da, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c69010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c6a010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c17fa23e4c12d474334d3895fb3edc0ae3dd761d60a04674108dbde58d54e0b8875a98afa3ce4b1f59ab0afda241ed1b05b31b2f5207aae6f5302724d672707c501a400a905000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xb71838528ef676d2318fe092c6a3087255dbe40c85b4f45a6621c06abfcf9fe0, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c6a010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c6b010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c39fb9303f9c69e47ae430348c498ed31e77d553e586c11ead47f825757aa51b13029e82f3bf3786446275ac1f599076b388e81a1d957837b98b94368b935f2de00a400ad05000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xab2dd34f6c0a3f4061dac8c0e96901ceb9d446eedbf3aa53e3c15537b3615c14, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c6b010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c6c010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92cf1ebfba4c9a6cdd25aa7b483ce608742d061848d49a4e945f495ac6a5cd966c3159ab399097d6ca9debed4810e2a375ccc314294e5a5cb0d7b45502a581f290d00a400b105000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0x0d6b88c27b7bf6ccabbfb8434835f5775eec2dc24ed460f6d10d9c352e5052b3, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c6c010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c6d010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c0230d6b8a4077d7ef37b19875b83bdc50e3308e066e395102a49e3b377fbf1d12cd3a775137d73599d3ca1017406a31ac301041c0b150070231cebc67be7c1bf01a400b505000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0x2c052046aaa2406dfe8078df29825175bd71ebc51f0639f8632f26a6bb741f82, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c6d010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c6e010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c3c288947b9a1d6ce56b041c110f0caa0a6f50cf6679a086519c12073570f669f02e979905f043418057e519284a3778362deadc78be9c1d33f58300fb9b84bc601a400b905000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xb47a79b6da79274b3aa70ff39960e28eb6910f21cda03b46adbce860723cca8e, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c6e010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c6f010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92ce69512874ffcf4abb6250a03f3a7d1c36e6cda59d6f82fecf917c7c4e1564399374ad2bfffa8f3921854f7b3a914fdc1b020005c26d3e283aa1a98b53eea2ec501a400bd05000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0xf32d45f412391f34849bf25a18e64e81b8d97ab1a8e75b77eb6997f821d4f5b7, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: TransactionSource::External, requires: [7a4a1533423e7f169e752cc51346f35195cbd92c6f010000], provides: [7a4a1533423e7f169e752cc51346f35195cbd92c70010000], data: 847a4a1533423e7f169e752cc51346f35195cbd92c3207a2793d58b441fca178d55b895f06cdbb06f1dafafb3a5037742110831554014f8f372e33e8448467b6c4205918bb80fb7e59c3e3701fde4cd682774b9f8501a400c105000a03537f17fb7fa5acbc6dec8b2fd1d64bbb6031d6d404}, Transaction { hash: 0x8cbf589cb6aa40e5e025ead12ce72e56f8b4a87d86119f42ccd410da7954b699, priority: 1459, valid_till: 41, bytes: 116, propagate: true, source: Trans...
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0x37195b0d66abf1afe635283776c5539638174c5db2b02dc032cde07a193c00b4] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0x064e4445eaa0b41a4b558631635bb333cfe75dd8448cfad430fa49fbdc6ac22e] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0xb589fd9e4aac2f29a780143abb332b7dfdfb65cc7562560cbd132cd47989f291] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0x259651a767b746c75a9463e3b61521775e5bd7f9d91c87236ef8251e88fbe034] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0x1ce94f2dda858eccff4a096facf155f1517aeaab702969ec0f8b47ed2bc75a36] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0x03ae9287f819a3b7b7a2b1d0e3c3d24a525d75ccf4e521d293bc6cf7835808ee] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0x5bb2b014407d60458fefcc3fad705230d6bb438e7299876f799be6fa88d688ee] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0xee06f8a85e4b44543cedd50b2fc36d619dc74345b9e3b2c1bee6243d98263850] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0xcd575fc69bfa9b39787948ca92cd7c71a2f0129ad2f4a4e938bf1cfcc0c1f9fe] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0xa2df34ce378e2ffd82a2ac527f9a75bc78243d1e3e034c2913c614bb2cdc6adc] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0xa1edf60850286faa49a207a8bd0a9c21860320e073f445b970e04abcd1ff98da] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0xb71838528ef676d2318fe092c6a3087255dbe40c85b4f45a6621c06abfcf9fe0] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0xab2dd34f6c0a3f4061dac8c0e96901ceb9d446eedbf3aa53e3c15537b3615c14] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0x0d6b88c27b7bf6ccabbfb8434835f5775eec2dc24ed460f6d10d9c352e5052b3] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] [0x2c052046aaa2406dfe8078df29825175bd71ebc51f0639f8632f26a6bb741f82] Extrinsic invalid
2023-11-09 17:22:18.102 DEBUG tokio-runtime-worker txpool: [Parachain] 
...

and from this point onwards, the pool behaves like this:

2023-11-09 17:22:18.131 DEBUG tokio-runtime-worker txpool: [0x530acb65e7ec058420735c66830285dd49b704982a0b5a7d9228774bcba6cc51] Importing to future
2023-11-09 17:22:18.131 TRACE tokio-runtime-worker txpool: [0x530acb65e7ec058420735c66830285dd49b704982a0b5a7d9228774bcba6cc51] Future
2023-11-09 17:22:18.131 DEBUG tokio-runtime-worker txpool: Pool Status: PoolStatus { ready: 0, ready_bytes: 0, future: 1, future_bytes: 116 }
2023-11-09 17:22:18.131 TRACE tokio-runtime-worker txpool: [0xc446dc919f96de712cd70ec97f7cad56e3377c119870aaa353af6282e187df40] WaitingTransaction { imported_at: Instant { tv_sec: 19636, tv_nsec: 328659125 }, transaction: Transaction { hash: 0xc446dc919f96de712cd70ec97f7cad56e3377c119870aaa353af6282e187df40, priority: 1459, valid_till: 42, bytes: 116, propagate: true, source: TransactionSource::External, requires: [2be0efdc475edd252c5fbcf9366efb2d7add6ad890010000], provides: [2be0efdc475edd252c5fbcf9366efb2d7add6ad891010000], data: 842be0efdc475edd252c5fbcf9366efb2d7add6ad8cb5750528d43432c5552c69f13106b249ba367b895a379a8d82bc0a602e8b2d27fd51cb978c7b59a448676d5e96886bcbf4fcd0a10a3000d36623d4f3c0f928700b4004506000a034d2c74d87e9de5d38dd589eb66110a7cf5201e7204}, missing_tags: {2be0efdc475edd252c5fbcf9366efb2d7add6ad890010000}}
2023-11-09 17:22:18.131 DEBUG tokio-runtime-worker txpool: [0xc446dc919f96de712cd70ec97f7cad56e3377c119870aaa353af6282e187df40] Importing to future
2023-11-09 17:22:18.131 TRACE tokio-runtime-worker txpool: [0xc446dc919f96de712cd70ec97f7cad56e3377c119870aaa353af6282e187df40] Future
2023-11-09 17:22:18.131 DEBUG tokio-runtime-worker txpool: Pool Status: PoolStatus { ready: 0, ready_bytes: 0, future: 2, future_bytes: 232 }

all extrinsics were sent as immortal.

[bkchr]

Looks exactly like the issue I described above. You are building a fork and then you include some transaction with a future nonce. This leads then to all its descendants being removed as well. You could for example not have transaction that depend on each other (by the nonce) and then you would not see this issue.

[ggwpez]

So if you use the sTPS tool then it should not happen, or? Since that is never re-using accounts.

[bkchr]

Yes

[bernardoaraujor]

sending txs from different accounts solved the issue.

[bkchr]

@michalkucharczyk could you give some short update on your status?

[michalkucharczyk]

I am working (fork) on implementation of idea that was proposed in: https://hackmd.io/@_FY3-hvwQZ6cX_4n8zYUNA/HJqUWj4_s.

Current status is:

• submitting transaction is working,
• fork handling and finalization with views is implemented ,
• tx events framework is working in general, however I expect some tweaks will be required,

Next steps are: implementation of revalidation, removing stale transactions from tx-pool and cleanup of the code.

[bkchr]

Thank you! :)

[Polkadot-Forum]

This issue has been mentioned on Polkadot Forum. There might be relevant details there:

https://forum.polkadot.network/t/parity-tech-update-for-february/6630/1

[noandrea]

with referenda #374 on Kusama, we are ready to get to 6s block time on Moonriver, but this issue is a blocker, can you share an update on this one @michalkucharczyk please?

[michalkucharczyk]

Quick update for now:

1. I have working fork-aware txpool crate with (hopefully) most of the scenarios tested on unit-test level,
2. Some pieces are missing though (main points from my todo list):
   • obeying txpool size limits,
   • properly handling finalization stalls (should not be difficult, but I need to think about this),
   • re-check metrics sent out, probably adjust them with some forks-handling-related stats,
   • check if there is any performance regression (also during warp-sync),
3. Need to integrate this work with the client, do some basic and stress-tests with stps tool to check if problems are gone,
4. Some memory optimizations needs to be done (I have excessive clones which I want to get rid of),
5. Probably validation cache may be needed (but I need to measure it),

I'll try to focus on opening the PR that would allow to do some preliminary testing and at least check if the original problems are solved with this. Obviously not all of the above steps needs to be accomplished to allow this. I still need some time (days) to do it.

[bkchr]

with referenda #374 on Kusama, we are ready to get to 6s block time on Moonriver, but this issue is a blocker, can you share an update on this one @michalkucharczyk please?

This bug should already appear without async backing. How do you want to approach async backing? Will you change your slot time to 6s or will you use the unincluded segment and stay with 12s slot time? If you go to 6s, this txpool behavior should not change.

[girazoki]

with referenda #374 on Kusama, we are ready to get to 6s block time on Moonriver, but this issue is a blocker, can you share an update on this one @michalkucharczyk please?

This bug should already appear without async backing. How do you want to approach async backing? Will you change your slot time to 6s or will you use the unincluded segment and stay with 12s slot time? If you go to 6s, this txpool behavior should not change.

Hey @bkchr , you mean that if we use a 6 second slot we should not see this bug in the tx-pool? I agree that this happens even without asynchronous backing, we are suffering this currently and we still did not reduce the slot time to 6s

[bkchr]

you mean that if we use a 6 second slot we should not see this bug in the tx-pool?

No, you will still have this issue, but it should not change to what you see right now. However, if you stay at 12s and use unincluded segment of 2, it may gets worse. I mean the underlying issue is the same, but you may include more tx and thus others are failing etc.

Generally this issue probably only appears in production networks if someone is "spamming" the tx pool. For sure someone could be unlucky, but you also got multiple collators and thus, they may get included by someone else.

[wilwade]

if someone is "spamming" the tx pool.

At least on Frequency that focuses on companies instead of end users interacting with the chain, dumping a lot of transactions onto the chain at once (aka "spamming") is a fairly common use case.

[bkchr]

I mean this should not be a complaint and I clearly did not thought about all the possibilities :see_no_evil:

@wilwade do you see this being a big problem in the "wild"? How many collators do you have running?

[bkchr]

Just for myself and anyone that is interested, writing down here some information:

This issue actually exists in two ways:

1. For some time we included parachain blocks without setting them directly as best block and instead waited for the relay chain to have them backed and then set them as best block. The problem with this is that we did not execute the maintenance for non best blocks. Thus we build X + 1 probably on the same set of transactions as X. When you find an invalid transaction we automatically remove the entire subtree. The case described here should actually not happen anymore since this commit, because we now set the best block directly and maintenance is running.
2. The second case is actually if maintenance is running because we set the best block. We will remove transactions that got included in a block. The special case now for parachains is that their block production is mainly driven by relay chain block import. This means that if you import a relay chain fork, the same node will produce multiple parachain blocks on the same height and then this happens.

Leaving this here for future me and others :D

[wilwade]

@bkchr

@wilwade do you see this being a big problem in the "wild"? How many collators do you have running?

We have caught it on our Testnet (Paseo based) with just two collators + one RPC (all peering). Have had a hard time recreating consistently however.

Haven't seen it in mainnet yet to my knowledge, however, we might not hear about it and the slamming we do on testnet isn't yet happening on mainnet as much (coming in the next few weeks).

[makinghappen]

any chance for this to be fixed soon?

[michalkucharczyk]

any chance for this to be fixed soon?

Still in progress.

[Polkadot-Forum]

This issue has been mentioned on Polkadot Forum. There might be relevant details there:

https://forum.polkadot.network/t/paritytech-update-for-april/7646/1

[girazoki]

@michalkucharczyk @bkchr is there any news on this? This feels quite important for chains that have a low number of collators (e.g., what we expect for parathreads for instance)

[girazoki]

Related to this issue, is there anything we can tweak in the parameters of an internal relay (based of fast-rococo) so that we see less often re-orgs?

[skunert]

Related to this issue, is there anything we can tweak in the parameters of an internal relay (based of fast-rococo) so that we see less often re-orgs?

I think there is nothing you can do about this. Fast-rococo has a low session duration and we do not choose unincluded parents in the parachain that have a relay parent in the last session. So once the session changes you will start building on the included block again, which will cause a fork.

[michalkucharczyk]

@michalkucharczyk @bkchr is there any news on this? This feels quite important for chains that have a low number of collators (e.g., what we expect for parathreads for instance)

The work is still in progress, I am now doing some stress tests, and will be opening the PR soon.

[michalkucharczyk]

Status update: I have a working implementation. My plan is to add a new command line parameter:

      --pool-type <POOL_TYPE>
          The type of transaction pool to be instantiated

          [default: single-state]

          Possible values:
          - single-state: Uses a legacy, single-state transaction pool
          - fork-aware:   Uses a fork-aware transaction pool

This would allow for some transitioning period during which I can further stabilize and likely do some bugs fixing before we do a switch to fork-aware transaction pool.

To make review smoother and easier I split my work into two parts:

• refactoring sc-transcation-pool crate and allowing to use transaction pool trait object across the codebase (#4561) - no logic changes, just preparing ground for integration,
• addition fork-aware txpool into sc-transcation-pool crate. The PR will be opened once previous one is reviewed/accepted and merged.

[albertov19]

Hey @michalkucharczyk - Any updates? Thanks in advance

[michalkucharczyk]

Hey @michalkucharczyk - Any updates? Thanks in advance

PR was opened #4639. I think core work is done, now polishing the code to get closer to production quality. There is a to-do list to allow progress tracking.