Investigate block production rate

[stbrody]

We expect blocks to be produced 1 per second. But on testnet we are observing 2 blocks per second instead. We need to understand the implications of this, and ideally find out why this is happening and potentially change it to be the 1 per block that we expect

[stbrody]

Our credit accounting is based on byte/blocks. Our TTLs on blobs are in terms of ChainEpochs, which I believe correspond to numbers of blocks. Are either of these affected by the block production rate?

[stbrody]

Sounds like the Portal (fka Studio) displays some UIs around the duration that data will be stored that does math based on an assumption of 1 second block times.

[stbrody]

Turning block production rate down to 1 per second will also likely help the block explorer keep up with indexing.

[sanderpick]

Needs investigation, but perhaps the explorer is just indexing faster than 1s, and the chain is still going at 1s?

[joewagner]

@stbrody @sanderpick I've got a little bit of insight here.

I used a combination of the explorer's block inspector, and the validator's evm api endpoint to get an understanding of what's going on with block production.

Below is some data from the explorer showing a series of blocks and timestamps. This spans a little over ten seconds.

1449309    2025-03-03T20:10:39.000000Z

1449310    2025-03-03T20:10:40.000000Z
1449311    2025-03-03T20:10:41.000000Z
1449312    2025-03-03T20:10:42.000000Z
1449313    2025-03-03T20:10:43.000000Z
1449314    2025-03-03T20:10:43.000000Z
1449315    2025-03-03T20:10:44.000000Z
1449316    2025-03-03T20:10:44.000000Z
1449317    2025-03-03T20:10:45.000000Z
1449318    2025-03-03T20:10:46.000000Z
1449319    2025-03-03T20:10:47.000000Z
1449320    2025-03-03T20:10:48.000000Z
1449321    2025-03-03T20:10:48.000000Z
1449322    2025-03-03T20:10:49.000000Z
1449323    2025-03-03T20:10:49.000000Z
1449324    2025-03-03T20:10:50.000000Z

1449325    2025-03-03T20:10:51.000000Z

// notice the timestamps all have 0 milliseconds

After looking at a few 10 second intervals of blocks it seems that about 15 blocks are mined every 10 seconds, according to the inspector.

---

I also used curl to make requests directly to the evm api.

Here is data for block 1449313:

curl https://evm.node-0.testnet.recall.network/   -X POST   -H "Content-Type: application/json"   --data '{"method":"eth_getBlockByNumber","params":["0x161D61",false],"id":1,"jsonrpc":"2.0"}'

> {"jsonrpc":"2.0","result":{"hash":"0xe97535e2d01b90c7fd64dfcbe3074c7b209db601249a632d524f19b282795878","parentHash":"0xeed0c9185adf1465927c0d7e7e51ae60c4bcb81c203b25ef11d0cce8eb9590c6","sha3Uncles":"0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347","miner":"0xf26f9190b27b9b00074d543e8fc6794f1abb8815","stateRoot":"0xba2a1925ae51e479e2313a7da914033080e6abc58f76b73e404e74a4ca6dbf6b","transactionsRoot":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","receiptsRoot":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","number":"0x161d61","gasUsed":"0x0","gasLimit":"0x0","extraData":"0x","logsBloom":"0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","timestamp":"0x67c60cc3","difficulty":"0x0","totalDifficulty":"0x0","sealFields":[],"uncles":[],"transactions":[],"size":"0x0","mixHash":"0x0000000000000000000000000000000000000000000000000000000000000000","nonce":"0x0000000000000000","baseFeePerGas":"0x7"},"id":1}

And here is data for block 1449314:

curl https://evm.node-0.testnet.recall.network/   -X POST   -H "Content-Type: application/json"   --data '{"method":"eth_getBlockByNumber","params":["0x161D62",false],"id":1,"jsonrpc":"2.0"}'

> {"jsonrpc":"2.0","result":{"hash":"0x3d95d075e35d9d2f29af0ecebef4b278349b7a88bc3e38493741e22f05b9ddda","parentHash":"0xe97535e2d01b90c7fd64dfcbe3074c7b209db601249a632d524f19b282795878","sha3Uncles":"0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347","miner":"0xf26f9190b27b9b00074d543e8fc6794f1abb8815","stateRoot":"0xfde558bed6f4e9f39204a85f28c96b3a7f905a0bb6724d67e6acf822285cbb1d","transactionsRoot":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","receiptsRoot":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","number":"0x161d62","gasUsed":"0x0","gasLimit":"0x0","extraData":"0x","logsBloom":"0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","timestamp":"0x67c60cc3","difficulty":"0x0","totalDifficulty":"0x0","sealFields":[],"uncles":[],"transactions":[],"size":"0x0","mixHash":"0x0000000000000000000000000000000000000000000000000000000000000000","nonce":"0x0000000000000000","baseFeePerGas":"0x7"},"id":1}

As you can see the timestamps are the same for both of these, which is also what the explorer shows.

---

Thoughts/Questions:

• Why are timestamps only using 1 second precision? The evm api returns json with "timestamp":"0x67c60cc3", which is 1741032643 in decimal. This is unix epoch time in seconds. I would expect the timestamp to be in the mili-second variant of unix epoch time.
• Regardless of block timestamp precision, we are getting about 15 blocks per 10 seconds, a.k.a 90 blocks a minute or 1.5bps. This is closer to 1bps than we thought, but still significantly off of our target. Which means we either need to find a way to change the bps or change the places in our UIs that indicate storage per month numbers based on a 1bps rate.

[sanderpick]

Thanks for this @joewagner. From what I understand many factors contribute to block times, including validator latency. @joewagner can you do the same analysis on localnet? I'm curious if there's a difference.

There is a cometbft setting, create_empty_blocks_interval. By default it's 0s, ie, "as fast as the app allows". We can try setting it to 1s:

create_empty_blocks_interval = "1s"

For localnet, you'd have to do this via env var here: https://github.com/recallnet/ipc/blob/main/infra/fendermint/scripts/cometbft.toml.

[joewagner]

Sorry, I meant to respond here last night.

Thanks for this @joewagner. From what I understand many factors contribute to block times, including validator latency. @joewagner can you do the same analysis on localnet? I'm curious if there's a difference.

I tried localnet, and it's almost exactly 1bps. It was actually closer to 0.95bps, but that seems close enough.
So I guess this means the factors affecting testnet different enough to cause a significant change.

There is a cometbft setting, create_empty_blocks_interval. By default it's 0s, ie, "as fast as the app allows". We can try setting it to 1s:

create_empty_blocks_interval = "1s"

For localnet, you'd have to do this via env var here: https://github.com/recallnet/ipc/blob/main/infra/fendermint/scripts/cometbft.toml.

I tried this, but I can't seem to get cometbft to accept the config value since our script doesn't use a toml config file. There's a flag called --consensus.create_empty_blocks_interval but it doesn't seem to have any effect on block times.

[stbrody]

I tried localnet, and it's almost exactly 1bps. It was actually closer to 0.95bps, but that seems close enough.
So I guess this means the factors affecting testnet different enough to cause a significant change.

This is the piece that really has me confused. If anything I would have expected the real testnet to produce blocks slower since it has real load, but the fact that it's making blocks faster than localnet is really strange. Are we sure there isn't just some simple configuration that's different between the two somehow?

[sanderpick]

without create_empty_blocks_interval = "1s", the validators just work as fast as possible... so my guess is that the testnet machines being so powerful is the root cause.

@joewagner the new testnet from last week should have the create_empty_blocks_interval = "1s" config setting... can you take another measurement?

[joewagner]

without create_empty_blocks_interval = "1s", the validators just work as fast as possible... so my guess is that the testnet machines being so powerful is the root cause.

@joewagner the new testnet from last week should have the create_empty_blocks_interval = "1s" config setting... can you take another measurement?

It does not seem like the create_empty_blocks_interval = "1s" setting is preventing blocks from being produced too fast.
When i take some random samplings of 10 second intervals, it varies between 1bps and 1.5bps. Which is a little slower than last time i looked, but probably just an artifact of when I'm taking samples.
Maybe the setting is designed to ensure the blocks are produced at least once per second?

[joewagner]

Update:
I've been watching block rates, and now that the network has been up for over a week the block rates are stabilizing at an appropriate value. The average block time is now at 1.2 seconds (0.83 bps). This issue might not actually be a problem once we stop resetting the testnet.

[stbrody]

Seems like no matter what the block production rate is never going to be perfectly one second. We have several places in our system that assume 1 block = 1 second (blob TTLs, inflation rate calculations, etc). All those places are now suspect. We might need to seriously audit all the places that assume a consistent block time and rethink how we are handling them.

[stbrody]

For blob TTLs, can we just use wallclock time instead of number of blocks?

For inflation rate it might not be so straightforward but we still need to revisit this.

@sanderpick

[sanderpick]

I think we could but same security concern applies. the tx result needs to be deterministic. we could try it. agreed that we need this for the "predictable pricing" promise.

re: inflation rate, what's the benefit here? do other chains use wall clock time for this? i haven't heard of that before