Implement BFT time by milosevic · Pull Request #2203 · tendermint/tendermint

milosevic · 2018-08-10T18:12:57Z

Updated all relevant documentation in docs
Updated all code comments where relevant
Wrote tests
Updated CHANGELOG_PENDING.md

Fix #2013.

melekes · 2018-08-13T09:31:02Z

blockchain/store_test.go

 	part2       = partSet.GetPart(1)
 	seenCommit1 = &types.Commit{Precommits: []*types.Vote{{Height: 10,
-		Timestamp: time.Now().UTC()}}}
+		Timestamp: types.Now()}}}


Maybe it will be better to call this types.TimeNow() or create a time subpackage, so this will be tmtime.Now()

melekes · 2018-08-13T09:32:04Z

config/config.go

 	PeerQueryMaj23SleepDuration int `mapstructure:"peer_query_maj23_sleep_duration"`
+
+	// Block time parameters in milliseconds
+	BlockTimeIota int `mapstructure:"blocktime_iota"`


description is missing

melekes · 2018-08-13T09:32:32Z

config/config.go

 	return cfg
 }

+// MinValidVoteTime returns the minimum acceptable block time. See the BFT time spec.


link to BFT time spec?

melekes · 2018-08-13T09:33:43Z

consensus/state.go

 func (cs *ConsensusState) signVote(type_ byte, hash []byte, header types.PartSetHeader) (*types.Vote, error) {
 	addr := cs.privValidator.GetAddress()
 	valIndex, _ := cs.Validators.GetByAddress(addr)
+	timestamp := cs.voteTime()


why create additional variable?

You are right, it can be inlined.

melekes · 2018-08-13T09:35:43Z

consensus/wal_test.go


 	data := nBytes(n)
-	enc.Encode(&TimedWALMessage{Msg: data, Time: time.Now().Round(time.Second)})
+	enc.Encode(&TimedWALMessage{Msg: data, Time: time.Now().Round(time.Second).UTC()})


why not use tmtypes.Now() here?

The difference seems to be .Round(time.Second) where in types.Now() we do Round(0)

Is there some reason we need to round to the nearest second? Or let's just use tmtypes.Now ?

libs/log/tmfmt_logger.go

melekes · 2018-08-13T09:39:45Z

state/state.go

 	return block, block.MakePartSet(state.ConsensusParams.BlockGossip.BlockPartSizeBytes)
 }

+func MedianTime(commit *types.Commit, validators *types.ValidatorSet) time.Time {


documentation is missing

melekes · 2018-08-13T09:45:16Z

ebuchman

Great start, thanks Zarko!

Only other thing is it seems the changes could have been better separated into distinct commits - ie. one to switch over to types.Now(), another for the BFT time stuff. Not a big deal though.

ebuchman · 2018-08-14T22:52:27Z

consensus/state.go

+	now := types.Now()
+	minVoteTime := now
+	// TODO: We should remove next line in case we don't vote for v in case cs.ProposalBlock == nil,
+	// even if cs.LockedBlock != nil. See https://github.com/tendermint/spec.


Not sure I follow

In the spec we don't vote for lockedBlock in case we don't agree with Proposal. In case we decide to align with the spec (which I would suggest as Prevoting always for lockedBlock is optimisation which is not clear how much it brings), then the logic here can be simplified as it will only depend on ProposalBlock.

ebuchman · 2018-08-14T22:53:21Z

docs/spec/consensus/bft-time.md

 the voting power is not uniform (one process one vote), a vote message is actually an aggregator of the same votes whose 
-number is equal to the voting power of the process that has casted the corresponding votes message. 
+number is equal to the voting power of the process that has casted the corresponding votes message.
+When computing weighted median, only votes with to `vote.BlockID = block.LastCommit.BlockID` are taken into account. 


with to -> with

libs/log/tmfmt_logger.go

ebuchman · 2018-08-14T22:56:45Z

state/state.go


+	// Set time
+	if height == 1 {
+		block.Time = types.Now()


should we consider genesis time in case its in the future ?

Makes sense.

ebuchman · 2018-08-14T22:57:55Z

state/state.go

+	for _, vote := range commit.Precommits {
+		if vote != nil && vote.BlockID.Equals(commit.BlockID) {
+			_, validator := validators.GetByIndex(vote.ValidatorIndex)
+			timeToVotingPower[vote.Timestamp] = validator.VotingPower


Should this be += ? What if some validators have identical timestamps

Great point!

I guess this was resolved by moving to use WeightedTime struct instead?

types/proposal.go

ebuchman · 2018-08-14T23:03:22Z

types/time.go

+	"sort"
+	"time"
+)
+


We should add proper Godoc comments to each exposed function

types/time.go

ebuchman · 2018-08-14T23:07:35Z

types/time.go

+	// To store the keys in slice in sorted order
+	var keys []time.Time
+	for k := range timeToVotingPower {
+		keys = append(keys, k)


so maybe it would actually be better to have WeightedMedian(weightedTimes []WeightedTime) where

type WeightedTime struct { Time time.Time Weight int64 }

Then we only have to build and sort the one array, instead of building up the map first and then copying into an array

ebuchman · 2018-08-14T23:09:50Z

types/time_test.go

+	m[t5] = 10 // faulty processes
+
+	median = WeightedMedian(m)
+	assert.Equal(t, t3, median) // median always returns value between values of correct processes


can we include the assertion associated with this comment? it's not clear until reading this what the significance of faulty process is here.

Also, this seems like its a good candidate for table driven tests.

melekes · 2018-08-27T07:14:37Z

Tests are failing with:

--- FAIL: TestBeginBlockValidators (0.01s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0xcc6b99]

goroutine 68 [running]:
testing.tRunner.func1(0xc420845770)
	/usr/local/go/src/testing/testing.go:742 +0x567
panic(0xe07f40, 0x14c5560)
	/usr/local/go/src/runtime/panic.go:502 +0x24a
github.com/tendermint/tendermint/types/time.WeightedMedian.func1(0x1, 0x0, 0xc42086b548)
	/go/src/github.com/tendermint/tendermint/types/time/time.go:30 +0xd9
sort.insertionSort_func(0xc42086b5f8, 0xc420814220, 0x0, 0x2)
	/usr/local/go/src/sort/zfuncversion.go:12 +0x91
sort.quickSort_func(0xc42086b5f8, 0xc420814220, 0x0, 0x2, 0x4)
	/usr/local/go/src/sort/zfuncversion.go:158 +0x204
sort.Slice(0xdb9da0, 0xc420814200, 0xc42086b5f8)
	/usr/local/go/src/sort/slice.go:21 +0xf1
github.com/tendermint/tendermint/types/time.WeightedMedian(0xc4200b1d60, 0x2, 0x2, 0x3e8, 0x2, 0x2, 0x0)
	/go/src/github.com/tendermint/tendermint/types/time/time.go:29 +0x108
github.com/tendermint/tendermint/state.MedianTime(0xc42083c380, 0xc4208137a0, 0x2, 0x10, 0xc42083c380)
	/go/src/github.com/tendermint/tendermint/state/state.go:162 +0x4fb
github.com/tendermint/tendermint/state.State.MakeBlock(0xee2540, 0xf, 0x1, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/tendermint/tendermint/state/state.go:126 +0x74b
github.com/tendermint/tendermint/state.TestBeginBlockValidators(0xc420845770)
	/go/src/github.com/tendermint/tendermint/state/execution_test.go:84 +0xf68
testing.tRunner(0xc420845770, 0x102d7c0)
	/usr/local/go/src/testing/testing.go:777 +0x16e
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:824 +0x565
FAIL	github.com/tendermint/tendermint/state	0.088s

milosevic · 2018-08-27T09:23:58Z

I have seen it. Working on it.

codecov-io · 2018-08-30T09:01:17Z

Codecov Report

Merging #2203 into develop will decrease coverage by 0.01%.
The diff coverage is 71.6%.

@@             Coverage Diff             @@
##           develop    #2203      +/-   ##
===========================================
- Coverage       61%   60.98%   -0.02%     
===========================================
  Files          196      197       +1     
  Lines        16173    16238      +65     
===========================================
+ Hits          9866     9903      +37     
- Misses        5451     5478      +27     
- Partials       856      857       +1

Impacted Files	Coverage Δ
state/validation.go	`49.09% <0%> (-7.16%)`	⬇️
cmd/tendermint/commands/testnet.go	`19.54% <0%> (ø)`	⬆️
consensus/wal.go	`61.24% <0%> (ø)`	⬆️
cmd/tendermint/commands/init.go	`0% <0%> (ø)`	⬆️
libs/log/tmfmt_logger.go	`88.67% <100%> (ø)`	⬆️
consensus/reactor.go	`73.82% <100%> (-0.54%)`	⬇️
consensus/state.go	`77.1% <100%> (-0.34%)`	⬇️
privval/priv_validator.go	`69.44% <100%> (ø)`	⬆️
types/time/time.go	`100% <100%> (ø)`
lite/helpers.go	`80.76% <100%> (ø)`	⬆️
... and 7 more

melekes · 2018-08-30T09:17:48Z

consensus/types/round_state_test.go

 	"testing"
-	"time"

-	amino "github.com/tendermint/go-amino"


please don't remove this alias

IDE removed it. Goland is great but not very flexible when it comes to configuration.

melekes · 2018-08-30T09:19:08Z

consensus/wal.go


 	// Write the wal message
-	if err := wal.enc.Encode(&TimedWALMessage{time.Now(), msg}); err != nil {
+	if err := wal.enc.Encode(&TimedWALMessage{tmtime.Now(), msg}); err != nil {


Do you think using time without monotonic part is beneficial for WAL file?

I am not sure to understand what do you mean? I guess idea with using tmtime.Now everywhere is being consistent about time.

I will try to explain. By stripping the monotonic part (that's what you're doing by calling tine.Now().Round(0)), if you try to compare two instances (t1 >= t2), Golang will only use wall clock (can be easily incorrect). https://golang.org/pkg/time/#hdr-Monotonic_Clocks

It looks like we're using time here for debugging, so that's fine. Please ignore

Thanks for explaining this. Could we have a problem here:

tendermint/consensus/state.go

Line 1673 in 412ba20

if now.After(minVoteTime) {

because we strip the monotonic part?

If locked/proposed block come from the outside (other nodes), then it does not matter cause "monotonic clock" is local-only property!

melekes · 2018-08-30T09:21:53Z

state/execution_test.go

 	}
 }

+func (state State) createBlock(


why not use state.MakeBlock?

state.MakeBlock expects state.LastValidators not to be empty because of the way how BFT time is set. This is the point discussed on Slack. But this test forces empty validator set (I don't really understand what is being tested).

I will check

for heights >= 2

melekes

LGTM

ebuchman · 2018-08-31T23:01:40Z

config/config.go

 		CreateEmptyBlocksInterval:   0,
 		PeerGossipSleepDuration:     100,
 		PeerQueryMaj23SleepDuration: 2000,
+		BlockTimeIota:               1000,


I think this needs to be a consensus parameter since it determines validity for blocks

ebuchman · 2018-08-31T23:04:53Z

consensus/wal_test.go


 	data := nBytes(n)
-	enc.Encode(&TimedWALMessage{Msg: data, Time: time.Now().Round(time.Second)})
+	enc.Encode(&TimedWALMessage{Msg: data, Time: time.Now().Round(time.Second).UTC()})


Is there some reason we need to round to the nearest second? Or let's just use tmtypes.Now ?

ebuchman · 2018-08-31T23:16:30Z

state/state.go

+		}
+	}
+
+	return tmtime.WeightedMedian(weightedTimes, totalVotingPower)


can we just call vals.TotalVotingPower() instead of accumulating it ourselves here?

ebuchman · 2018-08-31T23:19:14Z

state/state.go

+	if height == 1 {
+		block.Time = tmtime.Now()
+		if block.Time.Before(state.LastBlockTime) {
+			block.Time = state.LastBlockTime // state.LastBlockTime for height == 1 is genesis time


This suggests that #2294 isnt fixed here? Or at least it's still possible for a proposer to make a block before their local time reaches the genesis time. In any case I think we would want the first block to happen after the genesis time, and ala #2294, an honest proposer shouldn't make a block until they're locally at least that time.

Good point. I guess that the right way to address it would be not to start consensus machinery before genesis time. "Waiting" for genesis time probably shouldn't interfere with this logic.

Good point. I guess that the right way to address it would be not to start consensus machinery before genesis time.

this is also requested in #2294

ebuchman · 2018-08-31T23:20:13Z

state/validation.go

 	}

+	// Validate block Time
+	if block.Height > 1 {


should we add a clause Height==1 and require that it's at least the genesis time ? presumably, actually it should be some time after the genesis time ?

Probably we can enforce only that it's at least the genesis time.

ebuchman · 2018-08-31T23:22:28Z

types/time/time.go

+
+// Now returns UTC time rounded since the zero time.
+func Now() time.Time {
+	return time.Now().Round(0).UTC()


Can we clarify what we achieve with the Round(0) here ? It get's rid of the monotonic part according to https://golang.org/pkg/time/#Time.Round and https://golang.org/pkg/time/#hdr-Monotonic_Clocks but not 100% sure why we're doing that.

@jaekwon Can you please provide some input here? I have imported this from your old BFT time PR.

Stripping it is for time equality.

If we want to compare timestamps for equality, and you have time that was generated without Round(0) and compare it against one that was, they won't be equal. This might happen when you generate a block or vote (which generates a time locally, which without Round(0) would include the monotonic component), and then later you want to compare the timestamp there which was generated locally, against something that you encoded/decoded, using reflect.DeepEqual or assert/require.Equal.

We certainly don't need to use the monotonic part for most usages of time, because when we're setting the time of anything on the blockchain, we only care about what is encoded, nothing subjective. So, in order to make reflect.DeepEqual and other equality methods usable easily with Tendermint types, we should strip the monotonic component when creating them, like with this Now() method (for most usages of time anyways).

I remember that I was motivated to do this because a test was failing, I forget which.

Ok I'll add a comment to the code in #2343

ebuchman · 2018-08-31T23:22:51Z

types/time/time.go

+	return time.Now().Round(0).UTC()
+}
+
+type WeightedTime struct {


Exported types need comments

ebuchman · 2018-08-31T23:29:23Z

state/state.go

+	for _, vote := range commit.Precommits {
+		if vote != nil && vote.BlockID.Equals(commit.BlockID) {
+			_, validator := validators.GetByIndex(vote.ValidatorIndex)
+			timeToVotingPower[vote.Timestamp] = validator.VotingPower


I guess this was resolved by moving to use WeightedTime struct instead?

ebuchman

I think we can merge this, but will make a new issue for the follow up thanks @milosevic !

ebuchman · 2018-08-31T23:31:42Z

types/time/time_test.go

+	"github.com/stretchr/testify/assert"
+)
+
+func TestWeightedMedian(t *testing.T) {


should use table driven tests

milosevic requested review from ebuchman, melekes and xla as code owners August 10, 2018 18:12

milosevic force-pushed the zarko/2013-fix-bft-time branch 3 times, most recently from 67855a5 to 86777fd Compare August 11, 2018 18:33

milosevic requested a review from zramsay as a code owner August 11, 2018 18:33

melekes reviewed Aug 13, 2018

View reviewed changes

ebuchman reviewed Aug 14, 2018

View reviewed changes

milosevic force-pushed the zarko/2013-fix-bft-time branch 4 times, most recently from 3889a2f to f927c67 Compare August 24, 2018 13:19

milosevic force-pushed the zarko/2013-fix-bft-time branch 5 times, most recently from d275f54 to c44d354 Compare August 27, 2018 15:24

xla changed the title ~~WIP: Implement BFT time~~ [WIP] Implement BFT time Aug 27, 2018

xla added the C:consensus Component: Consensus label Aug 27, 2018

milosevic mentioned this pull request Aug 29, 2018

The “genesis_time” field is ignored #2294

Closed

Implement BFT time

2770689

milosevic force-pushed the zarko/2013-fix-bft-time branch from c44d354 to 2770689 Compare August 30, 2018 08:53

milosevic changed the title ~~[WIP] Implement BFT time~~ Implement BFT time Aug 30, 2018

melekes reviewed Aug 30, 2018

View reviewed changes

set LastValidators when creating state in state helper

412ba20

for heights >= 2

melekes approved these changes Aug 30, 2018

View reviewed changes

ebuchman reviewed Aug 31, 2018

View reviewed changes

ebuchman approved these changes Aug 31, 2018

View reviewed changes

Merge branch 'develop' into zarko/2013-fix-bft-time

d1f3872

ebuchman merged commit 7b88172 into develop Aug 31, 2018

ebuchman deleted the zarko/2013-fix-bft-time branch August 31, 2018 23:33

ebuchman mentioned this pull request Aug 31, 2018

Follow up on BFT time #2309

Closed

rickyyangz mentioned this pull request Sep 7, 2018

Tendermint Issues we need track bnb-chain/node#126

Closed

IronGauntlets mentioned this pull request Apr 26, 2019

Remove IBFT round change timer and add Tendermint timeouts and their handlers autonity/autonity#82

Closed

cason mentioned this pull request Sep 24, 2024

block/time: improve the test coverage for the BFT Time protocol cometbft/cometbft#4174

Open

3 tasks

rach-id mentioned this pull request Nov 4, 2025

Switch to monotonic time when calculating the delayed precommit timeout celestiaorg/celestia-core#2622

Open

Conversation

milosevic commented Aug 10, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

melekes Aug 13, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

melekes commented Aug 13, 2018

Uh oh!

ebuchman left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

melekes commented Aug 27, 2018

Uh oh!

milosevic commented Aug 27, 2018

Uh oh!

codecov-io commented Aug 30, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

milosevic commented Aug 10, 2018 •

edited

Loading

melekes Aug 13, 2018 •

edited

Loading

codecov-io commented Aug 30, 2018 •

edited

Loading