Investigate why transactions aren't counted

[bredamatt]

When testing tps and sender locally against a natively running zombienet, I encountered an issue with the tps counter.

The tps binary was expecting more transactions than it counted, even if the sender successfully sent all transactions.
This appears to be because counting the transfers takes longer than 12s on average, since new CandidateIncluded events may happen, but I am not entirely certain. It could also be because some transactions are dropped.

In principle, with the current logic, all transfers are counted before the next Candidate is processed. If counting 1094 transfers takes longer than 12s I would be quite surprised since it seems to work just fine when submitting fewer transactions.

Below are the logs when submitting 10,000 transactions from 1 sender. It should be noted this problem does not occur when sending 1000, 2000, or 3000 transactions, so I doubt it has anything to do with the calculation speed, but rather is likely because of dropped transactions. The sender also did not spend more than roughly 1s to send all the 10,000 transactions.

The reason why this is an issue is because when running these parachain TPS tests with zombienet, the tps binary is not receiving an exit signal, meaning the zombienet .dsl tests cannot pass, which means it would not be possible to have high number of transactions submitted in CI.

Yet, this is not really a fix as it seems to be of larger concern related to the memory pool and the lifetime of the extrinsics given that parablock numbers increment 1 by 1.

[2023-06-09T16:41:24Z DEBUG tps] New ParaHead: 0x275496df43e4dbff026ff0ff514029dc1423065f5f17ede1d87c721a35077dc5 for ParaId: Id(1000)
[2023-06-09T16:41:24Z DEBUG tps] Received ParaHead: 0x275496df43e4dbff026ff0ff514029dc1423065f5f17ede1d87c721a35077dc5
[2023-06-09T16:41:24Z DEBUG tps] Parablock time estimated at: 12020ms
[2023-06-09T16:41:24Z DEBUG tps] Checking extrinsics in parablock: 7
[2023-06-09T16:41:30Z DEBUG tps] Found 1094 transfers in parablock: 7
[2023-06-09T16:41:30Z INFO  tps] TPS on parablock 7: 91.01497
[2023-06-09T16:41:30Z INFO  tps] Total transactions processed: 6390
[2023-06-09T16:41:30Z DEBUG tps] Remaining transactions to process: 3610
[2023-06-09T16:41:36Z DEBUG tps] New ParaHead: 0xcdfe41469f2d3fa5f8ab649c16eb06fbbf72150377a5fe887a5c976b23c1f0d6 for ParaId: Id(1000)
[2023-06-09T16:41:36Z DEBUG tps] Received ParaHead: 0xcdfe41469f2d3fa5f8ab649c16eb06fbbf72150377a5fe887a5c976b23c1f0d6
[2023-06-09T16:41:36Z DEBUG tps] Parablock time estimated at: 11982ms
[2023-06-09T16:41:36Z DEBUG tps] Checking extrinsics in parablock: 8
[2023-06-09T16:41:38Z DEBUG tps] Found 708 transfers in parablock: 8
[2023-06-09T16:41:38Z INFO  tps] TPS on parablock 8: 59.08863
[2023-06-09T16:41:38Z INFO  tps] Total transactions processed: 7098
[2023-06-09T16:41:38Z DEBUG tps] Remaining transactions to process: 2902
[2023-06-09T16:41:48Z DEBUG tps] New ParaHead: 0x0c19adca9df721dd37263b707c39d031272547ed3ce8ca4ff582417065996866 for ParaId: Id(1000)
[2023-06-09T16:41:48Z DEBUG tps] Received ParaHead: 0x0c19adca9df721dd37263b707c39d031272547ed3ce8ca4ff582417065996866
[2023-06-09T16:41:48Z DEBUG tps] Parablock time estimated at: 12021ms
[2023-06-09T16:41:48Z DEBUG tps] Checking extrinsics in parablock: 9
[2023-06-09T16:41:48Z DEBUG tps] Found 0 transfers in parablock: 9

As can be seen in the logs there was a total of 2909 transactions remaining to be calculated for ParaId: Id(1000). After this last candidate with transfers was checked, no further candidates included any future transfers.

[bredamatt]

Note: The era of the transfers, and how the collators bundle transactions from the memory pool might be worthwhile angles to investigate here.

[bredamatt]

We can enforce that all transactions either get included within a certain number of blocks by specifying a Mortal era, and if not they are dropped. There's some overhead associated with implementing this though:

Regarding when the mortality period should start, we need to fetch the last finalized hash, and set that as the beginning. Alternatively we hard code a value, but that's susceptible to erroneously choosing the start period.

Secondly, how many transactions we can fit in one block, and the total number of transactions sent determines in expectation how long we should specify the period as. Theoretically a precise period = (max_transfers_in_block / total_transfers_expected). Note however, that max_transfers_in_block would be purely theoretical since it's based on estimated dispatchable weights and PoV size limits.

End of the day, even if we introduce this, it won't change the issue. Alternative solutions can be used such as a time-based approach.