cosmos-sdk/x/mock/simulation/simulate.go

453 lines
14 KiB
Go
Raw Normal View History

2018-07-16 18:25:15 -07:00
package simulation
import (
2018-07-17 11:33:53 -07:00
"encoding/json"
"fmt"
"math/rand"
2018-08-29 23:02:15 -07:00
"os"
"os/signal"
"runtime/debug"
"sort"
"strings"
"syscall"
"testing"
"time"
abci "github.com/tendermint/tendermint/abci/types"
tmtypes "github.com/tendermint/tendermint/types"
2018-07-16 18:15:50 -07:00
"github.com/cosmos/cosmos-sdk/baseapp"
2018-07-17 15:04:10 -07:00
sdk "github.com/cosmos/cosmos-sdk/types"
)
2018-11-07 20:26:02 -08:00
// RandSetup performs the random setup the mock module needs.
type RandSetup func(r *rand.Rand, accounts []Account)
2018-07-17 11:33:53 -07:00
// Simulate tests application by sending random messages.
func Simulate(t *testing.T, app *baseapp.BaseApp,
appStateFn func(r *rand.Rand, accs []Account) json.RawMessage,
ops []WeightedOperation, setups []RandSetup,
invariants []Invariant, numBlocks int, blockSize int, commit bool) error {
time := time.Now().UnixNano()
2018-11-07 20:26:02 -08:00
return SimulateFromSeed(t, app, appStateFn, time, ops,
setups, invariants, numBlocks, blockSize, commit)
}
2018-11-07 20:26:02 -08:00
// initialize the chain for the simulation
2018-11-07 07:28:18 -08:00
func initChain(r *rand.Rand, params Params,
accounts []Account, setups []RandSetup, app *baseapp.BaseApp,
2018-11-07 20:26:02 -08:00
appStateFn func(r *rand.Rand, accounts []Account) json.RawMessage) mockValidators {
req := abci.RequestInitChain{
AppStateBytes: appStateFn(r, accounts),
2018-08-29 23:02:15 -07:00
}
2018-11-07 20:26:02 -08:00
res := app.InitChain(req)
validators = newMockValidators(res.Validators)
2018-08-29 23:02:15 -07:00
for i := 0; i < len(setups); i++ {
setups[i](r, accounts)
2018-08-29 23:02:15 -07:00
}
2018-11-07 20:26:02 -08:00
return validators
2018-08-29 23:02:15 -07:00
}
2018-07-17 11:33:53 -07:00
// SimulateFromSeed tests an application by running the provided
// operations, testing the provided invariants, but using the provided seed.
func SimulateFromSeed(tb testing.TB, app *baseapp.BaseApp,
appStateFn func(r *rand.Rand, accs []Account) json.RawMessage,
seed int64, ops []WeightedOperation, setups []RandSetup, invariants []Invariant,
numBlocks int, blockSize int, commit bool) (simError error) {
// in case we have to end early, don't os.Exit so that we can run cleanup code.
stopEarly := false
2018-09-01 12:32:24 -07:00
testingMode, t, b := getTestingMode(tb)
fmt.Printf("Starting SimulateFromSeed with randomness created with seed %d\n", int(seed))
r := rand.New(rand.NewSource(seed))
params := RandomParams(r) // := DefaultParams()
fmt.Printf("Randomized simulation params: %+v\n", params)
2018-11-07 07:37:45 -08:00
timestamp := RandTimestamp(r)
2018-11-07 09:19:58 -08:00
fmt.Printf("Starting the simulation from time %v, unixtime %v\n",
timestamp.UTC().Format(time.UnixDate), timestamp.Unix())
timeDiff := maxTimePerBlock - minTimePerBlock
accs := RandomAccounts(r, params.NumKeys)
2018-07-17 16:27:51 -07:00
// Setup event stats
events := make(map[string]uint)
event := func(what string) {
2018-07-17 22:50:04 -07:00
events[what]++
2018-07-17 16:27:51 -07:00
}
validators := initChain(r, params, accs, setups, app, appStateFn)
2018-11-07 09:19:58 -08:00
// Second variable to keep pending validator set (delayed one block since TM 0.24)
// Initially this is the same as the initial validator set
nextValidators := validators
2018-11-07 09:19:58 -08:00
header := abci.Header{
Height: 1,
Time: timestamp,
ProposerAddress: randomProposer(r, validators),
}
opCount := 0
// Setup code to catch SIGTERM's
c := make(chan os.Signal)
signal.Notify(c, os.Interrupt, syscall.SIGTERM, syscall.SIGINT)
go func() {
receivedSignal := <-c
2018-11-07 09:19:58 -08:00
fmt.Printf("\nExiting early due to %s, on block %d, operation %d\n",
receivedSignal, header.Height, opCount)
simError = fmt.Errorf("Exited due to %s", receivedSignal)
stopEarly = true
}()
2018-09-01 12:32:24 -07:00
var pastTimes []time.Time
var pastVoteInfos [][]abci.VoteInfo
2018-11-07 09:19:58 -08:00
request := RandomRequestBeginBlock(r, params,
validators, pastTimes, pastVoteInfos, event, header)
2018-11-07 07:28:18 -08:00
// These are operations which have been queued by previous operations
operationQueue := make(map[int][]Operation)
timeOperationQueue := []FutureOperation{}
var blockLogBuilders []*strings.Builder
if testingMode {
blockLogBuilders = make([]*strings.Builder, numBlocks)
2018-08-30 00:13:31 -07:00
}
displayLogs := logPrinter(testingMode, blockLogBuilders)
2018-11-07 07:28:18 -08:00
blockSimulator := createBlockSimulator(
testingMode, tb, t, params, event, invariants,
ops, operationQueue, timeOperationQueue,
numBlocks, blockSize, displayLogs)
if !testingMode {
b.ResetTimer()
} else {
// Recover logs in case of panic
defer func() {
if r := recover(); r != nil {
fmt.Println("Panic with err\n", r)
stackTrace := string(debug.Stack())
fmt.Println(stackTrace)
displayLogs()
2018-11-07 09:19:58 -08:00
simError = fmt.Errorf(
"Simulation halted due to panic on block %d",
header.Height)
}
}()
}
2018-08-30 00:13:31 -07:00
2018-11-07 09:19:58 -08:00
// TODO split up the contents of this for loop into new functions
for i := 0; i < numBlocks && !stopEarly; i++ {
2018-09-01 12:32:24 -07:00
// Log the header time for future lookup
pastTimes = append(pastTimes, header.Time)
pastVoteInfos = append(pastVoteInfos, request.LastCommitInfo.Votes)
2018-09-01 12:32:24 -07:00
2018-10-18 18:55:14 -07:00
// Construct log writer
logWriter := addLogMessage(testingMode, blockLogBuilders, i)
// Run the BeginBlock handler
2018-10-18 18:55:14 -07:00
logWriter("BeginBlock")
app.BeginBlock(request)
2018-09-01 12:32:24 -07:00
if testingMode {
2018-08-30 00:13:31 -07:00
// Make sure invariants hold at beginning of block
assertAllInvariants(t, app, invariants, "BeginBlock", displayLogs)
2018-08-30 00:13:31 -07:00
}
ctx := app.NewContext(false, header)
2018-08-29 23:02:15 -07:00
// Run queued operations. Ignores blocksize if blocksize is too small
2018-10-18 18:55:14 -07:00
logWriter("Queued operations")
2018-11-07 07:28:18 -08:00
numQueuedOpsRan := runQueuedOperations(
operationQueue, int(header.Height),
tb, r, app, ctx, accs, logWriter,
displayLogs, event)
numQueuedTimeOpsRan := runQueuedTimeOperations(
timeOperationQueue, header.Time,
tb, r, app, ctx, accs,
logWriter, displayLogs, event)
2018-10-18 18:55:14 -07:00
if testingMode && onOperation {
// Make sure invariants hold at end of queued operations
assertAllInvariants(t, app, invariants, "QueuedOperations", displayLogs)
2018-10-18 18:55:14 -07:00
}
logWriter("Standard operations")
operations := blockSimulator(r, app, ctx, accs, header, logWriter)
opCount += operations + numQueuedOpsRan + numQueuedTimeOpsRan
2018-10-18 18:55:14 -07:00
if testingMode {
// Make sure invariants hold at end of block
assertAllInvariants(t, app, invariants, "StandardOperations", displayLogs)
2018-10-18 18:55:14 -07:00
}
res := app.EndBlock(abci.RequestEndBlock{})
header.Height++
2018-11-07 07:28:18 -08:00
header.Time = header.Time.Add(
time.Duration(minTimePerBlock) * time.Second)
header.Time = header.Time.Add(
time.Duration(int64(r.Intn(int(timeDiff)))) * time.Second)
header.ProposerAddress = randomProposer(r, validators)
logWriter("EndBlock")
2018-09-01 12:32:24 -07:00
if testingMode {
2018-08-30 00:13:31 -07:00
// Make sure invariants hold at end of block
assertAllInvariants(t, app, invariants, "EndBlock", displayLogs)
2018-08-30 00:13:31 -07:00
}
if commit {
app.Commit()
}
if header.ProposerAddress == nil {
fmt.Printf("\nSimulation stopped early as all validators " +
"have been unbonded, there is nobody left propose a block!\n")
stopEarly = true
break
}
// Generate a random RequestBeginBlock with the current validator set for the next block
2018-11-07 09:19:58 -08:00
request = RandomRequestBeginBlock(r, params, validators,
pastTimes, pastVoteInfos, event, header)
// Update the validator set, which will be reflected in the application on the next block
validators = nextValidators
2018-11-07 09:19:58 -08:00
nextValidators = updateValidators(tb, r, params,
validators, res.ValidatorUpdates, event)
}
if stopEarly {
DisplayEvents(events)
return
}
fmt.Printf("\nSimulation complete. Final height (blocks): %d, "+
"final time (seconds), : %v, operations ran %d\n",
header.Height, header.Time, opCount)
DisplayEvents(events)
return nil
}
//______________________________________________________________________________
2018-11-07 07:28:18 -08:00
type blockSimFn func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context,
accounts []Account, header abci.Header, logWriter func(string)) (opCount int)
2018-10-31 10:11:41 -07:00
2018-11-07 20:26:02 -08:00
// 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, params Params,
2018-11-07 20:26:02 -08:00
event func(string), invariants []Invariant, ops WeightedOperations,
2018-11-07 07:28:18 -08:00
operationQueue map[int][]Operation, timeOperationQueue []FutureOperation,
2018-10-31 09:37:50 -07:00
totalNumBlocks int, avgBlockSize int, displayLogs func()) blockSimFn {
2018-11-07 09:19:58 -08:00
var lastBlocksizeState = 0 // state for [4 * uniform distribution]
var blocksize int
2018-11-07 20:26:02 -08:00
selectOp := ops.getSelectOpFn()
return func(r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context,
accounts []Account, header abci.Header, logWriter func(string)) (opCount int) {
2018-11-07 07:28:18 -08:00
fmt.Printf("\rSimulating... block %d/%d, operation %d/%d. ",
header.Height, totalNumBlocks, opCount, blocksize)
lastBlocksizeState, blocksize = getBlockSize(r, params, lastBlocksizeState, avgBlockSize)
2018-11-07 07:28:18 -08:00
for j := 0; j < blocksize; j++ {
logUpdate, futureOps, err := selectOp(r)(r, app, ctx, accounts, event)
logWriter(logUpdate)
if err != nil {
displayLogs()
2018-11-07 07:28:18 -08:00
tb.Fatalf("error on operation %d within block %d, %v",
header.Height, opCount, err)
}
queueOperations(operationQueue, timeOperationQueue, futureOps)
2018-09-01 12:32:24 -07:00
if testingMode {
if onOperation {
2018-11-07 07:28:18 -08:00
assertAllInvariants(t, app, invariants,
fmt.Sprintf("operation: %v", logUpdate), displayLogs)
}
if opCount%50 == 0 {
2018-11-07 07:28:18 -08:00
fmt.Printf("\rSimulating... block %d/%d, operation %d/%d. ",
header.Height, totalNumBlocks, opCount, blocksize)
}
}
opCount++
}
return opCount
}
}
// adds all future operations into the operation queue.
2018-11-07 07:28:18 -08:00
func queueOperations(queuedOperations map[int][]Operation,
queuedTimeOperations []FutureOperation,
futureOperations []FutureOperation) {
if futureOperations == nil {
return
}
for _, futureOp := range futureOperations {
if futureOp.BlockHeight != 0 {
if val, ok := queuedOperations[futureOp.BlockHeight]; ok {
queuedOperations[futureOp.BlockHeight] = append(val, futureOp.Op)
} else {
queuedOperations[futureOp.BlockHeight] = []Operation{futureOp.Op}
}
} else {
// TODO: Replace with proper sorted data structure, so don't have the copy entire slice
index := sort.Search(
len(queuedTimeOperations),
func(i int) bool {
return queuedTimeOperations[i].BlockTime.After(futureOp.BlockTime)
},
)
queuedTimeOperations = append(queuedTimeOperations, FutureOperation{})
copy(queuedTimeOperations[index+1:], queuedTimeOperations[index:])
queuedTimeOperations[index] = futureOp
}
}
}
2018-09-03 09:47:24 -07:00
// nolint: errcheck
2018-11-07 09:00:13 -08:00
func runQueuedOperations(queueOps map[int][]Operation,
2018-11-07 07:28:18 -08:00
height int, tb testing.TB, r *rand.Rand, app *baseapp.BaseApp, ctx sdk.Context,
accounts []Account, logWriter func(string),
displayLogs func(), event func(string)) (numOpsRan int) {
2018-11-07 09:19:58 -08:00
queuedOp, ok := queueOps[height]
if !ok {
return 0
}
numOps := len(queuedOp)
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 := queuedOp[i](r, app, ctx, accounts, event)
logWriter(logUpdate)
if err != nil {
displayLogs()
tb.FailNow()
}
}
2018-11-07 09:19:58 -08:00
delete(queueOps, height)
return numOps
}
2018-11-07 09:00:13 -08:00
func runQueuedTimeOperations(queueOps []FutureOperation,
2018-11-07 07:28:18 -08:00
currentTime time.Time, tb testing.TB, r *rand.Rand,
app *baseapp.BaseApp, ctx sdk.Context, accounts []Account,
logWriter func(string), displayLogs func(), event func(string)) (numOpsRan int) {
numOpsRan = 0
2018-11-07 09:00:13 -08:00
for len(queueOps) > 0 && currentTime.After(queueOps[0].BlockTime) {
// 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.
2018-11-07 09:00:13 -08:00
logUpdate, _, err := queueOps[0].Op(r, app, ctx, accounts, event)
logWriter(logUpdate)
if err != nil {
displayLogs()
tb.FailNow()
}
2018-11-07 09:00:13 -08:00
queueOps = queueOps[1:]
numOpsRan++
}
return numOpsRan
}
2018-11-07 07:28:18 -08:00
// RandomRequestBeginBlock generates a list of signing validators according to
// the provided list of validators, signing fraction, and evidence fraction
func RandomRequestBeginBlock(r *rand.Rand, params Params,
validators map[string]mockValidator, pastTimes []time.Time,
pastVoteInfos [][]abci.VoteInfo,
event func(string), header abci.Header) abci.RequestBeginBlock {
if len(validators) == 0 {
2018-11-07 09:19:58 -08:00
return abci.RequestBeginBlock{
Header: header,
}
}
voteInfos := make([]abci.VoteInfo, len(validators))
2018-11-07 09:19:58 -08:00
for i, key := range getKeys(validators) {
mVal := validators[key]
mVal.livenessState = params.LivenessTransitionMatrix.NextState(r, mVal.livenessState)
signed := true
if mVal.livenessState == 1 {
// spotty connection, 50% probability of success
// See https://github.com/golang/go/issues/23804#issuecomment-365370418
// for reasoning behind computing like this
signed = r.Int63()%2 == 0
} else if mVal.livenessState == 2 {
// offline
signed = false
}
2018-11-07 09:19:58 -08:00
if signed {
event("beginblock/signing/signed")
} else {
event("beginblock/signing/missed")
}
2018-11-07 09:19:58 -08:00
pubkey, err := tmtypes.PB2TM.PubKey(mVal.val.PubKey)
if err != nil {
panic(err)
}
voteInfos[i] = abci.VoteInfo{
Validator: abci.Validator{
Address: pubkey.Address(),
2018-10-16 15:34:16 -07:00
Power: mVal.val.Power,
},
SignedLastBlock: signed,
}
}
2018-11-07 09:19:58 -08:00
// return if no past times
if len(pastTimes) <= 0 {
return abci.RequestBeginBlock{
Header: header,
LastCommitInfo: abci.LastCommitInfo{
Votes: voteInfos,
},
}
}
2018-08-29 23:02:15 -07:00
// TODO: Determine capacity before allocation
evidence := make([]abci.Evidence, 0)
2018-11-07 09:19:58 -08:00
for r.Float64() < params.EvidenceFraction {
height := header.Height
time := header.Time
vals := voteInfos
if r.Float64() < params.PastEvidenceFraction {
height = int64(r.Intn(int(header.Height) - 1))
time = pastTimes[height]
vals = pastVoteInfos[height]
}
2018-11-07 09:19:58 -08:00
validator := vals[r.Intn(len(vals))].Validator
var totalVotingPower int64
for _, val := range vals {
totalVotingPower += val.Validator.Power
}
evidence = append(evidence, abci.Evidence{
Type: tmtypes.ABCIEvidenceTypeDuplicateVote,
Validator: validator,
Height: height,
Time: time,
TotalVotingPower: totalVotingPower,
})
event("beginblock/evidence")
}
2018-11-07 09:19:58 -08:00
return abci.RequestBeginBlock{
Header: header,
LastCommitInfo: abci.LastCommitInfo{
Votes: voteInfos,
},
ByzantineValidators: evidence,
}
}