Additional logging to investigate issue with very large eth_estimateGas value

core/state/statedb.go

@@ -191,8 +191,10 @@ func (self *StateDB) Empty(addr common.Address) bool {
 func (self *StateDB) GetBalance(addr common.Address) *big.Int {
 	stateObject := self.getStateObject(addr)
 	if stateObject != nil {
+		log.Info(fmt.Sprintf("======== statedb : ACCOUNT FOUND: %x, with balance = %v", addr, stateObject.Balance()))
 		return stateObject.Balance()
 	}
+	log.Info(fmt.Sprintf("======== statedb : ACCOUNT NOT FOUND: %x", addr))
 	return common.Big0
 }
 

core/state_transition.go

@@ -220,6 +220,7 @@ func (st *StateTransition) TransitionDb() (ret []byte, usedGas uint64, failed bo
 
 	// Pay intrinsic gas
 	gas, err := IntrinsicGas(st.data, contractCreation, homestead)
+	log.Info("======== state_transition.go::TransitionDb(), calculated: ", "intrinsicGas", gas)
 	if err != nil {
 		return nil, 0, false, err
 	}
@@ -256,6 +257,7 @@ func (st *StateTransition) TransitionDb() (ret []byte, usedGas uint64, failed bo
 
 		ret, st.gas, vmerr = evm.Call(sender, to, data, st.gas, st.value)
 	}
+	log.Info("======== state_transition.go::TransitionDb(), used gas calculation: ", "st.gas", st.gas)
 	if vmerr != nil {
 		log.Debug("VM returned with error", "err", vmerr)
 		// The only possible consensus-error would be if there wasn't

core/vm/evm.go

@@ -25,6 +25,7 @@ import (
 	"github.com/ethereum/go-ethereum/core/state"
 	"github.com/ethereum/go-ethereum/crypto"
 	"github.com/ethereum/go-ethereum/params"
+	"github.com/ethereum/go-ethereum/log"
 )
 
 // note: Quorum, States, and Value Transfer
@@ -173,6 +174,7 @@ func (evm *EVM) Call(caller ContractRef, addr common.Address, input []byte, gas
 		return nil, gas, nil
 	}
 
+	log.Info("======== evm Call(): getting state for:", "addr", addr)
 	evm.Push(getDualState(evm, addr))
 	defer func() { evm.Pop() }()
 
@@ -208,6 +210,7 @@ func (evm *EVM) Call(caller ContractRef, addr common.Address, input []byte, gas
 		// skip transfer if value /= 0 (see note: Quorum, States, and Value Transfer)
 		if value.Sign() != 0 {
 			if evm.quorumReadOnly {
+				log.Info("======== evm Call() 1: disallowing transfer due to read-only flag")
 				return nil, gas, ErrReadOnlyValueTransfer
 			}
 			evm.Transfer(evm.StateDB, caller.Address(), to.Address(), value)
@@ -415,6 +418,7 @@ func (evm *EVM) Create(caller ContractRef, code []byte, gas uint64, value *big.I
 		// skip transfer if value /= 0 (see note: Quorum, States, and Value Transfer)
 		if value.Sign() != 0 {
 			if evm.quorumReadOnly {
+				log.Info("======== evm create() 1: disallowing transfer due to read-only flag")
 				return nil, common.Address{}, gas, ErrReadOnlyValueTransfer
 			}
 			evm.Transfer(evm.StateDB, caller.Address(), contractAddr, value)
@@ -498,7 +502,9 @@ func getDualState(env *EVM, addr common.Address) StateDB {
 func (env *EVM) PublicState() PublicState   { return env.publicState }
 func (env *EVM) PrivateState() PrivateState { return env.privateState }
 func (env *EVM) Push(statedb StateDB) {
+	log.Info("======== evm Push(): ENTRY", "env.privateState", env.privateState, "statedb", statedb)
 	if env.privateState != statedb {
+		log.Info("======== evm Push(): setting quorumReadOnly to TRUE")
 		env.quorumReadOnly = true
 		env.readOnlyDepth = env.currentStateDepth
 	}
@@ -511,8 +517,10 @@ func (env *EVM) Push(statedb StateDB) {
 	env.StateDB = statedb
 }
 func (env *EVM) Pop() {
+	log.Info("======== evm Pop(): ENTRY")
 	env.currentStateDepth--
 	if env.quorumReadOnly && env.currentStateDepth == env.readOnlyDepth {
+		log.Info("======== evm Pop(): setting quorumReadOnly to FALSE")
 		env.quorumReadOnly = false
 	}
 	env.StateDB = env.states[env.currentStateDepth-1]

internal/ethapi/api.go

@@ -660,6 +660,7 @@ func (s *PublicBlockChainAPI) doCall(ctx context.Context, args CallArgs, blockNr
 
 	state, header, err := s.b.StateAndHeaderByNumber(ctx, blockNr)
 	if state == nil || err != nil {
+		log.Info(fmt.Sprintf("======== doCall 1: failure: %v", err))
 		return nil, 0, false, err
 	}
 	// Set sender address or use a default if none specified
@@ -699,6 +700,7 @@ func (s *PublicBlockChainAPI) doCall(ctx context.Context, args CallArgs, blockNr
 	// Get a new instance of the EVM.
 	evm, vmError, err := s.b.GetEVM(ctx, msg, state, header, vmCfg)
 	if err != nil {
+		log.Info(fmt.Sprintf("======== doCall 2: failure: %v", err))
 		return nil, 0, false, err
 	}
 	// Wait for the context to be done and cancel the evm. Even if the
@@ -713,8 +715,10 @@ func (s *PublicBlockChainAPI) doCall(ctx context.Context, args CallArgs, blockNr
 	gp := new(core.GasPool).AddGas(math.MaxUint64)
 	res, gas, failed, err := core.ApplyMessage(evm, msg, gp)
 	if err := vmError(); err != nil {
+		log.Info(fmt.Sprintf("======== doCall 3: failure: %v", err))
 		return nil, 0, false, err
 	}
+	log.Info(fmt.Sprintf("======== doCall 4: returning: failed = %v, err = %v", failed, err))
 	return res, gas, failed, err
 }
 
@@ -736,6 +740,7 @@ func (s *PublicBlockChainAPI) EstimateGas(ctx context.Context, args CallArgs) (h
 	)
 	if uint64(args.Gas) >= params.TxGas {
 		hi = uint64(args.Gas)
+		log.Info(fmt.Sprintf("======== estimateGas 1a: hi = %v, lo = %v", hi, lo))
 	} else {
 		// Retrieve the current pending block to act as the gas ceiling
 		block, err := s.b.BlockByNumber(ctx, rpc.PendingBlockNumber)
@@ -743,6 +748,7 @@ func (s *PublicBlockChainAPI) EstimateGas(ctx context.Context, args CallArgs) (h
 			return 0, err
 		}
 		hi = block.GasLimit()
+		log.Info(fmt.Sprintf("======== estimateGas 1b: hi = %v, lo = %v", hi, lo))
 	}
 	cap = hi
 
@@ -750,8 +756,10 @@ func (s *PublicBlockChainAPI) EstimateGas(ctx context.Context, args CallArgs) (h
 	executable := func(gas uint64) bool {
 		args.Gas = hexutil.Uint64(gas)
 
+		log.Info(fmt.Sprintf("======== estimateGas 3: calling EVM with mid = %v", gas))
 		_, _, failed, err := s.doCall(ctx, args, rpc.PendingBlockNumber, vm.Config{}, 0)
 		if err != nil || failed {
+			log.Info(fmt.Sprintf("======== estimateGas 5: EVM call failed with err %v", err))
 			return false
 		}
 		return true
@@ -760,8 +768,10 @@ func (s *PublicBlockChainAPI) EstimateGas(ctx context.Context, args CallArgs) (h
 	for lo+1 < hi {
 		mid := (hi + lo) / 2
 		if !executable(mid) {
+			log.Info(fmt.Sprintf("======== estimateGas 5b: Call failed, setting lo = %v", mid))
 			lo = mid
 		} else {
+			log.Info(fmt.Sprintf("======== estimateGas 5b: Call succeeded, setting hi = %v", mid))
 			hi = mid
 		}
 	}