From 9bd56426d80b45a30c97d9c18b9e7f37cbb5d4e8 Mon Sep 17 00:00:00 2001 From: tycho garen Date: Fri, 11 Mar 2022 15:52:32 -0500 Subject: [PATCH] better logs --- internal/consensus/common_test.go | 10 +++---- internal/consensus/reactor_test.go | 12 ++++----- internal/consensus/state_test.go | 43 ++++++++---------------------- 3 files changed, 19 insertions(+), 46 deletions(-) diff --git a/internal/consensus/common_test.go b/internal/consensus/common_test.go index 2c894fb25..7a02a5e33 100644 --- a/internal/consensus/common_test.go +++ b/internal/consensus/common_test.go @@ -459,16 +459,12 @@ func newStateWithConfigAndBlockStore( ) *State { t.Helper() - // one for mempool, one for consensus - proxyAppConnMem := abciclient.NewLocalClient(logger, app) - proxyAppConnCon := abciclient.NewLocalClient(logger, app) - - // Make Mempool + proxyConn := abciclient.NewLocalClient(logger, app) mempool := mempool.NewTxMempool( logger.With("module", "mempool"), thisConfig.Mempool, - proxyAppConnMem, + proxyConn, ) if thisConfig.Consensus.WaitForTxs() { @@ -485,7 +481,7 @@ func newStateWithConfigAndBlockStore( eventBus := eventbus.NewDefault(logger.With("module", "events")) require.NoError(t, eventBus.Start(ctx)) - blockExec := sm.NewBlockExecutor(stateStore, logger, proxyAppConnCon, mempool, evpool, blockStore, eventBus) + blockExec := sm.NewBlockExecutor(stateStore, logger, proxyConn, mempool, evpool, blockStore, eventBus) cs, err := NewState(ctx, logger.With("module", "consensus"), thisConfig.Consensus, diff --git a/internal/consensus/reactor_test.go b/internal/consensus/reactor_test.go index 13baae665..f695928d2 100644 --- a/internal/consensus/reactor_test.go +++ b/internal/consensus/reactor_test.go @@ -743,15 +743,14 @@ func TestReactorVotingPowerChange(t *testing.T) { t.Cleanup(cleanup) - rts := setup(ctx, t, n, states, 100) // buffer must be large enough to not deadlock + rts := setup(ctx, t, n, states, 512) // buffer must be large enough to not deadlock for _, reactor := range rts.reactors { - state := reactor.state.GetState() - reactor.SwitchToConsensus(ctx, state, false) + reactor.SwitchToConsensus(ctx, reactor.state.state, false) } // map of active validators - activeVals := make(map[string]struct{}) + activeVals := make(map[string]struct{}, n) for i := 0; i < n; i++ { pubKey, err := states[i].privValidator.GetPubKey(ctx) require.NoError(t, err) @@ -815,7 +814,7 @@ func TestReactorVotingPowerChange(t *testing.T) { newVotingPower, ) - updateValidatorTx = kvstore.MakeValSetChangeTx(val1PubKeyABCI, 2) + updateValidatorTx = kvstore.MakeValSetChangeTx(val1PubKeyABCI, 10) previousTotalVotingPower = states[0].GetRoundState().LastValidators.TotalVotingPower() waitForAndValidateBlock(ctx, t, n, activeVals, blocksSubs, states, updateValidatorTx) @@ -868,8 +867,7 @@ func TestReactorValidatorSetChanges(t *testing.T) { rts := setup(ctx, t, nPeers, states, 512) // buffer must be large enough to not deadlock for _, reactor := range rts.reactors { - state := reactor.state.GetState() - reactor.SwitchToConsensus(ctx, state, false) + reactor.SwitchToConsensus(ctx, reactor.state.state, false) } // map of active validators diff --git a/internal/consensus/state_test.go b/internal/consensus/state_test.go index af4c61897..2d79dab07 100644 --- a/internal/consensus/state_test.go +++ b/internal/consensus/state_test.go @@ -3,7 +3,6 @@ package consensus import ( "bytes" "context" - "fmt" "testing" "time" @@ -493,7 +492,6 @@ func TestStateLock_NoPOL(t *testing.T) { round++ // moving to the next round ensureNewRound(t, newRoundCh, height, round) - t.Log("#### ONTO ROUND 1") /* Round2 (cs1, B) // B B2 */ @@ -536,7 +534,6 @@ func TestStateLock_NoPOL(t *testing.T) { round++ // entering new round ensureNewRound(t, newRoundCh, height, round) - t.Log("#### ONTO ROUND 2") /* Round3 (vs2, _) // B, B2 */ @@ -593,7 +590,6 @@ func TestStateLock_NoPOL(t *testing.T) { round++ // entering new round ensureNewRound(t, newRoundCh, height, round) - t.Log("#### ONTO ROUND 3") /* Round4 (vs2, C) // B C // B C */ @@ -665,7 +661,6 @@ func TestStateLock_POLUpdateLock(t *testing.T) { This ensures that cs1 will lock on B in this round but not precommit it. */ - t.Log("### Starting Round 0") // start round and wait for propose and prevote startTestRound(ctx, cs1, height, round) @@ -703,7 +698,6 @@ func TestStateLock_POLUpdateLock(t *testing.T) { Check that cs1 is now locked on the new block, D and no longer on the old block. */ - t.Log("### Starting Round 1") incrementRound(vs2, vs3, vs4) round++ @@ -776,7 +770,6 @@ func TestStateLock_POLRelock(t *testing.T) { Send a precommit for nil from all of the validators to cs1. This ensures that cs1 will lock on B in this round but not precommit it. */ - t.Log("### Starting Round 0") startTestRound(ctx, cs1, height, round) @@ -815,7 +808,6 @@ func TestStateLock_POLRelock(t *testing.T) { Check that cs1 updates its 'locked round' value to the current round. */ - t.Log("### Starting Round 1") incrementRound(vs2, vs3, vs4) round++ propR1 := types.NewProposal(height, round, cs1.ValidRound, blockID, theBlock.Header.Time) @@ -875,7 +867,6 @@ func TestStateLock_PrevoteNilWhenLockedAndMissProposal(t *testing.T) { This ensures that cs1 will lock on B in this round but not precommit it. */ - t.Log("### Starting Round 0") startTestRound(ctx, cs1, height, round) @@ -912,7 +903,6 @@ func TestStateLock_PrevoteNilWhenLockedAndMissProposal(t *testing.T) { Check that cs1 prevotes nil instead of its locked block, but ensure that it maintains its locked block. */ - t.Log("### Starting Round 1") incrementRound(vs2, vs3, vs4) round++ @@ -964,7 +954,7 @@ func TestStateLock_PrevoteNilWhenLockedAndDifferentProposal(t *testing.T) { This ensures that cs1 will lock on B in this round but not precommit it. */ - t.Log("### Starting Round 0") + startTestRound(ctx, cs1, height, round) ensureNewRound(t, newRoundCh, height, round) @@ -1001,7 +991,7 @@ func TestStateLock_PrevoteNilWhenLockedAndDifferentProposal(t *testing.T) { Check that cs1 prevotes nil instead of its locked block, but ensure that it maintains its locked block. */ - t.Log("### Starting Round 1") + incrementRound(vs2, vs3, vs4) round++ cs2 := newState(ctx, t, logger, cs1.state, vs2, kvstore.NewApplication()) @@ -1070,7 +1060,6 @@ func TestStateLock_POLDoesNotUnlock(t *testing.T) { This ensures that cs1 will lock on B in this round. */ - t.Log("#### ONTO ROUND 0") // start round and wait for propose and prevote startTestRound(ctx, cs1, height, round) @@ -1112,7 +1101,6 @@ func TestStateLock_POLDoesNotUnlock(t *testing.T) { Check that cs1 maintains its lock on B but precommits nil. Send a precommit for nil from >2/3 of the validators to `cs1`. */ - t.Log("#### ONTO ROUND 1") round++ incrementRound(vs2, vs3, vs4) cs2 := newState(ctx, t, logger, cs1.state, vs2, kvstore.NewApplication()) @@ -1151,7 +1139,7 @@ func TestStateLock_POLDoesNotUnlock(t *testing.T) { Send the validator >2/3 prevotes for nil and ensure that it did not unlock its block at the end of the previous round. */ - t.Log("#### ONTO ROUND 2") + round++ incrementRound(vs2, vs3, vs4) cs3 := newState(ctx, t, logger, cs1.state, vs2, kvstore.NewApplication()) @@ -1208,7 +1196,7 @@ func TestStateLock_MissingProposalWhenPOLSeenDoesNotUpdateLock(t *testing.T) { This ensures that cs1 will lock on B in this round but not precommit it. */ - t.Log("### Starting Round 0") + startTestRound(ctx, cs1, height, round) ensureNewRound(t, newRoundCh, height, round) @@ -1240,7 +1228,7 @@ func TestStateLock_MissingProposalWhenPOLSeenDoesNotUpdateLock(t *testing.T) { Check that cs1 does not update its locked block to this missed block D. */ - t.Log("### Starting Round 1") + incrementRound(vs2, vs3, vs4) round++ cs2 := newState(ctx, t, logger, cs1.state, vs2, kvstore.NewApplication()) @@ -1296,7 +1284,7 @@ func TestStateLock_DoesNotLockOnOldProposal(t *testing.T) { This ensures that cs1 will not lock on B. */ - t.Log("### Starting Round 0") + startTestRound(ctx, cs1, height, round) ensureNewRound(t, newRoundCh, height, round) @@ -1330,7 +1318,7 @@ func TestStateLock_DoesNotLockOnOldProposal(t *testing.T) { cs1 saw a POL for the block it saw in round 0. We ensure that it does not lock on this block, since it did not see a proposal for it in this round. */ - t.Log("### Starting Round 1") + round++ ensureNewRound(t, newRoundCh, height, round) @@ -1394,7 +1382,6 @@ func TestStateLock_POLSafety1(t *testing.T) { ensurePrecommit(t, voteCh, height, round) ensureNewTimeout(t, timeoutWaitCh, height, round, cs1.config.Precommit(round).Nanoseconds()) - t.Log("### ONTO ROUND 1") incrementRound(vs2, vs3, vs4) round++ // moving to the next round cs2 := newState(ctx, t, logger, cs1.state, vs2, kvstore.NewApplication()) @@ -1422,8 +1409,6 @@ func TestStateLock_POLSafety1(t *testing.T) { require.Nil(t, rs.LockedBlock, "we should not be locked!") - t.Logf("new prop hash %v", fmt.Sprintf("%X", propBlock.Hash())) - // go to prevote, prevote for proposal block ensurePrevoteMatch(t, voteCh, height, round, r2BlockID.Hash) @@ -1443,7 +1428,6 @@ func TestStateLock_POLSafety1(t *testing.T) { ensureNewRound(t, newRoundCh, height, round) - t.Log("### ONTO ROUND 2") /*Round3 we see the polka from round 1 but we shouldn't unlock! */ @@ -1509,7 +1493,7 @@ func TestStateLock_POLSafety2(t *testing.T) { incrementRound(vs2, vs3, vs4) round++ // moving to the next round - t.Log("### ONTO Round 1") + // jump in at round 1 startTestRound(ctx, cs1, height, round) ensureNewRound(t, newRoundCh, height, round) @@ -1551,7 +1535,6 @@ func TestStateLock_POLSafety2(t *testing.T) { addVotes(cs1, prevotes...) ensureNewRound(t, newRoundCh, height, round) - t.Log("### ONTO Round 2") /*Round2 // now we see the polka from round 1, but we shouldnt unlock */ @@ -1594,7 +1577,6 @@ func TestState_PrevotePOLFromPreviousRound(t *testing.T) { This ensures that cs1 will lock on B in this round but not precommit it. */ - t.Log("### Starting Round 0") startTestRound(ctx, cs1, height, round) @@ -1632,14 +1614,14 @@ func TestState_PrevotePOLFromPreviousRound(t *testing.T) { cs1 has now seen greater than 2/3 of the voting power prevote D in this round but cs1 did not see the proposal for D in this round so it will not prevote or precommit it. */ - t.Log("### Starting Round 1") incrementRound(vs2, vs3, vs4) round++ // Generate a new proposal block. cs2 := newState(ctx, t, logger, cs1.state, vs2, kvstore.NewApplication()) cs2.ValidRound = 1 propR1, propBlockR1 := decideProposal(ctx, t, cs2, vs2, vs2.Height, round) - t.Log(propR1.POLRound) + assert.Equal(t, 1, propR1.POLRound) + propBlockR1Parts, err := propBlockR1.MakePartSet(partSize) require.NoError(t, err) r1BlockID := types.BlockID{ @@ -1673,7 +1655,7 @@ func TestState_PrevotePOLFromPreviousRound(t *testing.T) { Send cs1 prevotes for nil and check that it still prevotes its locked block and not the block that it prevoted. */ - t.Log("### Starting Round 2") + incrementRound(vs2, vs3, vs4) round++ propR2 := types.NewProposal(height, round, 1, r1BlockID, propBlockR1.Header.Time) @@ -1760,7 +1742,6 @@ func TestProposeValidBlock(t *testing.T) { round++ // moving to the next round ensureNewRound(t, newRoundCh, height, round) - t.Log("### ONTO ROUND 1") // timeout of propose ensureNewTimeout(t, timeoutProposeCh, height, round, cs1.config.Propose(round).Nanoseconds()) @@ -1783,7 +1764,6 @@ func TestProposeValidBlock(t *testing.T) { round += 2 // increment by multiple rounds ensureNewRound(t, newRoundCh, height, round) - t.Log("### ONTO ROUND 3") ensureNewTimeout(t, timeoutWaitCh, height, round, cs1.config.Precommit(round).Nanoseconds()) @@ -2485,7 +2465,6 @@ func TestStateHalt1(t *testing.T) { ensureNewRound(t, newRoundCh, height, round) - t.Log("### ONTO ROUND 1") /*Round2 // we timeout and prevote // a polka happened but we didn't see it!