blockchain-node slow down over time

[ci-work]

replaying the ledger, and after running for roughly 12 hours, process time for each block is roughly 1.8 seconds (note the gap between timestamps):

2021-12-17 13:49:31.830 [info] <0.1338.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 114 post took 187 ms height 970820
2021-12-17 13:49:33.420 [info] <0.1338.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 148 post took 87 ms height 970821
2021-12-17 13:49:35.234 [info] <0.1338.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 225 post took 150 ms height 970822
2021-12-17 13:49:36.964 [info] <0.1338.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 109 post took 116 ms height 970823
2021-12-17 13:49:38.637 [info] <0.1338.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 187 post took 78 ms height 970824

however, after restart this drops to 0.6-0.8 seconds per block:

2021-12-17 14:11:31.843 [info] <0.1339.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 594 post took 251 ms height 970930
2021-12-17 14:11:32.452 [info] <0.1339.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 150 post took 116 ms height 970931
2021-12-17 14:11:33.131 [info] <0.1339.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 98 post took 126 ms height 970932
2021-12-17 14:11:34.082 [info] <0.1339.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 246 post took 126 ms height 970933
2021-12-17 14:11:34.848 [info] <0.1339.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 158 post took 92 ms height 970934

I'm unclear as to the specific reason, but have observed it at all heights from genesis over the last week.

The slow down is roughly 2x after 12 hours, roughly 3x after 24 hours, etc.

This may be specific to blockchain-node and a minor issue, or it may be caused by something in blockchain-core and only visible via blockchain-node since it is relatively light and not doing any other work, processing blocks rapidly, in which case chain consuming and ledger building programs will be affected, and perhaps a bigger issue.

[madninja]

It's hard to tell what the variance is. Remember that the number of transaction has gone up over time, and that the number of witness receipts also went up as p2p fixes were rolled out. In addition, chain var changes also activated alternate code-paths over time that affect block processing time.

[ci-work]

Indeed, hence why showing sequential blocks here in logs and the restart, I'd always put it down to the same reasons, but then seeing that a series of blocks could be 1.8s then restart and the subsequent blocks ~3x less was the reason for the issue raise :)