Block 15083355 had a length of under 3.1 seconds (the very first THORChain block under 5 seconds)
Summary of the below:
Though reflected by 15083355's timestamp relative to 15083354's,
this appears to be due to a node committing 15083353 early
(with the minimum +2/3 votes (69/102) for 15083353, slashing 33 nodes for a missed block)
(and so proposing 15083354 early)
since each block's timestamp is the median of the previous block's votes' timestamps.
https://thornode-v1.ninerealms.com/blocks/15083354
"time": "2024-03-12T17:36:47.985023643Z",
https://thornode-v1.ninerealms.com/blocks/15083355
"time": "2024-03-12T17:36:51.081596338Z",
Time between blocks: 3.09657270 seconds.
Why I perceive this to be "unprecedented for THORChain":
https://flipsidecrypto.xyz/Multipartite/q/4nPdDJlJcSfj/block-lengths-times-per-date-ignores-day-spanning-chain-halts
2024-03-12 is the first day in THORChain's history which has ever had a block length shorter than 5 seconds.
Relevant links:
https://github.com/tendermint/tendermint/issues/5911#issuecomment-967615517
It sounds like what you're trying to accomplish should be able to be done with
timeout-commit
andskip-timeout-commit=false
. This should make sure that all validators with the param configured wait for the full timeout-commit duration.
https://gitlab.com/thorchain/thornode/-/blob/v1.128.0/config/config.toml.tmpl#L354-355
# Make progress as soon as we have all the precommits (as if TimeoutCommit = 0)
skip_timeout_commit = false
https://gitlab.com/thorchain/thornode/-/blob/v1.128.0/config/config.toml.tmpl#L343-346
# How long we wait after committing a block, before starting on the new
# height (this gives us a chance to receive some more precommits, even
# though we already have +2/3).
timeout_commit = "{{ .Consensus.TimeoutCommit }}"
https://gitlab.com/thorchain/thornode/-/blob/v1.128.0/config/default.yaml#L339-340
consensus:
timeout_commit: 5s
My default perception is that a block should never be committed with a timestamp which is under 5s from the timestamp of the previous block,
unless 2/3rds of Active nodes have (/manually) changed this configuration.
Block 15083354 indicates 33 absent (null
) votes for block 15083353.
According to
https://thornode-v1.ninerealms.com/thorchain/nodes?height=15083353
there were 102 Active nodes at the time, indicating that 34 could be absent and still have a 2/3rds supermajority;
however, the '+2/3' appears to refer to '2/3 plus one'.
https://docs.tendermint.com/v0.34/tendermint-core/validators.html#committing-a-block
+2/3 is short for "more than 2/3"
While any +2/3 set of precommits for the same block at the same height&round can serve as validation, the canonical commit is included in the next block (see LastCommit).
sigs1=$(curl -s https://thornode-v1.ninerealms.com/blocks/15083354 | jq '.block.last_commit.signatures')
sigs2=$(curl -s https://thornode-v1.ninerealms.com/blocks/15083355 | jq '.block.last_commit.signatures')
echo $sigs1 | jq '[.[] | select (.signature != null)] | sort_by(.timestamp)[0].timestamp' -r
2024-03-12T17:36:47.92642253Z
echo $sigs1 | jq '[.[] | select (.signature != null)] | sort_by(.timestamp)[-1:][0].timestamp' -r
2024-03-12T17:36:48.091661552Z
echo $sigs1 | jq '[.[] | select (.signature != null)] | length'
69
echo $sigs1 | jq '[.[] | select (.signature != null)] | sort_by(.timestamp)[(69 - 1) / 2].timestamp' -r
2024-03-12T17:36:47.985023643Z
curl -s https://thornode-v1.ninerealms.com/blocks/15083354 | jq '.block.header.time' -r
2024-03-12T17:36:47.985023643Z
echo $sigs2 | jq '[.[] | select (.signature != null)] | sort_by(.timestamp)[0].timestamp' -r
2024-03-12T17:36:50.995591123Z
echo $sigs2 | jq '[.[] | select (.signature != null)] | sort_by(.timestamp)[-1:][0].timestamp' -r
2024-03-12T17:36:52.208980702Z
echo $sigs2 | jq '[.[] | select (.signature != null)] | length'
100
echo $sigs2 | jq '[.[] | select (.signature != null)] | sort_by(.timestamp)[(100 / 2) - 1].timestamp' -r
2024-03-12T17:36:51.081596338Z
echo $sigs2 | jq '[.[] | select (.signature != null)] | sort_by(.timestamp)[100 / 2].timestamp' -r
2024-03-12T17:36:51.08329812Z
curl -s https://thornode-v1.ninerealms.com/blocks/15083355 | jq '.block.header.time' -r
2024-03-12T17:36:51.081596338Z
The block timestamps were consistent with the medians of the vote timestamps for the previous block
in the last_commit
information
(which indicates the previous block's height
).
The earliest vote for block 4 (recorded in block 5)
was just over 3 seconds from the timestamp of block 4 (determined from the median of block 3's votes).
(50.995591123 − 47.985023643 = 3.01056748)
Perhaps (though perhaps not) relevant for those 3 seconds:
https://gitlab.com/thorchain/thornode/-/blob/v1.128.0/config/config.toml.tmpl#L331-332
# How long we wait for a proposal block before prevoting nil
timeout_propose = "3s"
( Perhaps refer to Tendermint's 2018 https://arxiv.org/abs/1807.04938 regarding PROPOSAL/PREVOTE/PRECOMMIT messages.)
So, the projected timeline:
Normal node proposes block 3 (with timestamp based on block 2's votes).
Abnormal node commits block 3 (with timestamp based on block 3's votes) as soon as the +2/3 threshold is reached, as though the below is true
.
https://gitlab.com/thorchain/thornode/-/blob/v1.128.0/config/config.toml.tmpl#L354-355
# Make progress as soon as we have all the precommits (as if TimeoutCommit = 0)
skip_timeout_commit = false
Having committed block 3 earlier than usual, the abnormal node then proposes block 4 earlier than usual,
with only the +2/3 threshold for block 3 votes,
and a proposed timestamp from the median of those block 3 votes.
After 3 seconds, normal nodes begin voting for block 4.
A normal node commies block 5 with normal timing, after 100/102 nodes (almost all) have voted for it.
Block 5's timestamp is based on the median of block 4's votes;
as block 3 was committed early and block 4 proposed early (by the abnormal node),
block 5's timestamp is slightly over 3 seconds later than block 4's, rather than over 5 seconds.
I question why an abnormal node that commits-and-proposes early doesn't become the first block proposer for every block, single-handedly shortening every block interval.
Is there a mechanism which keeps track of block proposers and avoids letting a single proposer propose many/consecutive blocks?
(I am glad that one node hopefully cannot made block production stall indefinitely, as presumably a normal node would propose a block with normal timing first.)
WITH
timestamps AS (
SELECT DISTINCT DATE(reftable.block_timestamp) AS date, block_id,
1e-6 * DATEDIFF('us', '1970-01-01', reftable.block_timestamp) AS block_timestamp_as_seconds
FROM (thorchain.defi.fact_rewards_events AS reftable INNER JOIN thorchain.core.dim_block
ON reftable.dim_block_id = dim_block.dim_block_id)
--Bond rewards, so should be present exactly once every block.
)
SELECT date, block_id,
(block_timestamp_as_seconds - LAG(block_timestamp_as_seconds) OVER(order by block_id ASC) ) / (block_id - LAG(block_id) OVER(order by block_id ASC) ) AS seconds_per_block
FROM timestamps
ORDER BY seconds_per_block ASC
LIMIT 20
This was indeed a one-off; the shortest block time was
2024-03-12 block 15083355 at 3.096572 seconds,
followed by (years earlier)
2021-04-12 block 25146 at 5.274647 seconds.
At the moment I remember puzzled/concerned regarding how a node's early commit could occur for only a single block.
(If due to changed configuration, then why not affecting one block every 102 blocks on average,
or else (worse) every single block pre-empting other block proposals?)
(Rather than configuration settings, could this be premature block proposal relating to a shut down when waiting to propose a block?
If so, why then has this not happened for other nodes before?)
Fullnode (local timestamp) THORNode logs for 15083354 and the blocks flanking it
(nothing in the log contents appearing unusual at this time):
2024-03-12_Block_15083353__fullnode__THORNode_logs.log