Merge PR #2282: simulation: Switch the log method from a single string to string builders

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] Remove log and testing.TB from Operation and Invariants, in favor of using errors \#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)
 
@@ -104,6 +105,7 @@ IMPROVEMENTS
     * [store] Speedup IAVL iteration, and consequently everything that requires IAVL iteration. [#2143](https://github.com/cosmos/cosmos-sdk/issues/2143)
     * [store] \#1952, \#2281 Update IAVL dependency to v0.11.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),
-			banksim.NonnegativeBalanceInvariant(app.accountMapper)(t, baseapp, log)
+		govsim.AllInvariants(),
-			govsim.AllInvariants()(t, baseapp, log)
+		stakesim.AllInvariants(app.bankKeeper, app.stakeKeeper, app.accountMapper),
-			stakesim.AllInvariants(app.bankKeeper, app.stakeKeeper, app.accountMapper)(t, baseapp, log)
+		slashingsim.AllInvariants(),
-			slashingsim.AllInvariants()(t, baseapp, log)
-		},
 	}
 }
 

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(),
+			if !coins.IsNotNegative() {
-				fmt.Sprintf("%s has a negative denomination of %s\n%s",
+				return fmt.Errorf("%s has a negative denomination of %s",
 					acc.GetAddress().String(),
-					coins.String(),
+					coins.String())
-					log),
+			}
-			)
 		}
+		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

@@ -5,9 +5,6 @@ import (
 	"fmt"
 	"math/big"
 	"math/rand"
-	"testing"
-
-	"github.com/stretchr/testify/require"
 
 	"github.com/cosmos/cosmos-sdk/baseapp"
 	sdk "github.com/cosmos/cosmos-sdk/types"
@@ -21,7 +18,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(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,14 +48,16 @@ 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(app, mapper, msg, ctx, []crypto.PrivKey{fromKey})
+		if goErr != nil {
+			return "", nil, goErr
+		}
 		event("bank/sendAndVerifyMsgSend/ok")
 
 		return action, nil, nil
@@ -66,7 +65,7 @@ func SimulateSingleInputMsgSend(mapper auth.AccountMapper) simulation.Operation
 }
 
 // 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(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))
@@ -89,25 +88,22 @@ func sendAndVerifyMsgSend(tb testing.TB, app *baseapp.BaseApp, mapper auth.Accou
 	res := app.Deliver(tx)
 	if !res.IsOK() {
 		// TODO: Do this in a more 'canonical' way
-		fmt.Println(res)
+		return fmt.Errorf("Deliver failed %v", 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,
+		if !initialInputAddrCoins[i].Minus(msg.Inputs[i].Coins).IsEqual(terminalInputCoins) {
-			initialInputAddrCoins[i].Minus(msg.Inputs[i].Coins),
+			return fmt.Errorf("input #%d had an incorrect amount of coins", i)
-			terminalInputCoins,
+		}
-			fmt.Sprintf("Input #%d had an incorrect amount of coins\n%s", i, log),
-		)
 	}
 	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

@@ -4,7 +4,6 @@ import (
 	"fmt"
 	"math"
 	"math/rand"
-	"testing"
 
 	"github.com/tendermint/tendermint/crypto"
 
@@ -45,10 +44,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(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(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 +79,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(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(r, sender)
+		if err != nil {
+			return "", nil, err
+		}
 		action = simulateHandleMsgSubmitProposal(msg, sk, handler, ctx, event)
 		return action, nil, nil
 	}
@@ -100,10 +105,10 @@ 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(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,
@@ -111,14 +116,14 @@ func simulationCreateMsgSubmitProposal(tb testing.TB, r *rand.Rand, sender crypt
 		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(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 +133,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 +158,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(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 +173,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)

x/mock/simulation/random_simulate_blocks.go

@@ -8,6 +8,7 @@ import (
 	"os"
 	"os/signal"
 	"sort"
+	"strings"
 	"syscall"
 	"testing"
 	"time"
@@ -57,11 +58,10 @@ func SimulateFromSeed(
 	invariants []Invariant, numBlocks int, blockSize int, commit bool,
 ) {
 	testingMode, t, b := getTestingMode(tb)
-	log := fmt.Sprintf("Starting SimulateFromSeed with randomness created with seed %d", int(seed))
+	fmt.Printf("Starting SimulateFromSeed with randomness created with seed %d\n", int(seed))
 	r := rand.New(rand.NewSource(seed))
 	timestamp := randTimestamp(r)
-	log = updateLog(testingMode, log, "Starting the simulation from time %v, unixtime %v", timestamp.UTC().Format(time.UnixDate), timestamp.Unix())
+	fmt.Printf("Starting the simulation from time %v, unixtime %v\n", timestamp.UTC().Format(time.UnixDate), timestamp.Unix())
-	fmt.Printf("%s\n", log)
 	timeDiff := maxTimePerBlock - minTimePerBlock
 
 	keys, accs := mock.GeneratePrivKeyAddressPairsFromRand(r, numKeys)
@@ -69,7 +69,6 @@ func SimulateFromSeed(
 	// Setup event stats
 	events := make(map[string]uint)
 	event := func(what string) {
-		log = updateLog(testingMode, log, "event - %s", what)
 		events[what]++
 	}
 
@@ -91,14 +90,18 @@ func SimulateFromSeed(
 	var pastTimes []time.Time
 	var pastSigningValidators [][]abci.SigningValidator
 
-	request := RandomRequestBeginBlock(r, validators, livenessTransitionMatrix, evidenceFraction, pastTimes, pastSigningValidators, event, header, log)
+	request := RandomRequestBeginBlock(r, validators, livenessTransitionMatrix, evidenceFraction, pastTimes, pastSigningValidators, event, header)
 	// These are operations which have been queued by previous operations
 	operationQueue := make(map[int][]Operation)
+	var blockLogBuilders []*strings.Builder
 
 	if !testingMode {
 		b.ResetTimer()
+	} else {
+		blockLogBuilders = make([]*strings.Builder, numBlocks)
 	}
-	blockSimulator := createBlockSimulator(testingMode, tb, t, event, invariants, ops, operationQueue, numBlocks)
+	displayLogs := logPrinter(testingMode, blockLogBuilders)
+	blockSimulator := createBlockSimulator(testingMode, tb, t, event, invariants, ops, operationQueue, numBlocks, displayLogs)
 
 	for i := 0; i < numBlocks; i++ {
 		// Log the header time for future lookup
@@ -107,38 +110,38 @@ func SimulateFromSeed(
 
 		// Run the BeginBlock handler
 		app.BeginBlock(request)
-		log = updateLog(testingMode, log, "BeginBlock")
 
 		if testingMode {
 			// Make sure invariants hold at beginning of block
-			AssertAllInvariants(t, app, invariants, log)
+			assertAllInvariants(t, app, invariants, displayLogs)
 		}
+		logWriter := addLogMessage(testingMode, blockLogBuilders, i)
 
 		ctx := app.NewContext(false, header)
 		thisBlockSize := getBlockSize(r, blockSize)
 
 		// Run queued operations. Ignores blocksize if blocksize is too small
-		log, numQueuedOpsRan := runQueuedOperations(operationQueue, int(header.Height), tb, r, app, ctx, keys, log, event)
+		numQueuedOpsRan := runQueuedOperations(operationQueue, int(header.Height), tb, r, app, ctx, keys, logWriter, displayLogs, event)
 		opCount += numQueuedOpsRan
 		thisBlockSize -= numQueuedOpsRan
-		log, operations := blockSimulator(thisBlockSize, r, app, ctx, keys, log, header)
+		operations := blockSimulator(thisBlockSize, r, app, ctx, keys, header, logWriter)
 		opCount += operations
 
 		res := app.EndBlock(abci.RequestEndBlock{})
 		header.Height++
 		header.Time = header.Time.Add(time.Duration(minTimePerBlock) * time.Second).Add(time.Duration(int64(r.Intn(int(timeDiff)))) * time.Second)
-		log = updateLog(testingMode, log, "EndBlock")
+		logWriter("EndBlock")
 
 		if testingMode {
 			// Make sure invariants hold at end of block
-			AssertAllInvariants(t, app, invariants, log)
+			assertAllInvariants(t, app, invariants, displayLogs)
 		}
 		if commit {
 			app.Commit()
 		}
 
 		// Generate a random RequestBeginBlock with the current validator set for the next block
-		request = RandomRequestBeginBlock(r, validators, livenessTransitionMatrix, evidenceFraction, pastTimes, pastSigningValidators, event, header, log)
+		request = RandomRequestBeginBlock(r, validators, livenessTransitionMatrix, evidenceFraction, pastTimes, pastSigningValidators, event, header)
 
 		// Update the validator set
 		validators = updateValidators(tb, r, validators, res.ValidatorUpdates, event)
@@ -150,21 +153,22 @@ func SimulateFromSeed(
 
 // Returns a function to simulate blocks. Written like this to avoid constant parameters being passed everytime, to minimize
 // memory overhead
-func createBlockSimulator(testingMode bool, tb testing.TB, t *testing.T, event func(string), invariants []Invariant, ops []Operation, operationQueue map[int][]Operation, totalNumBlocks int) func(
+func createBlockSimulator(testingMode bool, tb testing.TB, t *testing.T, event func(string), invariants []Invariant, ops []Operation, operationQueue map[int][]Operation, totalNumBlocks int, displayLogs func()) func(
-	blocksize int, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, privKeys []crypto.PrivKey, log string, header abci.Header) (updatedLog string, opCount int) {
+	blocksize int, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, privKeys []crypto.PrivKey, header abci.Header, logWriter func(string)) (opCount int) {
 	return func(blocksize int, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context,
-		keys []crypto.PrivKey, log string, header abci.Header) (updatedLog string, opCount int) {
+		keys []crypto.PrivKey, header abci.Header, logWriter func(string)) (opCount int) {
 		for j := 0; j < blocksize; j++ {
-			logUpdate, futureOps, err := ops[r.Intn(len(ops))](tb, r, app, ctx, keys, log, event)
+			logUpdate, futureOps, err := ops[r.Intn(len(ops))](r, app, ctx, keys, event)
-			log = updateLog(testingMode, log, logUpdate)
 			if err != nil {
-				tb.Fatalf("error on operation %d within block %d, %v, log %s", header.Height, opCount, err, log)
+				displayLogs()
+				tb.Fatalf("error on operation %d within block %d, %v", header.Height, opCount, err)
 			}
+			logWriter(logUpdate)
 
 			queueOperations(operationQueue, futureOps)
 			if testingMode {
 				if onOperation {
-					AssertAllInvariants(t, app, invariants, log)
+					assertAllInvariants(t, app, invariants, displayLogs)
 				}
 				if opCount%50 == 0 {
 					fmt.Printf("\rSimulating... block %d/%d, operation %d/%d.  ", header.Height, totalNumBlocks, opCount, blocksize)
@@ -172,7 +176,7 @@ func createBlockSimulator(testingMode bool, tb testing.TB, t *testing.T, event f
 			}
 			opCount++
 		}
-		return log, opCount
+		return opCount
 	}
 }
 
@@ -187,14 +191,6 @@ func getTestingMode(tb testing.TB) (testingMode bool, t *testing.T, b *testing.B
 	return
 }
 
-func updateLog(testingMode bool, log string, update string, args ...interface{}) (updatedLog string) {
-	if testingMode {
-		update = fmt.Sprintf(update, args...)
-		return fmt.Sprintf("%s\n%s", log, update)
-	}
-	return ""
-}
-
 func getBlockSize(r *rand.Rand, blockSize int) int {
 	load := r.Float64()
 	switch {
@@ -223,25 +219,24 @@ func queueOperations(queuedOperations map[int][]Operation, futureOperations []Fu
 
 // nolint: errcheck
 func runQueuedOperations(queueOperations map[int][]Operation, height int, tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context,
-	privKeys []crypto.PrivKey, log string, event func(string)) (updatedLog string, numOpsRan int) {
+	privKeys []crypto.PrivKey, logWriter func(string), displayLogs func(), event func(string)) (numOpsRan int) {
-	updatedLog = log
 	if queuedOps, ok := queueOperations[height]; ok {
 		numOps := len(queuedOps)
 		for i := 0; i < numOps; i++ {
 			// For now, queued operations cannot queue more operations.
 			// If a need arises for us to support queued messages to queue more messages, this can
 			// be changed.
-			logUpdate, _, err := queuedOps[i](tb, r, app, ctx, privKeys, updatedLog, event)
+			logUpdate, _, err := queuedOps[i](r, app, ctx, privKeys, event)
-			updatedLog = fmt.Sprintf("%s\n%s", updatedLog, logUpdate)
+			logWriter(logUpdate)
 			if err != nil {
-				fmt.Fprint(os.Stderr, updatedLog)
+				displayLogs()
 				tb.FailNow()
 			}
 		}
 		delete(queueOperations, height)
-		return updatedLog, numOps
+		return numOps
 	}
-	return log, 0
+	return 0
 }
 
 func getKeys(validators map[string]mockValidator) []string {
@@ -258,7 +253,7 @@ func getKeys(validators map[string]mockValidator) []string {
 // RandomRequestBeginBlock generates a list of signing validators according to the provided list of validators, signing fraction, and evidence fraction
 // nolint: unparam
 func RandomRequestBeginBlock(r *rand.Rand, validators map[string]mockValidator, livenessTransitions TransitionMatrix, evidenceFraction float64,
-	pastTimes []time.Time, pastSigningValidators [][]abci.SigningValidator, event func(string), header abci.Header, log string) abci.RequestBeginBlock {
+	pastTimes []time.Time, pastSigningValidators [][]abci.SigningValidator, event func(string), header abci.Header) abci.RequestBeginBlock {
 	if len(validators) == 0 {
 		return abci.RequestBeginBlock{Header: header}
 	}
@@ -326,13 +321,6 @@ func RandomRequestBeginBlock(r *rand.Rand, validators map[string]mockValidator,
 	}
 }
 
-// AssertAllInvariants asserts a list of provided invariants against application state
-func AssertAllInvariants(t *testing.T, app *baseapp.BaseApp, tests []Invariant, log string) {
-	for i := 0; i < len(tests); i++ {
-		tests[i](t, app, log)
-	}
-}
-
 // updateValidators mimicks Tendermint's update logic
 // nolint: unparam
 func updateValidators(tb testing.TB, r *rand.Rand, current map[string]mockValidator, updates []abci.Validator, event func(string)) map[string]mockValidator {

x/mock/simulation/types.go

@@ -2,7 +2,6 @@ package simulation
 
 import (
 	"math/rand"
-	"testing"
 
 	"github.com/cosmos/cosmos-sdk/baseapp"
 	sdk "github.com/cosmos/cosmos-sdk/types"
@@ -22,18 +21,18 @@ type (
 	//
 	// Operations can optionally provide a list of "FutureOperations" to run later
 	// These will be ran at the beginning of the corresponding block.
-	Operation func(
+	Operation func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context,
-		tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context,
+		privKeys []crypto.PrivKey, event func(string),
-		privKeys []crypto.PrivKey, log string, event func(string),
+	) (action string, futureOperations []FutureOperation, err error)
-	) (action string, futureOperations []FutureOperation, err sdk.Error)
 
 	// RandSetup performs the random setup the mock module needs.
 	RandSetup func(r *rand.Rand, privKeys []crypto.PrivKey)
 
 	// An Invariant is a function which tests a particular invariant.
-	// If the invariant has been broken, the function should halt the
+	// If the invariant has been broken, it should return an error
-	// test and output the log.
+	// containing a descriptive message about what happened.
-	Invariant func(t *testing.T, app *baseapp.BaseApp, log string)
+	// The simulator will then halt and print the logs.
+	Invariant func(app *baseapp.BaseApp) error
 
 	mockValidator struct {
 		val           abci.Validator
@@ -54,9 +53,10 @@ type (
 // a given invariant if the mock application's last block modulo the given
 // period is congruent to the given offset.
 func PeriodicInvariant(invariant Invariant, period int, offset int) Invariant {
-	return func(t *testing.T, app *baseapp.BaseApp, log string) {
+	return func(app *baseapp.BaseApp) error {
 		if int(app.LastBlockHeight())%period == offset {
-			invariant(t, app, log)
+			return invariant(app)
 		}
+		return nil
 	}
 }

x/mock/simulation/util.go

@@ -4,9 +4,12 @@ import (
 	"fmt"
 	"math/rand"
 	"sort"
+	"strings"
+	"testing"
 
 	"github.com/tendermint/tendermint/crypto"
 
+	"github.com/cosmos/cosmos-sdk/baseapp"
 	sdk "github.com/cosmos/cosmos-sdk/types"
 )
 
@@ -62,3 +65,44 @@ func RandomKey(r *rand.Rand, keys []crypto.PrivKey) crypto.PrivKey {
 func RandomAmount(r *rand.Rand, max sdk.Int) sdk.Int {
 	return sdk.NewInt(int64(r.Intn(int(max.Int64()))))
 }
+
+// Builds a function to add logs for this particular block
+func addLogMessage(testingmode bool, blockLogBuilders []*strings.Builder, height int) func(string) {
+	if testingmode {
+		blockLogBuilders[height] = &strings.Builder{}
+		return func(x string) {
+			(*blockLogBuilders[height]).WriteString(x)
+			(*blockLogBuilders[height]).WriteString("\n")
+		}
+	}
+	return func(x string) {}
+}
+
+// assertAllInvariants asserts a list of provided invariants against application state
+func assertAllInvariants(t *testing.T, app *baseapp.BaseApp, invariants []Invariant, displayLogs func()) {
+	for i := 0; i < len(invariants); i++ {
+		err := invariants[i](app)
+		if err != nil {
+			fmt.Println(err.Error())
+			displayLogs()
+			t.Fatal()
+		}
+	}
+}
+
+// Creates a function to print out the logs
+func logPrinter(testingmode bool, logs []*strings.Builder) func() {
+	if testingmode {
+		return func() {
+			for i := 0; i < len(logs); i++ {
+				// We're passed the last created block
+				if logs[i] == nil {
+					return
+				}
+				fmt.Printf("Begin block %d\n", i)
+				fmt.Println((*logs[i]).String())
+			}
+		}
+	}
+	return func() {}
+}

x/slashing/simulation/invariants.go

@@ -1,18 +1,14 @@
 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 slashing invariants
 func AllInvariants() simulation.Invariant {
-	return func(t *testing.T, app *baseapp.BaseApp, log string) {
+	return func(app *baseapp.BaseApp) error {
 		// TODO Any invariants to check here?
-		require.Nil(t, nil)
+		return nil
 	}
 }

x/slashing/simulation/msgs.go

@@ -3,7 +3,6 @@ package simulation
 import (
 	"fmt"
 	"math/rand"
-	"testing"
 
 	"github.com/tendermint/tendermint/crypto"
 
@@ -15,12 +14,12 @@ import (
 
 // SimulateMsgUnjail
 func SimulateMsgUnjail(k slashing.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(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)
 		address := sdk.ValAddress(key.PubKey().Address())
 		msg := slashing.NewMsgUnjail(address)
 		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 := slashing.NewHandler(k)(ctx, msg)

x/stake/simulation/invariants.go

@@ -1,9 +1,7 @@
 package simulation
 
 import (
-	"testing"
+	"fmt"
-
-	"github.com/stretchr/testify/require"
 
 	"github.com/cosmos/cosmos-sdk/baseapp"
 	sdk "github.com/cosmos/cosmos-sdk/types"
@@ -17,17 +15,24 @@ import (
 // AllInvariants runs all invariants of the stake module.
 // Currently: total supply, positive power
 func AllInvariants(ck bank.Keeper, k stake.Keeper, am auth.AccountMapper) simulation.Invariant {
-	return func(t *testing.T, app *baseapp.BaseApp, log string) {
+	return func(app *baseapp.BaseApp) error {
-		SupplyInvariants(ck, k, am)(t, app, log)
+		err := SupplyInvariants(ck, k, am)(app)
-		PositivePowerInvariant(k)(t, app, log)
+		if err != nil {
-		ValidatorSetInvariant(k)(t, app, log)
+			return err
+		}
+		err = PositivePowerInvariant(k)(app)
+		if err != nil {
+			return err
+		}
+		err = ValidatorSetInvariant(k)(app)
+		return err
 	}
 }
 
 // SupplyInvariants checks that the total supply reflects all held loose tokens, bonded tokens, and unbonding delegations
 // nolint: unparam
 func SupplyInvariants(ck bank.Keeper, k stake.Keeper, am 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{})
 		//pool := k.GetPool(ctx)
 
@@ -64,23 +69,30 @@ func SupplyInvariants(ck bank.Keeper, k stake.Keeper, am auth.AccountMapper) sim
 		//   pool.BondedTokens.RoundInt64(), bonded.RoundInt64(), log)
 
 		// TODO Inflation check on total supply
+		return nil
 	}
 }
 
 // PositivePowerInvariant checks that all stored validators have > 0 power
 func PositivePowerInvariant(k stake.Keeper) simulation.Invariant {
-	return func(t *testing.T, app *baseapp.BaseApp, log string) {
+	return func(app *baseapp.BaseApp) error {
 		ctx := app.NewContext(false, abci.Header{})
+		var err error
 		k.IterateValidatorsBonded(ctx, func(_ int64, validator sdk.Validator) bool {
-			require.True(t, validator.GetPower().GT(sdk.ZeroDec()), "validator with non-positive power stored")
+			if !validator.GetPower().GT(sdk.ZeroDec()) {
+				err = fmt.Errorf("validator with non-positive power stored. (pubkey %v)", validator.GetPubKey())
+				return true
+			}
 			return false
 		})
+		return err
 	}
 }
 
 // ValidatorSetInvariant checks equivalence of Tendermint validator set and SDK validator set
 func ValidatorSetInvariant(k stake.Keeper) simulation.Invariant {
-	return func(t *testing.T, app *baseapp.BaseApp, log string) {
+	return func(app *baseapp.BaseApp) error {
 		// TODO
+		return nil
 	}
 }

x/stake/simulation/msgs.go

@@ -3,7 +3,6 @@ package simulation
 import (
 	"fmt"
 	"math/rand"
-	"testing"
 
 	"github.com/cosmos/cosmos-sdk/baseapp"
 	sdk "github.com/cosmos/cosmos-sdk/types"
@@ -18,7 +17,7 @@ import (
 // SimulateMsgCreateValidator
 func SimulateMsgCreateValidator(m auth.AccountMapper, k stake.Keeper) simulation.Operation {
 	handler := stake.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, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 
 		denom := k.GetParams(ctx).BondDenom
 		description := stake.Description{
@@ -42,7 +41,7 @@ func SimulateMsgCreateValidator(m auth.AccountMapper, k stake.Keeper) simulation
 			Delegation:    sdk.NewCoin(denom, amount),
 		}
 		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 := handler(ctx, msg)
@@ -59,7 +58,7 @@ func SimulateMsgCreateValidator(m auth.AccountMapper, k stake.Keeper) simulation
 // SimulateMsgEditValidator
 func SimulateMsgEditValidator(k stake.Keeper) simulation.Operation {
 	handler := stake.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, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 
 		description := stake.Description{
 			Moniker:  simulation.RandStringOfLength(r, 10),
@@ -75,7 +74,7 @@ func SimulateMsgEditValidator(k stake.Keeper) simulation.Operation {
 			ValidatorAddr: address,
 		}
 		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 := handler(ctx, msg)
@@ -91,7 +90,7 @@ func SimulateMsgEditValidator(k stake.Keeper) simulation.Operation {
 // SimulateMsgDelegate
 func SimulateMsgDelegate(m auth.AccountMapper, k stake.Keeper) simulation.Operation {
 	handler := stake.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, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 
 		denom := k.GetParams(ctx).BondDenom
 		validatorKey := simulation.RandomKey(r, keys)
@@ -111,7 +110,7 @@ func SimulateMsgDelegate(m auth.AccountMapper, k stake.Keeper) simulation.Operat
 			Delegation:    sdk.NewCoin(denom, amount),
 		}
 		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 := handler(ctx, msg)
@@ -127,7 +126,7 @@ func SimulateMsgDelegate(m auth.AccountMapper, k stake.Keeper) simulation.Operat
 // SimulateMsgBeginUnbonding
 func SimulateMsgBeginUnbonding(m auth.AccountMapper, k stake.Keeper) simulation.Operation {
 	handler := stake.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, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 
 		denom := k.GetParams(ctx).BondDenom
 		validatorKey := simulation.RandomKey(r, keys)
@@ -147,7 +146,7 @@ func SimulateMsgBeginUnbonding(m auth.AccountMapper, k stake.Keeper) simulation.
 			SharesAmount:  sdk.NewDecFromInt(amount),
 		}
 		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 := handler(ctx, msg)
@@ -163,7 +162,7 @@ func SimulateMsgBeginUnbonding(m auth.AccountMapper, k stake.Keeper) simulation.
 // SimulateMsgCompleteUnbonding
 func SimulateMsgCompleteUnbonding(k stake.Keeper) simulation.Operation {
 	handler := stake.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, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 
 		validatorKey := simulation.RandomKey(r, keys)
 		validatorAddress := sdk.ValAddress(validatorKey.PubKey().Address())
@@ -174,7 +173,7 @@ func SimulateMsgCompleteUnbonding(k stake.Keeper) simulation.Operation {
 			ValidatorAddr: validatorAddress,
 		}
 		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 := handler(ctx, msg)
@@ -190,7 +189,7 @@ func SimulateMsgCompleteUnbonding(k stake.Keeper) simulation.Operation {
 // SimulateMsgBeginRedelegate
 func SimulateMsgBeginRedelegate(m auth.AccountMapper, k stake.Keeper) simulation.Operation {
 	handler := stake.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, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 
 		denom := k.GetParams(ctx).BondDenom
 		sourceValidatorKey := simulation.RandomKey(r, keys)
@@ -214,7 +213,7 @@ func SimulateMsgBeginRedelegate(m auth.AccountMapper, k stake.Keeper) simulation
 			SharesAmount:     sdk.NewDecFromInt(amount),
 		}
 		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 := handler(ctx, msg)
@@ -230,7 +229,7 @@ func SimulateMsgBeginRedelegate(m auth.AccountMapper, k stake.Keeper) simulation
 // SimulateMsgCompleteRedelegate
 func SimulateMsgCompleteRedelegate(k stake.Keeper) simulation.Operation {
 	handler := stake.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, fOp []simulation.FutureOperation, err sdk.Error) {
+	return func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context, keys []crypto.PrivKey, event func(string)) (action string, fOp []simulation.FutureOperation, err error) {
 
 		validatorSrcKey := simulation.RandomKey(r, keys)
 		validatorSrcAddress := sdk.ValAddress(validatorSrcKey.PubKey().Address())
@@ -244,7 +243,7 @@ func SimulateMsgCompleteRedelegate(k stake.Keeper) simulation.Operation {
 			ValidatorDstAddr: validatorDstAddress,
 		}
 		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 := handler(ctx, msg)