From c80f7bebe8664702cc52efd0426b1bb4a6ddb993 Mon Sep 17 00:00:00 2001 From: Gregory Hill Date: Tue, 24 Mar 2020 20:06:20 +0000 Subject: [PATCH] Ensure execution caches are reset after state is updated Remove the Flush call that did not provide the appropriate behaviour. Also add resets to all caches not just some. This was a logical error but only actually caused an issues with the vaildatorCache which unlike other caches performs a copy on `Reset(backend)`. Getting the causality right here for the other caches should help avoid future bugs. Signed-off-by: Silas Davis --- acm/acmstate/metadata_cache.go | 8 ++------ acm/acmstate/state_cache.go | 10 ---------- acm/validator/cache.go | 5 +---- cmd/burrow/commands/deploy.go | 8 ++++---- deploy/def/deploy.go | 1 - deploy/def/playbook.go | 2 +- execution/contexts/bond_context.go | 3 --- execution/contexts/call_context.go | 3 ++- execution/contexts/unbond_context.go | 4 ---- execution/execution.go | 20 ++++++++++++++------ execution/names/cache.go | 10 ---------- execution/proposal/cache.go | 10 ---------- execution/registry/cache.go | 10 ---------- logging/loggers/stream_logger.go | 4 ++-- util/debug.go | 4 ++-- 15 files changed, 28 insertions(+), 74 deletions(-) diff --git a/acm/acmstate/metadata_cache.go b/acm/acmstate/metadata_cache.go index acbe60a05..34fdb8308 100644 --- a/acm/acmstate/metadata_cache.go +++ b/acm/acmstate/metadata_cache.go @@ -55,13 +55,9 @@ func (cache *MetadataCache) Sync(st MetadataWriter) error { return nil } -func (cache *MetadataCache) Flush(output MetadataWriter, backend MetadataReader) error { - err := cache.Sync(output) - if err != nil { - return err - } +func (cache *MetadataCache) Reset(backend MetadataReader) { + cache.backend = backend cache.m = sync.Map{} - return nil } // Get the cache accountInfo item creating it if necessary diff --git a/acm/acmstate/state_cache.go b/acm/acmstate/state_cache.go index e6fac7fdb..59e364c64 100644 --- a/acm/acmstate/state_cache.go +++ b/acm/acmstate/state_cache.go @@ -250,16 +250,6 @@ func (cache *Cache) Reset(backend Reader) { cache.accounts = make(map[crypto.Address]*accountInfo, len(cache.accounts)) } -// Syncs the Cache to output and Resets it to use backend as Reader -func (cache *Cache) Flush(output Writer, backend Reader) error { - err := cache.Sync(output) - if err != nil { - return err - } - cache.Reset(backend) - return nil -} - func (cache *Cache) String() string { if cache.name == "" { return fmt.Sprintf("StateCache{Length: %v}", len(cache.accounts)) diff --git a/acm/validator/cache.go b/acm/validator/cache.go index 698a42adb..972d9b3a5 100644 --- a/acm/validator/cache.go +++ b/acm/validator/cache.go @@ -4,7 +4,6 @@ import ( "math/big" "github.com/hyperledger/burrow/crypto" - "github.com/hyperledger/burrow/util" ) // Cache is just a Ring with no memory @@ -22,8 +21,7 @@ func (vc *Cache) Reset(backend Iterable) { vc.Bucket = NewBucket(backend) } -func (vc *Cache) Flush(output Writer, backend Iterable) error { - util.Debugf("Flushing validators...") +func (vc *Cache) Sync(output Writer) error { err := vc.Delta.IterateValidators(func(id crypto.Addressable, power *big.Int) error { _, err := output.SetPower(id.GetPublicKey(), power) return err @@ -31,6 +29,5 @@ func (vc *Cache) Flush(output Writer, backend Iterable) error { if err != nil { return err } - vc.Reset(backend) return nil } diff --git a/cmd/burrow/commands/deploy.go b/cmd/burrow/commands/deploy.go index 84ef74303..309c74db7 100644 --- a/cmd/burrow/commands/deploy.go +++ b/cmd/burrow/commands/deploy.go @@ -50,9 +50,9 @@ func Deploy(output Output) func(cmd *cli.Cmd) { addressOpt := cmd.StringOpt("a address", "", "default address (or account name) to use; operates the same way as the [account] job, only before the deploy file is ran") - defaultFeeOpt := cmd.StringOpt("n fee", "9999", "default fee to use") + defaultFeeOpt := cmd.StringOpt("n fee", "99", "default fee to use") - defaultAmountOpt := cmd.StringOpt("m amount", "9999", + defaultAmountOpt := cmd.StringOpt("m amount", "99", "default amount to use") verboseOpt := cmd.BoolOpt("v verbose", false, "verbose output") @@ -116,11 +116,11 @@ func Deploy(output Output) func(cmd *cli.Cmd) { args.ProposeVerify = *proposalVerify args.ProposeVote = *proposalVote args.ProposeCreate = *proposalCreate - stderrLogger, err := loggers.NewStreamLogger(os.Stderr, loggers.TerminalFormat) + stdoutLogger, err := loggers.NewStreamLogger(os.Stdout, loggers.TerminalFormat) if err != nil { output.Fatalf("Could not make logger: %v", err) } - logger := logging.NewLogger(stderrLogger) + logger := logging.NewLogger(stdoutLogger) handleTerm() if !*debugOpt { diff --git a/deploy/def/deploy.go b/deploy/def/deploy.go index e9d2118ed..7495b2e43 100644 --- a/deploy/def/deploy.go +++ b/deploy/def/deploy.go @@ -38,4 +38,3 @@ func (args *DeployArgs) Validate() error { validation.Field(&args.DefaultGas, rule.Uint64), ) } - diff --git a/deploy/def/playbook.go b/deploy/def/playbook.go index b16ee15fa..99a79bac2 100644 --- a/deploy/def/playbook.go +++ b/deploy/def/playbook.go @@ -1,6 +1,6 @@ package def -import "github.com/go-ozzo/ozzo-validation" +import validation "github.com/go-ozzo/ozzo-validation" type Playbook struct { Filename string diff --git a/execution/contexts/bond_context.go b/execution/contexts/bond_context.go index 54dd22275..c79c3e169 100644 --- a/execution/contexts/bond_context.go +++ b/execution/contexts/bond_context.go @@ -10,7 +10,6 @@ import ( "github.com/hyperledger/burrow/execution/exec" "github.com/hyperledger/burrow/logging" "github.com/hyperledger/burrow/txs/payload" - "github.com/hyperledger/burrow/util" ) type BondContext struct { @@ -60,8 +59,6 @@ func (ctx *BondContext) Execute(txe *exec.TxExecution, p payload.Payload) error return err } - cache := ctx.ValidatorSet.(*validator.Cache) - util.Debugf("%v", cache.Bucket) // assume public key is know as we update account from signatures err = validator.AddPower(ctx.ValidatorSet, account.PublicKey, power) if err != nil { diff --git a/execution/contexts/call_context.go b/execution/contexts/call_context.go index 92ab28228..693653ffa 100644 --- a/execution/contexts/call_context.go +++ b/execution/contexts/call_context.go @@ -72,7 +72,8 @@ func (ctx *CallContext) Precheck() (*acm.Account, *acm.Account, error) { err = inAcc.SubtractFromBalance(ctx.tx.Fee) if err != nil { return nil, nil, errors.Errorf(errors.Codes.InsufficientFunds, - "Input account does not have sufficient balance to cover input amount: %v", ctx.tx.Input) + "Input account %v (balance: %d) does not have sufficient balance to cover input amount: %v", + inAcc.Address, inAcc.Balance, ctx.tx.Input) } // Calling a nil destination is defined as requesting contract creation diff --git a/execution/contexts/unbond_context.go b/execution/contexts/unbond_context.go index c2c6fed7c..31d551903 100644 --- a/execution/contexts/unbond_context.go +++ b/execution/contexts/unbond_context.go @@ -9,7 +9,6 @@ import ( "github.com/hyperledger/burrow/execution/exec" "github.com/hyperledger/burrow/logging" "github.com/hyperledger/burrow/txs/payload" - "github.com/hyperledger/burrow/util" ) type UnbondContext struct { @@ -42,9 +41,6 @@ func (ctx *UnbondContext) Execute(txe *exec.TxExecution, p payload.Payload) erro return err } - util.Debugf("unbonding %v", power) - cache := ctx.ValidatorSet.(*validator.Cache) - util.Debugf("%v", cache.Bucket) err = validator.SubtractPower(ctx.ValidatorSet, account.PublicKey, power) if err != nil { return err diff --git a/execution/execution.go b/execution/execution.go index a9cbd0665..8ad6ebe52 100644 --- a/execution/execution.go +++ b/execution/execution.go @@ -355,27 +355,27 @@ func (exe *executor) Commit(header *abciTypes.Header) (stateHash []byte, err err // that nothing in the downstream commit process could have failed. At worst we go back one block. hash, version, err := exe.state.Update(func(ws state.Updatable) error { // flush the caches - err := exe.stateCache.Flush(ws, exe.state) + err := exe.stateCache.Sync(ws) if err != nil { return err } - err = exe.metadataCache.Flush(ws, exe.state) + err = exe.metadataCache.Sync(ws) if err != nil { return err } - err = exe.nameRegCache.Flush(ws, exe.state) + err = exe.nameRegCache.Sync(ws) if err != nil { return err } - err = exe.nodeRegCache.Flush(ws, exe.state) + err = exe.nodeRegCache.Sync(ws) if err != nil { return err } - err = exe.proposalRegCache.Flush(ws, exe.state) + err = exe.proposalRegCache.Sync(ws) if err != nil { return err } - err = exe.validatorCache.Flush(ws, exe.state) + err = exe.validatorCache.Sync(ws) if err != nil { return err } @@ -388,6 +388,12 @@ func (exe *executor) Commit(header *abciTypes.Header) (stateHash []byte, err err if err != nil { return nil, err } + // Complete flushing of caches by resetting them to the state we have just committed + err = exe.Reset() + if err != nil { + return nil, err + } + expectedHeight := HeightAtVersion(version) if expectedHeight != height { return nil, fmt.Errorf("expected height at state tree version %d is %d but actual height is %d", @@ -401,7 +407,9 @@ func (exe *executor) Commit(header *abciTypes.Header) (stateHash []byte, err err func (exe *executor) Reset() error { // As with Commit() we do not take the write lock here exe.stateCache.Reset(exe.state) + exe.metadataCache.Reset(exe.state) exe.nameRegCache.Reset(exe.state) + exe.nodeRegCache.Reset(exe.state) exe.proposalRegCache.Reset(exe.state) exe.validatorCache.Reset(exe.state) return nil diff --git a/execution/names/cache.go b/execution/names/cache.go index a2602038b..81dc72517 100644 --- a/execution/names/cache.go +++ b/execution/names/cache.go @@ -120,16 +120,6 @@ func (cache *Cache) Reset(backend Reader) { cache.names = make(map[string]*nameInfo) } -// Syncs the Cache and Resets it to use Writer as the backend Reader -func (cache *Cache) Flush(output Writer, backend Reader) error { - err := cache.Sync(output) - if err != nil { - return err - } - cache.Reset(backend) - return nil -} - func (cache *Cache) Backend() Reader { return cache.backend } diff --git a/execution/proposal/cache.go b/execution/proposal/cache.go index 61fedb968..7784582a9 100644 --- a/execution/proposal/cache.go +++ b/execution/proposal/cache.go @@ -145,16 +145,6 @@ func (cache *Cache) Reset(backend Reader) { cache.proposals = make(map[[sha256.Size]byte]*proposalInfo) } -// Syncs the Cache and Resets it to use Writer as the backend Reader -func (cache *Cache) Flush(output Writer, backend Reader) error { - err := cache.Sync(output) - if err != nil { - return err - } - cache.Reset(backend) - return nil -} - func (cache *Cache) Backend() Reader { return cache.backend } diff --git a/execution/registry/cache.go b/execution/registry/cache.go index 46cac74d0..8dbb1099e 100644 --- a/execution/registry/cache.go +++ b/execution/registry/cache.go @@ -125,16 +125,6 @@ func (cache *Cache) Reset(backend Reader) { cache.registry = make(map[crypto.Address]*nodeInfo) } -// Syncs the Cache and Resets it to use Writer as the backend Reader -func (cache *Cache) Flush(output Writer, backend Reader) error { - err := cache.Sync(output) - if err != nil { - return err - } - cache.Reset(backend) - return nil -} - func (cache *Cache) Backend() Reader { return cache.backend } diff --git a/logging/loggers/stream_logger.go b/logging/loggers/stream_logger.go index 4794a6a60..98a485b1c 100644 --- a/logging/loggers/stream_logger.go +++ b/logging/loggers/stream_logger.go @@ -38,7 +38,7 @@ func NewLogfmtLogger(writer io.Writer) log.Logger { } func NewTerminalLogger(writer io.Writer) log.Logger { - logger := term.NewLogger(writer, log.NewLogfmtLogger, func(keyvals ...interface{}) term.FgBgColor { + logger := term.NewLogger(writer, log.NewLogfmtLogger, func(keyvals ...interface{}) term.FgBgColor { switch structure.Value(keyvals, structure.ChannelKey) { case structure.TraceChannelName: return term.FgBgColor{Fg: term.DarkGreen} @@ -46,7 +46,7 @@ func NewTerminalLogger(writer io.Writer) log.Logger { return term.FgBgColor{Fg: term.Yellow} } }) - return interceptSync(writer,NewBurrowFormatLogger(logger, StringifyValues)) + return interceptSync(writer, NewBurrowFormatLogger(logger, StringifyValues)) } func NewTemplateLogger(writer io.Writer, textTemplate string, recordSeparator []byte) (log.Logger, error) { diff --git a/util/debug.go b/util/debug.go index 1129df1c7..5e9e70cfa 100644 --- a/util/debug.go +++ b/util/debug.go @@ -4,8 +4,8 @@ import "fmt" // If we ever want to ship some specific debug we could make this a string var and set it through -ldflags "-X ..." -const debug = true -//const debug = false +//const debug = true +const debug = false // Using this in place of Printf statements makes it easier to find any errant debug statements and the switch means // we can turn them off at minimal runtime cost.