logging: update (#37)

* logging: update * debug: remove message * log: correct from * log: return data from contract calls * logging: more cleanup * logs: more cleanup
cerc-io · Sep 29, 2020 · 1aca24b · 1aca24b
1 parent 9711566
commit 1aca24b
Show file tree

Hide file tree

Showing 5 changed files with 36 additions and 24 deletions.
diff --git a/core/state/statedb.go b/core/state/statedb.go
@@ -18,14 +18,14 @@
 package state
 
 import (
-	"encoding/hex"
 	"errors"
 	"fmt"
 	"math/big"
 	"sort"
 	"time"
 
 	"github.com/ethereum/go-ethereum/common"
+	"github.com/ethereum/go-ethereum/common/hexutil"
 	"github.com/ethereum/go-ethereum/core/types"
 	"github.com/ethereum/go-ethereum/crypto"
 	"github.com/ethereum/go-ethereum/log"
@@ -370,7 +370,7 @@ func (s *StateDB) SetBalance(addr common.Address, amount *big.Int) {
 }
 
 func (s *StateDB) SetNonce(addr common.Address, nonce uint64) {
-	log.Debug("Setting nonce!", "Contract address:", hex.EncodeToString(addr.Bytes()), "Nonce", nonce)
+	log.Debug("Setting nonce!", "Contract address", addr.Hex(), "Nonce", nonce)
 	stateObject := s.GetOrNewStateObject(addr)
 	if stateObject != nil {
 		stateObject.SetNonce(nonce)
@@ -385,7 +385,7 @@ func (s *StateDB) SetCode(addr common.Address, code []byte) {
 }
 
 func (s *StateDB) SetState(addr common.Address, key, value common.Hash) {
-	log.Debug("Setting State!", "Contract address:", hex.EncodeToString(addr.Bytes()), "Key:", hex.EncodeToString(key.Bytes()), "Value:", hex.EncodeToString(value.Bytes()))
+	log.Debug("Setting State!", "Contract address", addr.Hex(), "Key", hexutil.Encode(key.Bytes()), "Value", hexutil.Encode(value.Bytes()))
 	stateObject := s.GetOrNewStateObject(addr)
 	if stateObject != nil {
 		stateObject.SetState(s.db, key, value)

diff --git a/core/state_transition.go b/core/state_transition.go
@@ -25,6 +25,7 @@ import (
 
 	"github.com/ethereum/go-ethereum/accounts/abi"
 	"github.com/ethereum/go-ethereum/common"
+	"github.com/ethereum/go-ethereum/common/hexutil"
 	"github.com/ethereum/go-ethereum/core/vm"
 	"github.com/ethereum/go-ethereum/log"
 	"github.com/ethereum/go-ethereum/params"
@@ -222,7 +223,14 @@ func (st *StateTransition) TransitionDb() (ret []byte, usedGas uint64, failed bo
 		// error.
 		vmerr error
 	)
-	log.Debug("Applying new transaction (technically Message)!", "Tx (aka Message) data", st.msg)
+
+	to := "<nil>"
+	if msg.To() != nil {
+		to = msg.To().Hex()
+	}
+
+	log.Debug("Applying transaction", "from", sender.Address().Hex(), "to", to, "nonce", msg.Nonce(), "data", hexutil.Encode(msg.Data()))
+
 	executionMgrTime := st.evm.Time
 	if executionMgrTime.Cmp(big.NewInt(0)) == 0 {
 		executionMgrTime = big.NewInt(1)
@@ -270,6 +278,7 @@ func (st *StateTransition) TransitionDb() (ret []byte, usedGas uint64, failed bo
 	st.refundGas()
 	st.state.AddBalance(st.evm.Coinbase, new(big.Int).Mul(new(big.Int).SetUint64(st.gasUsed()), st.gasPrice))
 
+	log.Debug("return data", "data", hexutil.Encode(ret))
 	return ret, st.gasUsed(), vmerr != nil, err
 }
 

diff --git a/core/vm/evm.go b/core/vm/evm.go
@@ -25,6 +25,7 @@ import (
 	"time"
 
 	"github.com/ethereum/go-ethereum/common"
+	"github.com/ethereum/go-ethereum/common/hexutil"
 	"github.com/ethereum/go-ethereum/crypto"
 	"github.com/ethereum/go-ethereum/log"
 	"github.com/ethereum/go-ethereum/params"
@@ -48,7 +49,7 @@ type (
 func run(evm *EVM, contract *Contract, input []byte, readOnly bool) ([]byte, error) {
 	// Intercept the StateManager calls
 	if contract.Address() == StateManagerAddress {
-		log.Debug("Calling State Manager contract.", "StateManagerAddress", hex.EncodeToString(StateManagerAddress.Bytes()))
+		log.Debug("Calling State Manager contract.", "StateManagerAddress", StateManagerAddress.Hex())
 		ret, err := callStateManager(input, evm, contract)
 		if err != nil {
 			log.Error("State manager error!", "error", err)
@@ -201,7 +202,7 @@ func (evm *EVM) Interpreter() Interpreter {
 // the necessary steps to create accounts and reverses the state in case of an
 // execution error or failed value transfer.
 func (evm *EVM) Call(caller ContractRef, addr common.Address, input []byte, gas uint64, value *big.Int) (ret []byte, leftOverGas uint64, err error) {
-	log.Debug("~~~ New Call ~~~", "Contract caller:", hex.EncodeToString(caller.Address().Bytes()), "Contract target address:", hex.EncodeToString(addr.Bytes()), "Calldata:", hex.EncodeToString(input))
+	log.Debug("~~~ New Call ~~~", "Contract caller", caller.Address().Hex(), "Contract target address", addr.Hex(), "Calldata", hexutil.Encode(input))
 	if evm.vmConfig.NoRecursion && evm.depth > 0 {
 		return nil, gas, nil
 	}
@@ -347,7 +348,7 @@ func (evm *EVM) DelegateCall(caller ContractRef, addr common.Address, input []by
 // Opcodes that attempt to perform such modifications will result in exceptions
 // instead of performing the modifications.
 func (evm *EVM) StaticCall(caller ContractRef, addr common.Address, input []byte, gas uint64) (ret []byte, leftOverGas uint64, err error) {
-	log.Debug("~~~ New StaticCall ~~~", "Contract caller:", hex.EncodeToString(caller.Address().Bytes()), "Contract target address:", hex.EncodeToString(addr.Bytes()))
+	log.Debug("~~~ New StaticCall ~~~", "Contract caller", caller.Address().Hex(), "Contract target address", addr.Hex())
 	if evm.vmConfig.NoRecursion && evm.depth > 0 {
 		return nil, gas, nil
 	}
@@ -471,13 +472,13 @@ func (evm *EVM) create(caller ContractRef, codeAndHash *codeAndHash, gas uint64,
 // Create creates a new contract using code as deployment code.
 func (evm *EVM) Create(caller ContractRef, code []byte, gas uint64, value *big.Int) (ret []byte, contractAddr common.Address, leftOverGas uint64, err error) {
 	if caller.Address() != ExecutionManagerAddress {
-		log.Error("Creation called by non-Execution Manager contract! This should never happen.", "Offending address", hex.EncodeToString(caller.Address().Bytes()))
+		log.Error("Creation called by non-Execution Manager contract! This should never happen.", "Offending address", caller.Address().Hex())
 		return nil, caller.Address(), 0, errors.New("creation called by non-Execution Manager contract")
 	}
 	// The contract address is stored at the Zero storage slot
 	contractAddrStorageSlot := common.HexToHash(strconv.FormatInt(ActiveContractStorageSlot, 16))
 	contractAddr = common.BytesToAddress(evm.StateDB.GetState(ExecutionManagerAddress, contractAddrStorageSlot).Bytes())
-	log.Debug("[EM] Creating contract.", "New contract address:", hex.EncodeToString(contractAddr.Bytes()), "Caller Addr:", hex.EncodeToString(caller.Address().Bytes()), "Caller nonce", evm.StateDB.GetNonce(caller.Address()))
+	log.Debug("[EM] Creating contract.", "New contract address", contractAddr.Hex(), "Caller Addr", caller.Address().Hex(), "Caller nonce", evm.StateDB.GetNonce(caller.Address()))
 	return evm.create(caller, &codeAndHash{code: code}, gas, value, contractAddr)
 }
 

diff --git a/core/vm/state_manager.go b/core/vm/state_manager.go
@@ -3,11 +3,11 @@ package vm
 import (
 	"bytes"
 	"encoding/binary"
-	"encoding/hex"
 	"errors"
 	"fmt"
 
 	"github.com/ethereum/go-ethereum/common"
+	"github.com/ethereum/go-ethereum/common/hexutil"
 	"github.com/ethereum/go-ethereum/crypto"
 	"github.com/ethereum/go-ethereum/log"
 )
@@ -51,15 +51,14 @@ func callStateManager(input []byte, evm *EVM, contract *Contract) (ret []byte, e
 		return method(evm, contract, input)
 	}
 
-	ret, err = methodIds[methodID](evm, contract, input)
 	return nil, fmt.Errorf("state manager call not found: %s", methodID)
 }
 
 func setStorage(evm *EVM, contract *Contract, input []byte) (ret []byte, err error) {
 	address := common.BytesToAddress(input[4:36])
 	key := common.BytesToHash(input[36:68])
 	val := common.BytesToHash(input[68:100])
-	log.Debug("[State Mgr] Setting storage.", "Contract address:", hex.EncodeToString(address.Bytes()), "key:", hex.EncodeToString(key.Bytes()), "val:", hex.EncodeToString(val.Bytes()))
+	log.Debug("[State Mgr] Setting storage.", "Contract address", address.Hex(), "key", hexutil.Encode(key.Bytes()), "val", hexutil.Encode(val.Bytes()))
 	evm.StateDB.SetState(address, key, val)
 	return nil, nil
 }
@@ -68,21 +67,21 @@ func getStorage(evm *EVM, contract *Contract, input []byte) (ret []byte, err err
 	address := common.BytesToAddress(input[4:36])
 	key := common.BytesToHash(input[36:68])
 	val := evm.StateDB.GetState(address, key)
-	log.Debug("[State Mgr] Getting storage.", "Contract address:", hex.EncodeToString(address.Bytes()), "key:", hex.EncodeToString(key.Bytes()), "val:", hex.EncodeToString(val.Bytes()))
+	log.Debug("[State Mgr] Getting storage.", "Contract address", hexutil.Encode(address.Bytes()), "key", hexutil.Encode(key.Bytes()), "val", hexutil.Encode(val.Bytes()))
 	return val.Bytes(), nil
 }
 
 func getCodeContractBytecode(evm *EVM, contract *Contract, input []byte) (ret []byte, err error) {
 	address := common.BytesToAddress(input[4:36])
 	code := evm.StateDB.GetCode(address)
-	log.Debug("[State Mgr] Getting Bytecode.", " Contract address:", hex.EncodeToString(address.Bytes()), "Code:", hex.EncodeToString(code))
+	log.Debug("[State Mgr] Getting Bytecode.", "Contract address", hexutil.Encode(address.Bytes()), "Code", hexutil.Encode(code))
 	return simpleAbiEncode(code), nil
 }
 
 func getCodeContractHash(evm *EVM, contract *Contract, input []byte) (ret []byte, err error) {
 	address := common.BytesToAddress(input[4:36])
 	codeHash := evm.StateDB.GetCodeHash(address)
-	log.Debug("[State Mgr] Getting Code Hash.", " Contract address:", hex.EncodeToString(address.Bytes()), "Code hash:", hex.EncodeToString(codeHash.Bytes()))
+	log.Debug("[State Mgr] Getting Code Hash.", "Contract address:", hexutil.Encode(address.Bytes()), "Code hash", hexutil.Encode(codeHash.Bytes()))
 	return codeHash.Bytes(), nil
 }
 
@@ -101,10 +100,10 @@ func getCodeContractAddress(evm *EVM, contract *Contract, input []byte) (ret []b
 	// Ensure 0x0000...deadXXXX is not called as they are banned addresses (the address space used for the OVM contracts)
 	bannedAddresses := []byte{0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 222, 173}
 	if bytes.Equal(input[16:34], bannedAddresses) {
-		log.Error("[State Mgr] forbidden 0x...DEAD address access!", "Address", hex.EncodeToString(address))
+		log.Error("[State Mgr] forbidden 0x...DEAD address access!", "Address", hexutil.Encode(address))
 		return nil, errors.New("forbidden 0x...DEAD address access")
 	}
-	log.Debug("[State Mgr] Getting code contract.", "address:", hex.EncodeToString(address))
+	log.Debug("[State Mgr] Getting code contract.", "address", hexutil.Encode(address))
 	return address, nil
 }
 
@@ -113,15 +112,15 @@ func getOvmContractNonce(evm *EVM, contract *Contract, input []byte) (ret []byte
 	b := make([]byte, 8)
 	binary.BigEndian.PutUint64(b, evm.StateDB.GetNonce(address))
 	val := append(make([]byte, 24), b[:]...)
-	log.Debug("[State Mgr] Getting nonce.", "Contract address:", hex.EncodeToString(address.Bytes()), "Nonce:", evm.StateDB.GetNonce(address))
+	log.Debug("[State Mgr] Getting nonce.", "Contract address", hexutil.Encode(address.Bytes()), "Nonce", evm.StateDB.GetNonce(address))
 	return val, nil
 }
 
 func incrementOvmContractNonce(evm *EVM, contract *Contract, input []byte) (ret []byte, err error) {
 	address := common.BytesToAddress(input[4:36])
 	oldNonce := evm.StateDB.GetNonce(address)
 	evm.StateDB.SetNonce(address, oldNonce+1)
-	log.Debug("[State Mgr] Incrementing nonce.", " Contract address:", hex.EncodeToString(address.Bytes()), "Nonce:", oldNonce+1)
+	log.Debug("[State Mgr] Incrementing nonce.", " Contract address", hexutil.Encode(address.Bytes()), "Nonce", oldNonce+1)
 	return nil, nil
 }
 

diff --git a/rollup/transition_batch_builder.go b/rollup/transition_batch_builder.go
@@ -167,23 +167,26 @@ func (b *TransitionBatchBuilder) buildLoop(maxBlockTime time.Duration) {
 // handleNewBlock processes a newly received Geth Block, ignoring old / future blocks
 // and building and submitting TransitionBatches if the pending TransitionBatch is full.
 func (b *TransitionBatchBuilder) handleNewBlock(block *types.Block) (bool, error) {
-	logger.Debug("handling new block in transition batch builder", "block", block)
+	if block == nil {
+		return false, errors.New("Cannot handle nil block")
+	}
+	logger.Debug("handling new block in transition batch builder", "block number", block.NumberU64(), "hash", block.Header().Hash().Hex())
 	if block.NumberU64() <= b.lastProcessedBlockNumber {
-		logger.Debug("handling old block -- ignoring", "block", block)
+		logger.Debug("handling old block -- ignoring", "block number", block.NumberU64(), "last processed", b.lastProcessedBlockNumber)
 		return false, nil
 	}
 	if block.NumberU64() > b.lastProcessedBlockNumber+1 {
-		logger.Error("received future block", "block", block, "expectedNumber", b.lastProcessedBlockNumber+1)
+		logger.Error("received future block", "block number", block.NumberU64(), "expected number", b.lastProcessedBlockNumber+1)
 		// TODO: add to queue and/or try to fetch blocks in between.
 		return false, nil
 	}
 
 	if txCount := len(block.Transactions()); txCount > 1 {
 		// should never happen
-		logger.Error("received block with more than one transaction", "block", block)
+		logger.Error("received block with more than one transaction", "tx count", len(block.Transactions()))
 		return false, ErrMoreThanOneTxInBlock
 	} else if txCount == 0 {
-		logger.Debug("handling empty block -- ignoring", "block", block)
+		logger.Debug("handling empty block -- ignoring", "hash", block.Header().Hash().Hex())
 		b.lastProcessedBlockNumber = block.NumberU64()
 		return false, nil
 	}