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 <[email protected]>

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

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))

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,15 +21,13 @@ 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
 	})
 	if err != nil {
 		return err
 	}
-	vc.Reset(backend)
 	return nil
 }

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 {

deploy/def/deploy.go

@@ -38,4 +38,3 @@ func (args *DeployArgs) Validate() error {
 		validation.Field(&args.DefaultGas, rule.Uint64),
 	)
 }
-

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

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 {

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

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

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

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
 }

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
 }

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
 }

logging/loggers/stream_logger.go

@@ -38,15 +38,15 @@ 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}
 		default:
 			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) {

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.