Make "Update to validators" msg value pretty (#2848)

* Make "Update to validators" msg value pretty #2765

* New format for logging validator updates

* Refactor logging validator updates

* Fix changelog item

* fix merge conflict

CHANGELOG_PENDING.md

@@ -34,6 +34,7 @@ program](https://hackerone.com/tendermint).
 
 ### IMPROVEMENTS:
 
+- [state] \#2765 Make "Update to validators" msg value pretty (@danil-lashin)
 - [p2p] \#2857 "Send failed" is logged at debug level instead of error.
 
 ### BUG FIXES:

state/execution.go

@@ -2,6 +2,7 @@ package state
 
 import (
 	"fmt"
+	"strings"
 	"time"
 
 	abci "github.com/tendermint/tendermint/abci/types"
@@ -107,7 +108,7 @@ func (blockExec *BlockExecutor) ApplyBlock(state State, blockID types.BlockID, b
 	fail.Fail() // XXX
 
 	// Update the state with the block and responses.
-	state, err = updateState(state, blockID, &block.Header, abciResponses)
+	state, err = updateState(blockExec.logger, state, blockID, &block.Header, abciResponses)
 	if err != nil {
 		return state, fmt.Errorf("Commit failed for application: %v", err)
 	}
@@ -254,12 +255,6 @@ func execBlockOnProxyApp(
 
 	logger.Info("Executed block", "height", block.Height, "validTxs", validTxs, "invalidTxs", invalidTxs)
 
-	valUpdates := abciResponses.EndBlock.ValidatorUpdates
-	if len(valUpdates) > 0 {
-		// TODO: cleanup the formatting
-		logger.Info("Updates to validators", "updates", valUpdates)
-	}
-
 	return abciResponses, nil
 }
 
@@ -315,16 +310,16 @@ func getBeginBlockValidatorInfo(block *types.Block, lastValSet *types.ValidatorS
 // If more or equal than 1/3 of total voting power changed in one block, then
 // a light client could never prove the transition externally. See
 // ./lite/doc.go for details on how a light client tracks validators.
-func updateValidators(currentSet *types.ValidatorSet, abciUpdates []abci.ValidatorUpdate) error {
+func updateValidators(currentSet *types.ValidatorSet, abciUpdates []abci.ValidatorUpdate) ([]*types.Validator, error) {
 	updates, err := types.PB2TM.ValidatorUpdates(abciUpdates)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	// these are tendermint types now
 	for _, valUpdate := range updates {
 		if valUpdate.VotingPower < 0 {
-			return fmt.Errorf("Voting power can't be negative %v", valUpdate)
+			return nil, fmt.Errorf("Voting power can't be negative %v", valUpdate)
 		}
 
 		address := valUpdate.Address
@@ -333,27 +328,28 @@ func updateValidators(currentSet *types.ValidatorSet, abciUpdates []abci.Validat
 			// remove val
 			_, removed := currentSet.Remove(address)
 			if !removed {
-				return fmt.Errorf("Failed to remove validator %X", address)
+				return nil, fmt.Errorf("Failed to remove validator %X", address)
 			}
 		} else if val == nil {
 			// add val
 			added := currentSet.Add(valUpdate)
 			if !added {
-				return fmt.Errorf("Failed to add new validator %v", valUpdate)
+				return nil, fmt.Errorf("Failed to add new validator %v", valUpdate)
 			}
 		} else {
 			// update val
 			updated := currentSet.Update(valUpdate)
 			if !updated {
-				return fmt.Errorf("Failed to update validator %X to %v", address, valUpdate)
+				return nil, fmt.Errorf("Failed to update validator %X to %v", address, valUpdate)
 			}
 		}
 	}
-	return nil
+	return updates, nil
 }
 
 // updateState returns a new State updated according to the header and responses.
 func updateState(
+	logger log.Logger,
 	state State,
 	blockID types.BlockID,
 	header *types.Header,
@@ -367,12 +363,14 @@ func updateState(
 	// Update the validator set with the latest abciResponses.
 	lastHeightValsChanged := state.LastHeightValidatorsChanged
 	if len(abciResponses.EndBlock.ValidatorUpdates) > 0 {
-		err := updateValidators(nValSet, abciResponses.EndBlock.ValidatorUpdates)
+		validatorUpdates, err := updateValidators(nValSet, abciResponses.EndBlock.ValidatorUpdates)
 		if err != nil {
 			return state, fmt.Errorf("Error changing validator set: %v", err)
 		}
 		// Change results from this height but only applies to the next next height.
 		lastHeightValsChanged = header.Height + 1 + 1
+
+		logger.Info("Updates to validators", "updates", makeValidatorUpdatesLogString(validatorUpdates))
 	}
 
 	// Update validator accums and set state variables.
@@ -466,3 +464,13 @@ func ExecCommitBlock(
 	// ResponseCommit has no error or log, just data
 	return res.Data, nil
 }
+
+// Make pretty string for validatorUpdates logging
+func makeValidatorUpdatesLogString(vals []*types.Validator) string {
+	chunks := make([]string, len(vals))
+	for i, val := range vals {
+		chunks[i] = fmt.Sprintf("%s:%d", val.Address, val.VotingPower)
+	}
+
+	return strings.Join(chunks, ",")
+}

state/execution_test.go

@@ -218,7 +218,7 @@ func TestUpdateValidators(t *testing.T) {
 
 	for _, tc := range testCases {
 		t.Run(tc.name, func(t *testing.T) {
-			err := updateValidators(tc.currentSet, tc.abciUpdates)
+			_, err := updateValidators(tc.currentSet, tc.abciUpdates)
 			if tc.shouldErr {
 				assert.Error(t, err)
 			} else {

state/state_test.go

@@ -3,6 +3,7 @@ package state
 import (
 	"bytes"
 	"fmt"
+	"github.com/tendermint/tendermint/libs/log"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
@@ -228,7 +229,7 @@ func TestOneValidatorChangesSaveLoad(t *testing.T) {
 			power++
 		}
 		header, blockID, responses := makeHeaderPartsResponsesValPowerChange(state, i, power)
-		state, err = updateState(state, blockID, &header, responses)
+		state, err = updateState(log.TestingLogger(), state, blockID, &header, responses)
 		assert.Nil(t, err)
 		nextHeight := state.LastBlockHeight + 1
 		saveValidatorsInfo(stateDB, nextHeight+1, state.LastHeightValidatorsChanged, state.NextValidators)
@@ -280,7 +281,7 @@ func TestManyValidatorChangesSaveLoad(t *testing.T) {
 
 	// Save state etc.
 	var err error
-	state, err = updateState(state, blockID, &header, responses)
+	state, err = updateState(log.TestingLogger(), state, blockID, &header, responses)
 	require.Nil(t, err)
 	nextHeight := state.LastBlockHeight + 1
 	saveValidatorsInfo(stateDB, nextHeight+1, state.LastHeightValidatorsChanged, state.NextValidators)
@@ -359,7 +360,7 @@ func TestConsensusParamsChangesSaveLoad(t *testing.T) {
 			cp = params[changeIndex]
 		}
 		header, blockID, responses := makeHeaderPartsResponsesParams(state, i, cp)
-		state, err = updateState(state, blockID, &header, responses)
+		state, err = updateState(log.TestingLogger(), state, blockID, &header, responses)
 
 		require.Nil(t, err)
 		nextHeight := state.LastBlockHeight + 1