simulation: Switch the log method from a single string to string builders

This rapidly speeds up simulation in testing mode.

Author: ValarDragon

Makefile

@@ -157,7 +157,7 @@ test_sim_gaia_nondeterminism:
 
 test_sim_gaia_fast:
 	@echo "Running quick Gaia simulation. This may take several minutes..."
-	@go test ./cmd/gaia/app -run TestFullGaiaSimulation -SimulationEnabled=true -SimulationNumBlocks=150 -v -timeout 24h
+	@go test ./cmd/gaia/app -run TestFullGaiaSimulation -SimulationEnabled=true -SimulationNumBlocks=200 -v -timeout 24h
 
 test_sim_gaia_slow:
 	@echo "Running full Gaia simulation. This may take awhile!"

PENDING.md

@@ -40,6 +40,7 @@ BREAKING CHANGES
     * [x/slashing] [#2122](https://github.com/cosmos/cosmos-sdk/pull/2122) - Implement slashing period
     * [types] [\#2119](https://github.com/cosmos/cosmos-sdk/issues/2119) Parsed error messages and ABCI log errors to make them more human readable.
     * [simulation] Rename TestAndRunTx to Operation [#2153](https://github.com/cosmos/cosmos-sdk/pull/2153)
+    * [simulation] Delete "log string" from the relevant types \#2282
     * [tools] Removed gocyclo [#2211](https://github.com/cosmos/cosmos-sdk/issues/2211)
     * [baseapp] Remove `SetTxDecoder` in favor of requiring the decoder be set in baseapp initialization. [#1441](https://github.com/cosmos/cosmos-sdk/issues/1441)
 
@@ -103,6 +104,7 @@ IMPROVEMENTS
     * [store] Speedup IAVL iteration, and consequently everything that requires IAVL iteration. [#2143](https://github.com/cosmos/cosmos-sdk/issues/2143)
     * [store] \#1952 Update IAVL dependency to v0.10.0
     * [simulation] Make timestamps randomized [#2153](https://github.com/cosmos/cosmos-sdk/pull/2153)
+    * [simulation] Make logs not just pure strings, speeding it up by a large factor at greater block heights \#2282
 
 * Tendermint
 

cmd/gaia/app/sim_test.go

@@ -14,7 +14,6 @@ import (
 	dbm "github.com/tendermint/tendermint/libs/db"
 	"github.com/tendermint/tendermint/libs/log"
 
-	"github.com/cosmos/cosmos-sdk/baseapp"
 	sdk "github.com/cosmos/cosmos-sdk/types"
 	banksim "github.com/cosmos/cosmos-sdk/x/bank/simulation"
 	"github.com/cosmos/cosmos-sdk/x/gov"
@@ -108,12 +107,10 @@ func testAndRunTxs(app *GaiaApp) []simulation.Operation {
 
 func invariants(app *GaiaApp) []simulation.Invariant {
 	return []simulation.Invariant{
-		func(t *testing.T, baseapp *baseapp.BaseApp, log string) {
-			banksim.NonnegativeBalanceInvariant(app.accountMapper)(t, baseapp, log)
-			govsim.AllInvariants()(t, baseapp, log)
-			stakesim.AllInvariants(app.bankKeeper, app.stakeKeeper, app.accountMapper)(t, baseapp, log)
-			slashingsim.AllInvariants()(t, baseapp, log)
-		},
+		banksim.NonnegativeBalanceInvariant(app.accountMapper),
+		govsim.AllInvariants(),
+		stakesim.AllInvariants(app.bankKeeper, app.stakeKeeper, app.accountMapper),
+		slashingsim.AllInvariants(),
 	}
 }
 

x/bank/simulation/invariants.go

@@ -1,10 +1,8 @@
 package simulation
 
 import (
+	"errors"
 	"fmt"
-	"testing"
-
-	"github.com/stretchr/testify/require"
 
 	"github.com/cosmos/cosmos-sdk/baseapp"
 	sdk "github.com/cosmos/cosmos-sdk/types"
@@ -16,25 +14,25 @@ import (
 
 // NonnegativeBalanceInvariant checks that all accounts in the application have non-negative balances
 func NonnegativeBalanceInvariant(mapper auth.AccountMapper) simulation.Invariant {
-	return func(t *testing.T, app *baseapp.BaseApp, log string) {
+	return func(app *baseapp.BaseApp) error {
 		ctx := app.NewContext(false, abci.Header{})
 		accts := mock.GetAllAccounts(mapper, ctx)
 		for _, acc := range accts {
 			coins := acc.GetCoins()
-			require.True(t, coins.IsNotNegative(),
-				fmt.Sprintf("%s has a negative denomination of %s\n%s",
+			if !coins.IsNotNegative() {
+				return fmt.Errorf("%s has a negative denomination of %s\n",
 					acc.GetAddress().String(),
-					coins.String(),
-					log),
-			)
+					coins.String())
+			}
 		}
+		return nil
 	}
 }
 
 // TotalCoinsInvariant checks that the sum of the coins across all accounts
 // is what is expected
 func TotalCoinsInvariant(mapper auth.AccountMapper, totalSupplyFn func() sdk.Coins) simulation.Invariant {
-	return func(t *testing.T, app *baseapp.BaseApp, log string) {
+	return func(app *baseapp.BaseApp) error {
 		ctx := app.NewContext(false, abci.Header{})
 		totalCoins := sdk.Coins{}
 
@@ -45,6 +43,9 @@ func TotalCoinsInvariant(mapper auth.AccountMapper, totalSupplyFn func() sdk.Coi
 		}
 
 		mapper.IterateAccounts(ctx, chkAccount)
-		require.Equal(t, totalSupplyFn(), totalCoins, log)
+		if !totalSupplyFn().IsEqual(totalCoins) {
+			return errors.New("total calculated coins doesn't equal expected coins")
+		}
+		return nil
 	}
 }

x/bank/simulation/msgs.go

@@ -7,8 +7,6 @@ import (
 	"math/rand"
 	"testing"
 
-	"github.com/stretchr/testify/require"
-
 	"github.com/cosmos/cosmos-sdk/baseapp"
 	sdk "github.com/cosmos/cosmos-sdk/types"
 	"github.com/cosmos/cosmos-sdk/x/auth"
@@ -21,7 +19,7 @@ import (
 // SimulateSingleInputMsgSend tests and runs a single msg send, with one input and one output, where both
 // accounts already exist.
 func SimulateSingleInputMsgSend(mapper auth.AccountMapper) simulation.Operation {
-	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, log string, event func(string)) (action string, fOps []simulation.FutureOperation, err sdk.Error) {
+	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOps []simulation.FutureOperation, err error) {
 		fromKey := simulation.RandomKey(r, keys)
 		fromAddr := sdk.AccAddress(fromKey.PubKey().Address())
 		toKey := simulation.RandomKey(r, keys)
@@ -51,22 +49,24 @@ func SimulateSingleInputMsgSend(mapper auth.AccountMapper) simulation.Operation
 			initFromCoins[denomIndex].Denom,
 			toAddr.String(),
 		)
-		log = fmt.Sprintf("%s\n%s", log, action)
 
 		coins := sdk.Coins{{initFromCoins[denomIndex].Denom, amt}}
 		var msg = bank.MsgSend{
 			Inputs:  []bank.Input{bank.NewInput(fromAddr, coins)},
 			Outputs: []bank.Output{bank.NewOutput(toAddr, coins)},
 		}
-		sendAndVerifyMsgSend(tb, app, mapper, msg, ctx, log, []crypto.PrivKey{fromKey})
+		goErr = sendAndVerifyMsgSend(tb, app, mapper, msg, ctx, []crypto.PrivKey{fromKey})
+		if goErr != nil {
+			return "", nil, goErr
+		}
 		event("bank/sendAndVerifyMsgSend/ok")
 
 		return action, nil, nil
 	}
 }
 
 // Sends and verifies the transition of a msg send. This fails if there are repeated inputs or outputs
-func sendAndVerifyMsgSend(tb testing.TB, app *baseapp.BaseApp, mapper auth.AccountMapper, msg bank.MsgSend, ctx sdk.Context, log string, privkeys []crypto.PrivKey) {
+func sendAndVerifyMsgSend(tb testing.TB, app *baseapp.BaseApp, mapper auth.AccountMapper, msg bank.MsgSend, ctx sdk.Context, privkeys []crypto.PrivKey) error {
 	initialInputAddrCoins := make([]sdk.Coins, len(msg.Inputs))
 	initialOutputAddrCoins := make([]sdk.Coins, len(msg.Outputs))
 	AccountNumbers := make([]int64, len(msg.Inputs))
@@ -90,24 +90,22 @@ func sendAndVerifyMsgSend(tb testing.TB, app *baseapp.BaseApp, mapper auth.Accou
 	if !res.IsOK() {
 		// TODO: Do this in a more 'canonical' way
 		fmt.Println(res)
-		fmt.Println(log)
 		tb.FailNow()
 	}
 
 	for i := 0; i < len(msg.Inputs); i++ {
 		terminalInputCoins := mapper.GetAccount(ctx, msg.Inputs[i].Address).GetCoins()
-		require.Equal(tb,
-			initialInputAddrCoins[i].Minus(msg.Inputs[i].Coins),
-			terminalInputCoins,
-			fmt.Sprintf("Input #%d had an incorrect amount of coins\n%s", i, log),
-		)
+		if !initialInputAddrCoins[i].Minus(msg.Inputs[i].Coins).IsEqual(terminalInputCoins) {
+			return fmt.Errorf("Input #%d had an incorrect amount of coins", i)
+		}
 	}
 	for i := 0; i < len(msg.Outputs); i++ {
 		terminalOutputCoins := mapper.GetAccount(ctx, msg.Outputs[i].Address).GetCoins()
 		if !terminalOutputCoins.IsEqual(initialOutputAddrCoins[i].Plus(msg.Outputs[i].Coins)) {
-			tb.Fatalf("Output #%d had an incorrect amount of coins\n%s", i, log)
+			return fmt.Errorf("Output #%d had an incorrect amount of coins", i)
 		}
 	}
+	return nil
 }
 
 func randPositiveInt(r *rand.Rand, max sdk.Int) (sdk.Int, error) {

x/gov/simulation/invariants.go

@@ -1,19 +1,15 @@
 package simulation
 
 import (
-	"testing"
-
-	"github.com/stretchr/testify/require"
-
 	"github.com/cosmos/cosmos-sdk/baseapp"
 	"github.com/cosmos/cosmos-sdk/x/mock/simulation"
 )
 
 // AllInvariants tests all governance invariants
 func AllInvariants() simulation.Invariant {
-	return func(t *testing.T, app *baseapp.BaseApp, log string) {
+	return func(app *baseapp.BaseApp) error {
 		// TODO Add some invariants!
 		// Checking proposal queues, no passed-but-unexecuted proposals, etc.
-		require.Nil(t, nil)
+		return nil
 	}
 }

x/gov/simulation/msgs.go

@@ -45,10 +45,13 @@ func SimulateSubmittingVotingAndSlashingForProposal(k gov.Keeper, sk stake.Keepe
 	})
 	statePercentageArray := []float64{1, .9, .75, .4, .15, 0}
 	curNumVotesState := 1
-	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, log string, event func(string)) (action string, fOps []simulation.FutureOperation, err sdk.Error) {
+	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOps []simulation.FutureOperation, err error) {
 		// 1) submit proposal now
 		sender := simulation.RandomKey(r, keys)
-		msg := simulationCreateMsgSubmitProposal(tb, r, sender, log)
+		msg, err := simulationCreateMsgSubmitProposal(tb, r, sender)
+		if err != nil {
+			return "", nil, err
+		}
 		action = simulateHandleMsgSubmitProposal(msg, sk, handler, ctx, event)
 		proposalID := k.GetLastProposalID(ctx)
 		// 2) Schedule operations for votes
@@ -77,9 +80,12 @@ func SimulateSubmittingVotingAndSlashingForProposal(k gov.Keeper, sk stake.Keepe
 // Note: Currently doesn't ensure that the proposal txt is in JSON form
 func SimulateMsgSubmitProposal(k gov.Keeper, sk stake.Keeper) simulation.Operation {
 	handler := gov.NewHandler(k)
-	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, log string, event func(string)) (action string, fOps []simulation.FutureOperation, err sdk.Error) {
+	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOps []simulation.FutureOperation, err error) {
 		sender := simulation.RandomKey(r, keys)
-		msg := simulationCreateMsgSubmitProposal(tb, r, sender, log)
+		msg, err := simulationCreateMsgSubmitProposal(tb, r, sender)
+		if err != nil {
+			return "", nil, err
+		}
 		action = simulateHandleMsgSubmitProposal(msg, sk, handler, ctx, event)
 		return action, nil, nil
 	}
@@ -100,25 +106,25 @@ func simulateHandleMsgSubmitProposal(msg gov.MsgSubmitProposal, sk stake.Keeper,
 	return action
 }
 
-func simulationCreateMsgSubmitProposal(tb testing.TB, r *rand.Rand, sender crypto.PrivKey, log string) gov.MsgSubmitProposal {
+func simulationCreateMsgSubmitProposal(tb testing.TB, r *rand.Rand, sender crypto.PrivKey) (msg gov.MsgSubmitProposal, err error) {
 	addr := sdk.AccAddress(sender.PubKey().Address())
 	deposit := randomDeposit(r)
-	msg := gov.NewMsgSubmitProposal(
+	msg = gov.NewMsgSubmitProposal(
 		simulation.RandStringOfLength(r, 5),
 		simulation.RandStringOfLength(r, 5),
 		gov.ProposalTypeText,
 		addr,
 		deposit,
 	)
 	if msg.ValidateBasic() != nil {
-		tb.Fatalf("expected msg to pass ValidateBasic: %s, log %s", msg.GetSignBytes(), log)
+		err = fmt.Errorf("expected msg to pass ValidateBasic: %s", msg.GetSignBytes())
 	}
-	return msg
+	return
 }
 
 // SimulateMsgDeposit
 func SimulateMsgDeposit(k gov.Keeper, sk stake.Keeper) simulation.Operation {
-	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, log string, event func(string)) (action string, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 		key := simulation.RandomKey(r, keys)
 		addr := sdk.AccAddress(key.PubKey().Address())
 		proposalID, ok := randomProposalID(r, k, ctx)
@@ -128,7 +134,7 @@ func SimulateMsgDeposit(k gov.Keeper, sk stake.Keeper) simulation.Operation {
 		deposit := randomDeposit(r)
 		msg := gov.NewMsgDeposit(addr, proposalID, deposit)
 		if msg.ValidateBasic() != nil {
-			tb.Fatalf("expected msg to pass ValidateBasic: %s, log %s", msg.GetSignBytes(), log)
+			return "", nil, fmt.Errorf("expected msg to pass ValidateBasic: %s", msg.GetSignBytes())
 		}
 		ctx, write := ctx.CacheContext()
 		result := gov.NewHandler(k)(ctx, msg)
@@ -153,7 +159,7 @@ func SimulateMsgVote(k gov.Keeper, sk stake.Keeper) simulation.Operation {
 
 // nolint: unparam
 func operationSimulateMsgVote(k gov.Keeper, sk stake.Keeper, key crypto.PrivKey, proposalID int64) simulation.Operation {
-	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, log string, event func(string)) (action string, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 		if key == nil {
 			key = simulation.RandomKey(r, keys)
 		}
@@ -168,7 +174,7 @@ func operationSimulateMsgVote(k gov.Keeper, sk stake.Keeper, key crypto.PrivKey,
 		option := randomVotingOption(r)
 		msg := gov.NewMsgVote(addr, proposalID, option)
 		if msg.ValidateBasic() != nil {
-			tb.Fatalf("expected msg to pass ValidateBasic: %s, log %s", msg.GetSignBytes(), log)
+			return "", nil, fmt.Errorf("expected msg to pass ValidateBasic: %s", msg.GetSignBytes())
 		}
 		ctx, write := ctx.CacheContext()
 		result := gov.NewHandler(k)(ctx, msg)