Merge branch 'ethersphere-feature/logging' into develop

This commit is contained in:
obscuren 2014-06-26 19:52:31 +02:00
commit 491925b71e
19 changed files with 521 additions and 295 deletions

View File

@ -2,13 +2,15 @@ package ethchain
import (
"bytes"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethutil"
"github.com/ethereum/eth-go/ethwire"
"log"
"math"
"math/big"
)
var chainlogger = ethlog.NewLogger("CHAIN")
type BlockChain struct {
Ethereum EthManager
// The famous, the fabulous Mister GENESIIIIIIS (block)
@ -129,38 +131,38 @@ func (bc *BlockChain) FindCanonicalChain(blocks []*Block, commonBlockHash []byte
// Start with the newest block we got, all the way back to the common block we both know
for _, block := range blocks {
if bytes.Compare(block.Hash(), commonBlockHash) == 0 {
log.Println("[CHAIN] We have found the common parent block, breaking")
chainlogger.Infoln("[CHAIN] We have found the common parent block, breaking")
break
}
chainDifficulty.Add(chainDifficulty, bc.CalculateBlockTD(block))
}
log.Println("[CHAIN] Incoming chain difficulty:", chainDifficulty)
chainlogger.Infoln("Incoming chain difficulty:", chainDifficulty)
curChainDifficulty := new(big.Int)
block := bc.CurrentBlock
for i := 0; block != nil; block = bc.GetBlock(block.PrevHash) {
i++
if bytes.Compare(block.Hash(), commonBlockHash) == 0 {
log.Println("[CHAIN] We have found the common parent block, breaking")
chainlogger.Infoln("We have found the common parent block, breaking")
break
}
anOtherBlock := bc.GetBlock(block.PrevHash)
if anOtherBlock == nil {
// We do not want to count the genesis block for difficulty since that's not being sent
log.Println("[CHAIN] At genesis block, breaking")
chainlogger.Infoln("At genesis block, breaking")
break
}
curChainDifficulty.Add(curChainDifficulty, bc.CalculateBlockTD(block))
}
log.Println("[CHAIN] Current chain difficulty:", curChainDifficulty)
chainlogger.Infoln("Current chain difficulty:", curChainDifficulty)
if chainDifficulty.Cmp(curChainDifficulty) == 1 {
log.Printf("[CHAIN] The incoming Chain beat our asses, resetting to block: %x", commonBlockHash)
chainlogger.Infof("The incoming Chain beat our asses, resetting to block: %x", commonBlockHash)
bc.ResetTillBlockHash(commonBlockHash)
return false
} else {
log.Println("[CHAIN] Our chain showed the incoming chain who is boss. Ignoring.")
chainlogger.Infoln("Our chain showed the incoming chain who is boss. Ignoring.")
return true
}
}
@ -189,7 +191,7 @@ func (bc *BlockChain) ResetTillBlockHash(hash []byte) error {
var block *Block
for ; block != nil; block = bc.GetBlock(block.PrevHash) {
if bytes.Compare(block.Hash(), hash) == 0 {
log.Println("[CHAIN] We have arrived at the the common parent block, breaking")
chainlogger.Infoln("We have arrived at the the common parent block, breaking")
break
}
err = ethutil.Config.Db.Delete(block.Hash())
@ -197,7 +199,7 @@ func (bc *BlockChain) ResetTillBlockHash(hash []byte) error {
return err
}
}
log.Println("[CHAIN] Split chain deleted and reverted to common parent block.")
chainlogger.Infoln("Split chain deleted and reverted to common parent block.")
return nil
}
@ -226,7 +228,7 @@ func (bc *BlockChain) GetChainFromHash(hash []byte, max uint64) []interface{} {
// Get the block of the chain
block := bc.GetBlock(currentHash)
if block == nil {
ethutil.Config.Log.Debugf("Unexpected error during GetChainFromHash: Unable to find %x\n", currentHash)
chainlogger.Debugf("Unexpected error during GetChainFromHash: Unable to find %x\n", currentHash)
break
}
@ -285,7 +287,7 @@ func (bc *BlockChain) setLastBlock() {
bc.LastBlockHash = block.Hash()
bc.LastBlockNumber = block.Number.Uint64()
ethutil.Config.Log.Infof("[CHAIN] Last known block height #%d\n", bc.LastBlockNumber)
chainlogger.Infof("Last known block height #%d\n", bc.LastBlockNumber)
} else {
AddTestNetFunds(bc.genesisBlock)
@ -293,14 +295,14 @@ func (bc *BlockChain) setLastBlock() {
// Prepare the genesis block
bc.Add(bc.genesisBlock)
//log.Printf("root %x\n", bm.bc.genesisBlock.State().Root)
//chainlogger.Infof("root %x\n", bm.bc.genesisBlock.State().Root)
//bm.bc.genesisBlock.PrintHash()
}
// Set the last know difficulty (might be 0x0 as initial value, Genesis)
bc.TD = ethutil.BigD(ethutil.Config.Db.LastKnownTD())
ethutil.Config.Log.Infof("Last block: %x\n", bc.CurrentBlock.Hash())
chainlogger.Infof("Last block: %x\n", bc.CurrentBlock.Hash())
}
func (bc *BlockChain) SetTotalDifficulty(td *big.Int) {
@ -357,6 +359,6 @@ func (bc *BlockChain) writeBlockInfo(block *Block) {
func (bc *BlockChain) Stop() {
if bc.CurrentBlock != nil {
log.Println("[CHAIN] Stopped")
chainlogger.Infoln("Stopped")
}
}

View File

@ -1,15 +1,17 @@
package ethchain
import (
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethutil"
"github.com/obscuren/sha3"
"hash"
"log"
"math/big"
"math/rand"
"time"
)
var powlogger = ethlog.NewLogger("POW")
type PoW interface {
Search(block *Block, reactChan chan ethutil.React) []byte
Verify(hash []byte, diff *big.Int, nonce []byte) bool
@ -29,14 +31,13 @@ func (pow *EasyPow) Search(block *Block, reactChan chan ethutil.React) []byte {
for {
select {
case <-reactChan:
//ethutil.Config.Log.Infoln("[POW] Received reactor event; breaking out.")
return nil
default:
i++
if i%1234567 == 0 {
elapsed := time.Now().UnixNano() - start
hashes := ((float64(1e9) / float64(elapsed)) * float64(i)) / 1000
ethutil.Config.Log.Infoln("[POW] Hashing @", int64(hashes), "khash")
powlogger.Infoln("Hashing @", int64(hashes), "khash")
}
sha := ethutil.Sha3Bin(big.NewInt(r.Int63()).Bytes())
@ -81,7 +82,7 @@ func (dag *Dagger) Find(obj *big.Int, resChan chan int64) {
rnd := r.Int63()
res := dag.Eval(big.NewInt(rnd))
log.Printf("rnd %v\nres %v\nobj %v\n", rnd, res, obj)
powlogger.Infof("rnd %v\nres %v\nobj %v\n", rnd, res, obj)
if res.Cmp(obj) < 0 {
// Post back result on the channel
resChan <- rnd

View File

@ -125,7 +125,7 @@ func (self *State) GetOrNewStateObject(addr []byte) *StateObject {
}
func (self *State) NewStateObject(addr []byte) *StateObject {
ethutil.Config.Log.Printf(ethutil.LogLevelInfo, "(+) %x\n", addr)
statelogger.Infof("(+) %x\n", addr)
stateObject := NewStateObject(addr)
self.stateObjects[string(addr)] = stateObject

View File

@ -3,7 +3,7 @@ package ethchain
import (
"bytes"
"container/list"
"fmt"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethutil"
"github.com/ethereum/eth-go/ethwire"
"math/big"
@ -11,6 +11,8 @@ import (
"time"
)
var statelogger = ethlog.NewLogger("STATE")
type BlockProcessor interface {
ProcessBlock(block *Block)
}
@ -120,7 +122,7 @@ done:
break done
default:
ethutil.Config.Log.Infoln(err)
statelogger.Infoln(err)
}
}
@ -172,10 +174,10 @@ func (sm *StateManager) Process(block *Block, dontReact bool) (err error) {
if err != nil {
if len(receipts) == len(block.Receipts()) {
for i, receipt := range block.Receipts() {
ethutil.Config.Log.Debugf("diff (r) %v ~ %x <=> (c) %v ~ %x (%x)\n", receipt.CumulativeGasUsed, receipt.PostState[0:4], receipts[i].CumulativeGasUsed, receipts[i].PostState[0:4], receipt.Tx.Hash())
statelogger.Debugf("diff (r) %v ~ %x <=> (c) %v ~ %x (%x)\n", receipt.CumulativeGasUsed, receipt.PostState[0:4], receipts[i].CumulativeGasUsed, receipts[i].PostState[0:4], receipt.Tx.Hash())
}
} else {
ethutil.Config.Log.Debugln("Unable to print receipt diff. Length didn't match", len(receipts), "for", len(block.Receipts()))
statelogger.Warnln("Unable to print receipt diff. Length didn't match", len(receipts), "for", len(block.Receipts()))
}
}
}()
@ -186,19 +188,19 @@ func (sm *StateManager) Process(block *Block, dontReact bool) (err error) {
// Block validation
if err = sm.ValidateBlock(block); err != nil {
fmt.Println("[SM] Error validating block:", err)
statelogger.Errorln("Error validating block:", err)
return err
}
// I'm not sure, but I don't know if there should be thrown
// any errors at this time.
if err = sm.AccumelateRewards(state, block); err != nil {
fmt.Println("[SM] Error accumulating reward", err)
statelogger.Errorln("Error accumulating reward", err)
return err
}
if !block.State().Cmp(state) {
err = fmt.Errorf("Invalid merkle root.\nrec: %x\nis: %x", block.State().trie.Root, state.trie.Root)
statelogger.Errorf("Invalid merkle root.\nrec: %x\nis: %x", block.State().trie.Root, state.trie.Root)
return
}
@ -211,7 +213,7 @@ func (sm *StateManager) Process(block *Block, dontReact bool) (err error) {
sm.bc.Add(block)
sm.notifyChanges(state)
ethutil.Config.Log.Infof("[STATE] Added block #%d (%x)\n", block.Number, block.Hash())
statelogger.Infof("Added block #%d (%x)\n", block.Number, block.Hash())
if dontReact == false {
sm.Ethereum.Reactor().Post("newBlock", block)
@ -222,7 +224,7 @@ func (sm *StateManager) Process(block *Block, dontReact bool) (err error) {
sm.Ethereum.TxPool().RemoveInvalid(state)
} else {
fmt.Println("total diff failed")
statelogger.Errorln("total diff failed")
}
return nil

View File

@ -130,13 +130,13 @@ func (c *StateObject) ReturnGas(gas, price *big.Int, state *State) {
func (c *StateObject) AddAmount(amount *big.Int) {
c.SetAmount(new(big.Int).Add(c.Amount, amount))
ethutil.Config.Log.Printf(ethutil.LogLevelInfo, "%x: #%d %v (+ %v)\n", c.Address(), c.Nonce, c.Amount, amount)
statelogger.Infof("%x: #%d %v (+ %v)\n", c.Address(), c.Nonce, c.Amount, amount)
}
func (c *StateObject) SubAmount(amount *big.Int) {
c.SetAmount(new(big.Int).Sub(c.Amount, amount))
ethutil.Config.Log.Printf(ethutil.LogLevelInfo, "%x: #%d %v (- %v)\n", c.Address(), c.Nonce, c.Amount, amount)
statelogger.Infof("%x: #%d %v (- %v)\n", c.Address(), c.Nonce, c.Amount, amount)
}
func (c *StateObject) SetAmount(amount *big.Int) {
@ -157,7 +157,7 @@ func (c *StateObject) ConvertGas(gas, price *big.Int) error {
func (self *StateObject) SetGasPool(gasLimit *big.Int) {
self.gasPool = new(big.Int).Set(gasLimit)
ethutil.Config.Log.Printf(ethutil.LogLevelSystem, "%x: fuel (+ %v)", self.Address(), self.gasPool)
statelogger.DebugDetailf("%x: fuel (+ %v)", self.Address(), self.gasPool)
}
func (self *StateObject) BuyGas(gas, price *big.Int) error {

View File

@ -2,7 +2,6 @@ package ethchain
import (
"fmt"
"github.com/ethereum/eth-go/ethutil"
"math/big"
)
@ -135,12 +134,12 @@ func (self *StateTransition) preCheck() (err error) {
}
func (self *StateTransition) TransitionState() (err error) {
ethutil.Config.Log.Printf(ethutil.LogLevelInfo, "(~) %x\n", self.tx.Hash())
statelogger.Infof("(~) %x\n", self.tx.Hash())
/*
defer func() {
if r := recover(); r != nil {
ethutil.Config.Log.Infoln(r)
logger.Infoln(r)
err = fmt.Errorf("state transition err %v", r)
}
}()
@ -231,7 +230,7 @@ func (self *StateTransition) transferValue(sender, receiver *StateObject) error
// Add the amount to receivers account which should conclude this transaction
receiver.AddAmount(self.value)
//ethutil.Config.Log.Debugf("%x => %x (%v)\n", sender.Address()[:4], receiver.Address()[:4], self.value)
//statelogger.Debugf("%x => %x (%v)\n", sender.Address()[:4], receiver.Address()[:4], self.value)
//}
return nil

View File

@ -3,15 +3,15 @@ package ethchain
import (
"bytes"
"container/list"
"errors"
"fmt"
"github.com/ethereum/eth-go/ethutil"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethwire"
"log"
"math/big"
"sync"
)
var txplogger = ethlog.NewLogger("TXP")
const (
txPoolQueueSize = 50
)
@ -97,7 +97,7 @@ func (pool *TxPool) ProcessTransaction(tx *Transaction, state *State, toContract
fmt.Printf("state root before update %x\n", state.Root())
defer func() {
if r := recover(); r != nil {
ethutil.Config.Log.Infoln(r)
txplogger.Infoln(r)
err = fmt.Errorf("%v", r)
}
}()
@ -156,7 +156,7 @@ func (pool *TxPool) ProcessTransaction(tx *Transaction, state *State, toContract
fmt.Printf("state root after receiver update %x\n", state.Root())
}
ethutil.Config.Log.Infof("[TXPL] Processed Tx %x\n", tx.Hash())
txplogger.Infof("[TXPL] Processed Tx %x\n", tx.Hash())
return
}
@ -168,7 +168,7 @@ func (pool *TxPool) ValidateTransaction(tx *Transaction) error {
block := pool.Ethereum.BlockChain().CurrentBlock
// Something has gone horribly wrong if this happens
if block == nil {
return errors.New("[TXPL] No last block on the block chain")
return fmt.Errorf("[TXPL] No last block on the block chain")
}
if len(tx.Recipient) != 20 {
@ -188,7 +188,7 @@ func (pool *TxPool) ValidateTransaction(tx *Transaction) error {
if tx.IsContract() {
if tx.GasPrice.Cmp(big.NewInt(minGasPrice)) < 0 {
return fmt.Errorf("[TXPL] Gasprice to low, %s given should be at least %d.", tx.GasPrice, minGasPrice)
return fmt.Errorf("[TXPL] Gasprice too low, %s given should be at least %d.", tx.GasPrice, minGasPrice)
}
}
@ -215,12 +215,12 @@ out:
// Validate the transaction
err := pool.ValidateTransaction(tx)
if err != nil {
ethutil.Config.Log.Debugln("Validating Tx failed", err)
txplogger.Debugln("Validating Tx failed", err)
} else {
// Call blocking version.
pool.addTransaction(tx)
ethutil.Config.Log.Debugf("(t) %x => %x (%v) %x\n", tx.Sender()[:4], tx.Recipient[:4], tx.Value, tx.Hash())
txplogger.Debugf("(t) %x => %x (%v) %x\n", tx.Sender()[:4], tx.Recipient[:4], tx.Value, tx.Hash())
// Notify the subscribers
pool.Ethereum.Reactor().Post("newTx:pre", tx)
@ -282,5 +282,5 @@ func (pool *TxPool) Stop() {
pool.Flush()
log.Println("[TXP] Stopped")
txplogger.Infoln("Stopped")
}

View File

@ -2,11 +2,14 @@ package ethchain
import (
"fmt"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethutil"
"math"
"math/big"
)
var vmlogger = ethlog.NewLogger("VM")
var (
GasStep = big.NewInt(1)
GasSha = big.NewInt(20)
@ -72,7 +75,7 @@ func (self *Vm) Printf(format string, v ...interface{}) *Vm {
func (self *Vm) Endl() *Vm {
if self.Verbose {
ethutil.Config.Log.Infoln(self.logStr)
vmlogger.Infoln(self.logStr)
self.logStr = ""
}
@ -93,11 +96,11 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro
if r := recover(); r != nil {
ret = closure.Return(nil)
err = fmt.Errorf("%v", r)
fmt.Println(err)
vmlogger.Errorln("vm err", err)
}
}()
ethutil.Config.Log.Debugf("[VM] (~) %x gas: %v (d) %x\n", closure.object.Address(), closure.Gas, closure.Args)
vmlogger.Debugf("(~) %x gas: %v (d) %x\n", closure.object.Address(), closure.Gas, closure.Args)
var (
op OpCode
@ -642,7 +645,7 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro
args := mem.Get(inOffset.Int64(), inSize.Int64())
if closure.object.Amount.Cmp(value) < 0 {
ethutil.Config.Log.Debugf("Insufficient funds to transfer value. Req %v, has %v", value, closure.object.Amount)
vmlogger.Debugf("Insufficient funds to transfer value. Req %v, has %v", value, closure.object.Amount)
stack.Push(ethutil.BigFalse)
} else {
@ -661,7 +664,7 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro
if err != nil {
stack.Push(ethutil.BigFalse)
ethutil.Config.Log.Debugf("Closure execution failed. %v\n", err)
vmlogger.Debugf("Closure execution failed. %v\n", err)
vm.err = err
vm.state.Set(snapshot)
@ -696,7 +699,7 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro
return closure.Return(nil), nil
default:
ethutil.Config.Log.Debugf("Invalid opcode %x\n", op)
vmlogger.Debugf("Invalid opcode %x\n", op)
return closure.Return(nil), fmt.Errorf("Invalid opcode %x", op)
}

View File

@ -5,11 +5,11 @@ import (
"fmt"
"github.com/ethereum/eth-go/ethchain"
"github.com/ethereum/eth-go/ethdb"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethrpc"
"github.com/ethereum/eth-go/ethutil"
"github.com/ethereum/eth-go/ethwire"
"io/ioutil"
"log"
"math/rand"
"net"
"net/http"
@ -20,6 +20,8 @@ import (
"time"
)
var ethlogger = ethlog.NewLogger("SERV")
func eachPeer(peers *list.List, callback func(*Peer, *list.Element)) {
// Loop thru the peers and close them (if we had them)
for e := peers.Front(); e != nil; e = e.Next() {
@ -85,7 +87,7 @@ func New(caps Caps, usePnp bool) (*Ethereum, error) {
if usePnp {
nat, err = Discover()
if err != nil {
ethutil.Config.Log.Debugln("UPnP failed", err)
ethlogger.Debugln("UPnP failed", err)
}
}
@ -163,7 +165,7 @@ func (s *Ethereum) AddPeer(conn net.Conn) {
if s.peers.Len() < s.MaxPeers {
peer.Start()
} else {
ethutil.Config.Log.Debugf("[SERV] Max connected peers reached. Not adding incoming peer.")
ethlogger.Debugf("Max connected peers reached. Not adding incoming peer.")
}
}
}
@ -223,7 +225,7 @@ func (s *Ethereum) ConnectToPeer(addr string) error {
if phost == chost {
alreadyConnected = true
//ethutil.Config.Log.Debugf("[SERV] Peer %s already added.\n", chost)
//ethlogger.Debugf("Peer %s already added.\n", chost)
return
}
})
@ -340,12 +342,12 @@ func (s *Ethereum) Start(seed bool) {
// Bind to addr and port
ln, err := net.Listen("tcp", ":"+s.Port)
if err != nil {
ethutil.Config.Log.Infof("port=%s in use. Connection listening disabled.")
ethlogger.Warnf("Port %s in use. Connection listening disabled. Acting as client", s.Port)
s.listening = false
} else {
s.listening = true
// Starting accepting connections
ethutil.Config.Log.Infoln("Ready and accepting connections")
ethlogger.Infoln("Ready and accepting connections")
// Start the peer handler
go s.peerHandler(ln)
}
@ -360,10 +362,11 @@ func (s *Ethereum) Start(seed bool) {
if seed {
s.Seed()
}
ethlogger.Infoln("Server started")
}
func (s *Ethereum) Seed() {
ethutil.Config.Log.Debugln("[SERV] Retrieving seed nodes")
ethlogger.Debugln("Retrieving seed nodes")
// Eth-Go Bootstrapping
ips, er := net.LookupIP("seed.bysh.me")
@ -371,7 +374,7 @@ func (s *Ethereum) Seed() {
peers := []string{}
for _, ip := range ips {
node := fmt.Sprintf("%s:%d", ip.String(), 30303)
ethutil.Config.Log.Debugln("[SERV] Found DNS Go Peer:", node)
ethlogger.Debugln("Found DNS Go Peer:", node)
peers = append(peers, node)
}
s.ProcessPeerList(peers)
@ -391,11 +394,11 @@ func (s *Ethereum) Seed() {
for _, a := range addr {
// Build string out of SRV port and Resolved IP
peer := net.JoinHostPort(a, port)
ethutil.Config.Log.Debugln("[SERV] Found DNS Bootstrap Peer:", peer)
ethlogger.Debugln("Found DNS Bootstrap Peer:", peer)
peers = append(peers, peer)
}
} else {
ethutil.Config.Log.Debugln("[SERV] Couldn't resolve :", target)
ethlogger.Debugln("Couldn't resolve :", target)
}
}
// Connect to Peer list
@ -404,13 +407,13 @@ func (s *Ethereum) Seed() {
// Fallback to servers.poc3.txt
resp, err := http.Get("http://www.ethereum.org/servers.poc3.txt")
if err != nil {
log.Println("Fetching seed failed:", err)
ethlogger.Warnln("Fetching seed failed:", err)
return
}
defer resp.Body.Close()
body, err := ioutil.ReadAll(resp.Body)
if err != nil {
log.Println("Reading seed failed:", err)
ethlogger.Warnln("Reading seed failed:", err)
return
}
@ -422,7 +425,7 @@ func (s *Ethereum) peerHandler(listener net.Listener) {
for {
conn, err := listener.Accept()
if err != nil {
ethutil.Config.Log.Debugln(err)
ethlogger.Debugln(err)
continue
}
@ -447,6 +450,7 @@ func (s *Ethereum) Stop() {
s.txPool.Stop()
s.stateManager.Stop()
ethlogger.Infoln("Server stopped")
close(s.shutdownChan)
}
@ -468,13 +472,13 @@ out:
var err error
_, err = s.nat.AddPortMapping("TCP", int(lport), int(lport), "eth listen port", 20*60)
if err != nil {
ethutil.Config.Log.Debugln("can't add UPnP port mapping:", err)
ethlogger.Debugln("can't add UPnP port mapping:", err)
break out
}
if first && err == nil {
_, err = s.nat.GetExternalAddress()
if err != nil {
ethutil.Config.Log.Debugln("UPnP can't get external address:", err)
ethlogger.Debugln("UPnP can't get external address:", err)
continue out
}
first = false
@ -488,8 +492,8 @@ out:
timer.Stop()
if err := s.nat.DeletePortMapping("TCP", int(lport), int(lport)); err != nil {
ethutil.Config.Log.Debugln("unable to remove UPnP port mapping:", err)
ethlogger.Debugln("unable to remove UPnP port mapping:", err)
} else {
ethutil.Config.Log.Debugln("succesfully disestablished UPnP port mapping")
ethlogger.Debugln("succesfully disestablished UPnP port mapping")
}
}

62
ethlog/README.md Normal file
View File

@ -0,0 +1,62 @@
## Features
- packages use tagged logger sending log messages to shared (process-wide) logging engine
- log writers (interface ethlog.LogSystem) can be added to the logging engine by wrappers/guis/clients
- shared logging engine dispatching to multiple log systems
- log level can be set separately per log system
- async logging thread: logging IO does not block main thread
- log messages are synchronously stringified to avoid incorrectly logging of changed states
- log level enum: ethlog.LogLevel: Silence, ErrorLevel, WarnLevel, InfoLevel, DebugLevel, DebugDetailLevel
## Usage
In an ethereum component package:
import "github.com/ethereum/eth-go/ethlog"
// package-wide logger using tag
var logger = ethlog.NewLogger("TAG")
Logger provides named Printf and Println style methods for all loglevels
logger.Infoln("this is info") # > [TAG] This is info
logger.Infof("this %v is info", object) # > [TAG] This object is info
Ethereum wrappers should register log systems conforming to ethlog.LogSystem
import "github.com/ethereum/eth-go/ethlog"
type CustomLogWriter struct {
logLevel ethlog.LogLevel
}
func (t *TestLogSystem) SetLogLevel(i LogLevel) {
t.level = i
}
func (t *TestLogSystem) GetLogLevel() LogLevel {
return t.level
}
func (c *CustomLogWriter) Printf(format string, v...interface{}) {
//....
}
func (c *CustomLogWriter) Println(v...interface{}) {
//....
}
ethlog.AddLogWriter(&CustomLogWriter{})
ethlog also provides constructors for that wrap io.Writers into a standard logger with a settable level:
filename := "test.log"
file, _ := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, os.ModePerm)
fileLogSystem := NewStdLogSystem(file, 0, WarnLevel)
AddLogSystem(fileLogSystem)
stdOutLogSystem := NewStdLogSystem(os.Stdout, 0, WarnLevel)
AddLogSystem(stdOutLogSystem)

188
ethlog/loggers.go Normal file
View File

@ -0,0 +1,188 @@
package ethlog
import (
"fmt"
"io"
"log"
"os"
"sync"
)
type LogSystem interface {
GetLogLevel() LogLevel
SetLogLevel(i LogLevel)
Println(v ...interface{})
Printf(format string, v ...interface{})
}
type logMessage struct {
LogLevel LogLevel
format bool
msg string
}
func newPrintlnLogMessage(level LogLevel, tag string, v ...interface{}) *logMessage {
return &logMessage{level, false, fmt.Sprintf("[%s] %s", tag, fmt.Sprint(v...))}
}
func newPrintfLogMessage(level LogLevel, tag string, format string, v ...interface{}) *logMessage {
return &logMessage{level, true, fmt.Sprintf("[%s] %s", tag, fmt.Sprintf(format, v...))}
}
func (msg *logMessage) send(logger LogSystem) {
if msg.format {
logger.Printf(msg.msg)
} else {
logger.Println(msg.msg)
}
}
var logMessages chan (*logMessage)
var logSystems []LogSystem
var drained = true
type LogLevel uint8
const (
Silence LogLevel = iota
ErrorLevel
WarnLevel
InfoLevel
DebugLevel
DebugDetailLevel
)
// log messages are dispatched to log writers
func start() {
for {
select {
case msg := <-logMessages:
for _, logSystem := range logSystems {
if logSystem.GetLogLevel() >= msg.LogLevel {
msg.send(logSystem)
}
}
default:
drained = true
}
}
}
// waits until log messages are drained (dispatched to log writers)
func Flush() {
for !drained {
}
}
type Logger struct {
tag string
}
func NewLogger(tag string) *Logger {
return &Logger{tag}
}
func AddLogSystem(logSystem LogSystem) {
var mutex = &sync.Mutex{}
mutex.Lock()
defer mutex.Unlock()
if logSystems == nil {
logMessages = make(chan *logMessage)
go start()
}
logSystems = append(logSystems, logSystem)
}
func (logger *Logger) sendln(level LogLevel, v ...interface{}) {
if logMessages != nil {
msg := newPrintlnLogMessage(level, logger.tag, v...)
drained = false
logMessages <- msg
}
}
func (logger *Logger) sendf(level LogLevel, format string, v ...interface{}) {
if logMessages != nil {
msg := newPrintfLogMessage(level, logger.tag, format, v...)
drained = false
logMessages <- msg
}
}
func (logger *Logger) Errorln(v ...interface{}) {
logger.sendln(ErrorLevel, v...)
}
func (logger *Logger) Warnln(v ...interface{}) {
logger.sendln(WarnLevel, v...)
}
func (logger *Logger) Infoln(v ...interface{}) {
logger.sendln(InfoLevel, v...)
}
func (logger *Logger) Debugln(v ...interface{}) {
logger.sendln(DebugLevel, v...)
}
func (logger *Logger) DebugDetailln(v ...interface{}) {
logger.sendln(DebugDetailLevel, v...)
}
func (logger *Logger) Errorf(format string, v ...interface{}) {
logger.sendf(ErrorLevel, format, v...)
}
func (logger *Logger) Warnf(format string, v ...interface{}) {
logger.sendf(WarnLevel, format, v...)
}
func (logger *Logger) Infof(format string, v ...interface{}) {
logger.sendf(InfoLevel, format, v...)
}
func (logger *Logger) Debugf(format string, v ...interface{}) {
logger.sendf(DebugLevel, format, v...)
}
func (logger *Logger) DebugDetailf(format string, v ...interface{}) {
logger.sendf(DebugDetailLevel, format, v...)
}
func (logger *Logger) Fatalln(v ...interface{}) {
logger.sendln(ErrorLevel, v...)
Flush()
os.Exit(0)
}
func (logger *Logger) Fatalf(format string, v ...interface{}) {
logger.sendf(ErrorLevel, format, v...)
Flush()
os.Exit(0)
}
type StdLogSystem struct {
logger *log.Logger
level LogLevel
}
func (t *StdLogSystem) Println(v ...interface{}) {
t.logger.Println(v...)
}
func (t *StdLogSystem) Printf(format string, v ...interface{}) {
t.logger.Printf(format, v...)
}
func (t *StdLogSystem) SetLogLevel(i LogLevel) {
t.level = i
}
func (t *StdLogSystem) GetLogLevel() LogLevel {
return t.level
}
func NewStdLogSystem(writer io.Writer, flags int, level LogLevel) *StdLogSystem {
logger := log.New(writer, "", flags)
return &StdLogSystem{logger, level}
}

109
ethlog/loggers_test.go Normal file
View File

@ -0,0 +1,109 @@
package ethlog
import (
"fmt"
"io/ioutil"
"os"
"testing"
)
type TestLogSystem struct {
Output string
level LogLevel
}
func (t *TestLogSystem) Println(v ...interface{}) {
t.Output += fmt.Sprintln(v...)
}
func (t *TestLogSystem) Printf(format string, v ...interface{}) {
t.Output += fmt.Sprintf(format, v...)
}
func (t *TestLogSystem) SetLogLevel(i LogLevel) {
t.level = i
}
func (t *TestLogSystem) GetLogLevel() LogLevel {
return t.level
}
func quote(s string) string {
return fmt.Sprintf("'%s'", s)
}
func TestLoggerPrintln(t *testing.T) {
logger := NewLogger("TEST")
testLogSystem := &TestLogSystem{level: WarnLevel}
AddLogSystem(testLogSystem)
logger.Errorln("error")
logger.Warnln("warn")
logger.Infoln("info")
logger.Debugln("debug")
Flush()
output := testLogSystem.Output
fmt.Println(quote(output))
if output != "[TEST] error\n[TEST] warn\n" {
t.Error("Expected logger output '[TEST] error\\n[TEST] warn\\n', got ", quote(testLogSystem.Output))
}
}
func TestLoggerPrintf(t *testing.T) {
logger := NewLogger("TEST")
testLogSystem := &TestLogSystem{level: WarnLevel}
AddLogSystem(testLogSystem)
logger.Errorf("error to %v\n", *testLogSystem)
logger.Warnf("warn")
logger.Infof("info")
logger.Debugf("debug")
Flush()
output := testLogSystem.Output
fmt.Println(quote(output))
if output != "[TEST] error to { 2}\n[TEST] warn" {
t.Error("Expected logger output '[TEST] error to { 2}\\n[TEST] warn', got ", quote(testLogSystem.Output))
}
}
func TestMultipleLogSystems(t *testing.T) {
logger := NewLogger("TEST")
testLogSystem0 := &TestLogSystem{level: ErrorLevel}
testLogSystem1 := &TestLogSystem{level: WarnLevel}
AddLogSystem(testLogSystem0)
AddLogSystem(testLogSystem1)
logger.Errorln("error")
logger.Warnln("warn")
Flush()
output0 := testLogSystem0.Output
output1 := testLogSystem1.Output
if output0 != "[TEST] error\n" {
t.Error("Expected logger 0 output '[TEST] error\\n', got ", quote(testLogSystem0.Output))
}
if output1 != "[TEST] error\n[TEST] warn\n" {
t.Error("Expected logger 1 output '[TEST] error\\n[TEST] warn\\n', got ", quote(testLogSystem1.Output))
}
}
func TestFileLogSystem(t *testing.T) {
logger := NewLogger("TEST")
filename := "test.log"
file, _ := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, os.ModePerm)
testLogSystem := NewStdLogSystem(file, 0, WarnLevel)
AddLogSystem(testLogSystem)
logger.Errorf("error to %s\n", filename)
logger.Warnln("warn")
Flush()
contents, _ := ioutil.ReadFile(filename)
output := string(contents)
fmt.Println(quote(output))
if output != "[TEST] error to test.log\n[TEST] warn\n" {
t.Error("Expected contents of file 'test.log': '[TEST] error to test.log\\n[TEST] warn\\n', got ", quote(output))
} else {
os.Remove(filename)
}
}
func TestNoLogSystem(t *testing.T) {
logger := NewLogger("TEST")
logger.Warnln("warn")
Flush()
}

View File

@ -3,11 +3,14 @@ package ethminer
import (
"bytes"
"github.com/ethereum/eth-go/ethchain"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethutil"
"github.com/ethereum/eth-go/ethwire"
"sort"
)
var logger = ethlog.NewLogger("MINER")
type Miner struct {
pow ethchain.PoW
ethereum ethchain.EthManager
@ -54,23 +57,28 @@ func NewDefaultMiner(coinbase []byte, ethereum ethchain.EthManager) Miner {
return miner
}
func (miner *Miner) Start() {
// Prepare inital block
//miner.ethereum.StateManager().Prepare(miner.block.State(), miner.block.State())
go miner.listener()
logger.Infoln("Started")
}
func (miner *Miner) listener() {
out:
for {
select {
case <-miner.quitChan:
logger.Infoln("Stopped")
break out
case chanMessage := <-miner.reactChan:
if block, ok := chanMessage.Resource.(*ethchain.Block); ok {
//ethutil.Config.Log.Infoln("[MINER] Got new block via Reactor")
//logger.Infoln("Got new block via Reactor")
if bytes.Compare(miner.ethereum.BlockChain().CurrentBlock.Hash(), block.Hash()) == 0 {
// TODO: Perhaps continue mining to get some uncle rewards
//ethutil.Config.Log.Infoln("[MINER] New top block found resetting state")
//logger.Infoln("New top block found resetting state")
// Filter out which Transactions we have that were not in this block
var newtxs []*ethchain.Transaction
@ -92,7 +100,7 @@ out:
} else {
if bytes.Compare(block.PrevHash, miner.ethereum.BlockChain().CurrentBlock.PrevHash) == 0 {
ethutil.Config.Log.Infoln("[MINER] Adding uncle block")
logger.Infoln("Adding uncle block")
miner.uncles = append(miner.uncles, block)
}
}
@ -120,8 +128,9 @@ out:
}
func (self *Miner) Stop() {
self.powQuitChan <- ethutil.React{}
logger.Infoln("Stopping...")
self.quitChan <- true
self.powQuitChan <- ethutil.React{}
}
func (self *Miner) mineNewBlock() {
@ -137,14 +146,14 @@ func (self *Miner) mineNewBlock() {
// Sort the transactions by nonce in case of odd network propagation
sort.Sort(ethchain.TxByNonce{self.txs})
// Accumulate all valid transaction and apply them to the new state
// Accumulate all valid transactions and apply them to the new state
// Error may be ignored. It's not important during mining
parent := self.ethereum.BlockChain().GetBlock(self.block.PrevHash)
coinbase := self.block.State().GetOrNewStateObject(self.block.Coinbase)
coinbase.SetGasPool(self.block.CalcGasLimit(parent))
receipts, txs, unhandledTxs, err := stateManager.ProcessTransactions(coinbase, self.block.State(), self.block, self.block, self.txs)
if err != nil {
ethutil.Config.Log.Debugln("[MINER]", err)
logger.Debugln(err)
}
self.txs = append(txs, unhandledTxs...)
@ -156,18 +165,18 @@ func (self *Miner) mineNewBlock() {
self.block.State().Update()
ethutil.Config.Log.Infoln("[MINER] Mining on block. Includes", len(self.txs), "transactions")
logger.Infof("Mining on block. Includes %v transactions", len(self.txs))
// Find a valid nonce
self.block.Nonce = self.pow.Search(self.block, self.powQuitChan)
if self.block.Nonce != nil {
err := self.ethereum.StateManager().Process(self.block, false)
if err != nil {
ethutil.Config.Log.Infoln(err)
logger.Infoln(err)
} else {
self.ethereum.Broadcast(ethwire.MsgBlockTy, []interface{}{self.block.Value().Val})
ethutil.Config.Log.Infof("[MINER] 🔨 Mined block %x\n", self.block.Hash())
ethutil.Config.Log.Infoln(self.block)
logger.Infof("🔨 Mined block %x\n", self.block.Hash())
logger.Infoln(self.block)
// Gather the new batch of transactions currently in the tx pool
self.txs = self.ethereum.TxPool().CurrentTransactions()
}

View File

@ -5,12 +5,15 @@ import (
"encoding/hex"
"encoding/json"
"github.com/ethereum/eth-go/ethchain"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethutil"
"math/big"
"strings"
"sync/atomic"
)
var logger = ethlog.NewLogger("PUB")
type PEthereum struct {
manager ethchain.EthManager
stateManager *ethchain.StateManager
@ -222,7 +225,7 @@ func (lib *PEthereum) createTx(key, recipient, valueStr, gasStr, gasPriceStr, sc
lib.txPool.QueueTransaction(tx)
if contractCreation {
ethutil.Config.Log.Infof("Contract addr %x", tx.CreationAddress())
logger.Infof("Contract addr %x", tx.CreationAddress())
}
return NewPReciept(contractCreation, tx.CreationAddress(), tx.Hash(), keyPair.Address()), nil

View File

@ -184,7 +184,7 @@ func (p *EthereumApi) GetStorageAt(args *GetStorageArgs, reply *string) error {
i, _ := new(big.Int).SetString(args.Key, 10)
hx = ethutil.Hex(i.Bytes())
}
ethutil.Config.Log.Debugf("[JSON] GetStorageAt(%s, %s)\n", args.Address, hx)
logger.Debugf("GetStorageAt(%s, %s)\n", args.Address, hx)
value := state.GetStorage(hx)
*reply = NewSuccessRes(GetStorageAtRes{Address: args.Address, Key: args.Key, Value: value})
return nil

View File

@ -2,13 +2,15 @@ package ethrpc
import (
"fmt"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethpub"
"github.com/ethereum/eth-go/ethutil"
"net"
"net/rpc"
"net/rpc/jsonrpc"
)
var logger = ethlog.NewLogger("JSON")
type JsonRpcServer struct {
quit chan bool
listener net.Listener
@ -25,7 +27,7 @@ out:
}
}
ethutil.Config.Log.Infoln("[JSON] Shutdown JSON-RPC server")
logger.Infoln("Shutdown JSON-RPC server")
}
func (s *JsonRpcServer) Stop() {
@ -33,7 +35,7 @@ func (s *JsonRpcServer) Stop() {
}
func (s *JsonRpcServer) Start() {
ethutil.Config.Log.Infoln("[JSON] Starting JSON-RPC server")
logger.Infoln("Starting JSON-RPC server")
go s.exitHandler()
rpc.Register(&EthereumApi{ethp: s.ethp})
rpc.HandleHTTP()
@ -41,10 +43,10 @@ func (s *JsonRpcServer) Start() {
for {
conn, err := s.listener.Accept()
if err != nil {
ethutil.Config.Log.Infoln("[JSON] Error starting JSON-RPC:", err)
logger.Infoln("Error starting JSON-RPC:", err)
break
}
ethutil.Config.Log.Debugln("[JSON] Incoming request.")
logger.Debugln("Incoming request.")
go jsonrpc.ServeConn(conn)
}
}

View File

@ -4,10 +4,7 @@ import (
"flag"
"fmt"
"github.com/rakyll/globalconf"
"log"
"os"
"os/user"
"path"
"runtime"
)
@ -15,7 +12,6 @@ import (
type config struct {
Db Database
Log *Logger
ExecPath string
Debug bool
Ver string
@ -26,62 +22,31 @@ type config struct {
conf *globalconf.GlobalConf
}
const defaultConf = `
id = ""
port = 30303
upnp = true
maxpeer = 10
rpc = false
rpcport = 8080
`
var Config *config
func ApplicationFolder(base string) string {
usr, _ := user.Current()
p := path.Join(usr.HomeDir, base)
if len(base) > 0 {
//Check if the logging directory already exists, create it if not
_, err := os.Stat(p)
if err != nil {
if os.IsNotExist(err) {
log.Printf("Debug logging directory %s doesn't exist, creating it\n", p)
os.Mkdir(p, 0777)
}
}
iniFilePath := path.Join(p, "conf.ini")
_, err = os.Stat(iniFilePath)
if err != nil && os.IsNotExist(err) {
file, err := os.Create(iniFilePath)
if err != nil {
fmt.Println(err)
} else {
assetPath := path.Join(os.Getenv("GOPATH"), "src", "github.com", "ethereum", "go-ethereum", "ethereal", "assets")
file.Write([]byte(defaultConf + "\nasset_path = " + assetPath))
}
}
}
return p
}
// Read config
//
// Initialize the global Config variable with default settings
func ReadConfig(base string, logTypes LoggerType, g *globalconf.GlobalConf, id string) *config {
// Initialize Config from Config File
func ReadConfig(ConfigFile string, Datadir string, Identifier string, EnvPrefix string) *config {
if Config == nil {
path := ApplicationFolder(base)
Config = &config{ExecPath: path, Debug: true, Ver: "0.5.14"}
Config.conf = g
Config.Identifier = id
Config.Log = NewLogger(logTypes, LogLevelDebug)
// create ConfigFile if does not exist, otherwise globalconf panic when trying to persist flags
_, err := os.Stat(ConfigFile)
if err != nil && os.IsNotExist(err) {
fmt.Printf("config file '%s' doesn't exist, creating it\n", ConfigFile)
os.Create(ConfigFile)
}
g, err := globalconf.NewWithOptions(&globalconf.Options{
Filename: ConfigFile,
EnvPrefix: EnvPrefix,
})
if err != nil {
fmt.Println(err)
} else {
g.ParseAll()
}
Config = &config{ExecPath: Datadir, Debug: true, Ver: "0.5.14", conf: g, Identifier: Identifier}
Config.SetClientString("Ethereum(G)")
}
return Config
}
@ -98,137 +63,12 @@ func (c *config) SetIdentifier(id string) {
c.Set("id", id)
}
// provides persistence for flags
func (c *config) Set(key, value string) {
f := &flag.Flag{Name: key, Value: &confValue{value}}
c.conf.Set("", f)
}
type LoggerType byte
const (
LogFile = 0x1
LogStd = 0x2
)
type LogSystem interface {
Println(v ...interface{})
Printf(format string, v ...interface{})
}
type Logger struct {
logSys []LogSystem
logLevel int
}
func NewLogger(flag LoggerType, level int) *Logger {
var loggers []LogSystem
flags := log.LstdFlags
if flag&LogFile > 0 {
file, err := os.OpenFile(path.Join(Config.ExecPath, "debug.log"), os.O_RDWR|os.O_CREATE|os.O_APPEND, os.ModePerm)
if err != nil {
log.Panic("unable to create file logger", err)
}
log := log.New(file, "", flags)
loggers = append(loggers, log)
}
if flag&LogStd > 0 {
log := log.New(os.Stdout, "", flags)
loggers = append(loggers, log)
}
return &Logger{logSys: loggers, logLevel: level}
}
func (self *Logger) SetLevel(level int) {
self.logLevel = level
}
func (log *Logger) AddLogSystem(logger LogSystem) {
log.logSys = append(log.logSys, logger)
}
const (
LogLevelSystem = iota
LogLevelDebug
LogLevelInfo
)
func (log *Logger) Debugln(v ...interface{}) {
if log.logLevel != LogLevelDebug {
return
}
for _, logger := range log.logSys {
logger.Println(v...)
}
}
func (log *Logger) Debugf(format string, v ...interface{}) {
if log.logLevel != LogLevelDebug {
return
}
for _, logger := range log.logSys {
logger.Printf(format, v...)
}
}
func (log *Logger) Infoln(v ...interface{}) {
if log.logLevel > LogLevelInfo {
return
}
for _, logger := range log.logSys {
logger.Println(v...)
}
}
func (log *Logger) Infof(format string, v ...interface{}) {
if log.logLevel > LogLevelInfo {
return
}
for _, logger := range log.logSys {
logger.Printf(format, v...)
}
}
func (log *Logger) Fatal(v ...interface{}) {
if log.logLevel > LogLevelInfo {
return
}
for _, logger := range log.logSys {
logger.Println(v...)
}
os.Exit(1)
}
func (log *Logger) Println(level int, v ...interface{}) {
if log.logLevel > level {
return
}
for _, logger := range log.logSys {
logger.Println(v...)
}
}
func (log *Logger) Printf(level int, format string, v ...interface{}) {
if log.logLevel > level {
return
}
for _, logger := range log.logSys {
logger.Printf(format, v...)
}
}
type confValue struct {
value string
}

View File

@ -64,4 +64,4 @@ func TestCompactDecode(t *testing.T) {
if !CompareIntSlice(res, exp) {
t.Error("even terminated compact decode. Expected", exp, "got", res)
}
}
}

60
peer.go
View File

@ -5,6 +5,7 @@ import (
"container/list"
"fmt"
"github.com/ethereum/eth-go/ethchain"
"github.com/ethereum/eth-go/ethlog"
"github.com/ethereum/eth-go/ethutil"
"github.com/ethereum/eth-go/ethwire"
"net"
@ -14,6 +15,8 @@ import (
"time"
)
var peerlogger = ethlog.NewLogger("PEER")
const (
// The size of the output buffer for writing messages
outputBufferSize = 50
@ -178,7 +181,7 @@ func NewOutboundPeer(addr string, ethereum *Ethereum, caps Caps) *Peer {
conn, err := net.DialTimeout("tcp", addr, 10*time.Second)
if err != nil {
ethutil.Config.Log.Debugln("Connection to peer failed", err)
peerlogger.Debugln("Connection to peer failed", err)
p.Stop()
return
}
@ -247,11 +250,11 @@ func (p *Peer) writeMessage(msg *ethwire.Msg) {
}
}
ethutil.Config.Log.Println(ethutil.LogLevelSystem, "<=", msg.Type, msg.Data)
peerlogger.DebugDetailln("<=", msg.Type, msg.Data)
err := ethwire.WriteMessage(p.conn, msg)
if err != nil {
ethutil.Config.Log.Debugln("[PEER] Can't send message:", err)
peerlogger.Debugln(" Can't send message:", err)
// Stop the client if there was an error writing to it
p.Stop()
return
@ -276,7 +279,7 @@ out:
case <-pingTimer.C:
timeSince := time.Since(time.Unix(p.lastPong, 0))
if !p.pingStartTime.IsZero() && p.lastPong != 0 && timeSince > (pingPongTimer+30*time.Second) {
ethutil.Config.Log.Infof("[PEER] Peer did not respond to latest pong fast enough, it took %s, disconnecting.\n", timeSince)
peerlogger.Infof("Peer did not respond to latest pong fast enough, it took %s, disconnecting.\n", timeSince)
p.Stop()
return
}
@ -318,10 +321,10 @@ func (p *Peer) HandleInbound() {
// Wait for a message from the peer
msgs, err := ethwire.ReadMessages(p.conn)
if err != nil {
ethutil.Config.Log.Debugln(err)
peerlogger.Debugln(err)
}
for _, msg := range msgs {
ethutil.Config.Log.Println(ethutil.LogLevelSystem, "=>", msg.Type, msg.Data)
peerlogger.DebugDetailln("=>", msg.Type, msg.Data)
switch msg.Type {
case ethwire.MsgHandshakeTy:
@ -333,7 +336,7 @@ func (p *Peer) HandleInbound() {
}
case ethwire.MsgDiscTy:
p.Stop()
ethutil.Config.Log.Infoln("Disconnect peer:", DiscReason(msg.Data.Get(0).Uint()))
peerlogger.Infoln("Disconnect peer:", DiscReason(msg.Data.Get(0).Uint()))
case ethwire.MsgPingTy:
// Respond back with pong
p.QueueMessage(ethwire.NewMessage(ethwire.MsgPongTy, ""))
@ -358,8 +361,7 @@ func (p *Peer) HandleInbound() {
continue
}
p.lastRequestedBlock = lastBlock
ethutil.Config.Log.Infof("[PEER] Last block: %x. Checking if we have it locally.\n", lastBlock.Hash())
peerlogger.Infof("Last block: %x. Checking if we have it locally.\n", lastBlock.Hash())
for i := msg.Data.Len() - 1; i >= 0; i-- {
block = ethchain.NewBlockFromRlpValue(msg.Data.Get(i))
// Do we have this block on our chain? If so we can continue
@ -380,7 +382,7 @@ func (p *Peer) HandleInbound() {
// we just keep increasing the amount of blocks.
p.blocksRequested = p.blocksRequested * 2
ethutil.Config.Log.Infof("[PEER] No common ancestor found, requesting %d more blocks.\n", p.blocksRequested)
peerlogger.Infof("No common ancestor found, requesting %d more blocks.\n", p.blocksRequested)
p.catchingUp = false
p.FindCommonParentBlock()
break
@ -396,9 +398,9 @@ func (p *Peer) HandleInbound() {
if err != nil {
if ethutil.Config.Debug {
ethutil.Config.Log.Infof("[PEER] Block %x failed\n", block.Hash())
ethutil.Config.Log.Infof("[PEER] %v\n", err)
ethutil.Config.Log.Debugln(block)
peerlogger.Infof("Block %x failed\n", block.Hash())
peerlogger.Infof("%v\n", err)
peerlogger.Debugln(block)
}
break
} else {
@ -415,7 +417,7 @@ func (p *Peer) HandleInbound() {
if err != nil {
// If the parent is unknown try to catch up with this peer
if ethchain.IsParentErr(err) {
ethutil.Config.Log.Infoln("Attempting to catch. Parent known")
peerlogger.Infoln("Attempting to catch. Parent known")
p.catchingUp = false
p.CatchupWithPeer(p.ethereum.BlockChain().CurrentBlock.Hash())
} else if ethchain.IsValidationErr(err) {
@ -427,7 +429,7 @@ func (p *Peer) HandleInbound() {
if p.catchingUp && msg.Data.Len() > 1 {
if lastBlock != nil {
blockInfo := lastBlock.BlockInfo()
ethutil.Config.Log.Printf(ethutil.LogLevelSystem, "Synced chain to #%d %x %x\n", blockInfo.Number, lastBlock.Hash(), blockInfo.Hash)
peerlogger.DebugDetailf("Synced chain to #%d %x %x\n", blockInfo.Number, lastBlock.Hash(), blockInfo.Hash)
}
p.catchingUp = false
@ -494,17 +496,17 @@ func (p *Peer) HandleInbound() {
// If a parent is found send back a reply
if parent != nil {
ethutil.Config.Log.Printf(ethutil.LogLevelSystem, "[PEER] Found canonical block, returning chain from: %x ", parent.Hash())
peerlogger.DebugDetailf("Found canonical block, returning chain from: %x ", parent.Hash())
chain := p.ethereum.BlockChain().GetChainFromHash(parent.Hash(), amountOfBlocks)
if len(chain) > 0 {
//ethutil.Config.Log.Debugf("[PEER] Returning %d blocks: %x ", len(chain), parent.Hash())
//peerlogger.Debugf("Returning %d blocks: %x ", len(chain), parent.Hash())
p.QueueMessage(ethwire.NewMessage(ethwire.MsgBlockTy, chain))
} else {
p.QueueMessage(ethwire.NewMessage(ethwire.MsgBlockTy, []interface{}{}))
}
} else {
//ethutil.Config.Log.Debugf("[PEER] Could not find a similar block")
//peerlogger.Debugf("Could not find a similar block")
// If no blocks are found we send back a reply with msg not in chain
// and the last hash from get chain
if l > 0 {
@ -514,7 +516,7 @@ func (p *Peer) HandleInbound() {
}
}
case ethwire.MsgNotInChainTy:
ethutil.Config.Log.Printf(ethutil.LogLevelSystem, "Not in chain: %x\n", msg.Data.Get(0).Bytes())
peerlogger.DebugDetailf("Not in chain: %x\n", msg.Data.Get(0).Bytes())
if p.diverted == true {
// If were already looking for a common parent and we get here again we need to go deeper
p.blocksRequested = p.blocksRequested * 2
@ -535,7 +537,7 @@ func (p *Peer) HandleInbound() {
// Unofficial but fun nonetheless
case ethwire.MsgTalkTy:
ethutil.Config.Log.Infoln("%v says: %s\n", p.conn.RemoteAddr(), msg.Data.Str())
peerlogger.Infoln("%v says: %s\n", p.conn.RemoteAddr(), msg.Data.Str())
}
}
}
@ -554,7 +556,7 @@ func (p *Peer) Start() {
err := p.pushHandshake()
if err != nil {
ethutil.Config.Log.Debugln("Peer can't send outbound version ack", err)
peerlogger.Debugln("Peer can't send outbound version ack", err)
p.Stop()
@ -628,7 +630,7 @@ func (p *Peer) handleHandshake(msg *ethwire.Msg) {
p.pubkey = c.Get(5).Bytes()
if p.pubkey == nil {
//ethutil.Config.Log.Debugln("Pubkey required, not supplied in handshake.")
peerlogger.Warnln("Pubkey required, not supplied in handshake.")
p.Stop()
return
}
@ -643,13 +645,13 @@ func (p *Peer) handleHandshake(msg *ethwire.Msg) {
})
if usedPub > 0 {
//ethutil.Config.Log.Debugf("Pubkey %x found more then once. Already connected to client.", p.pubkey)
peerlogger.Debugf("Pubkey %x found more then once. Already connected to client.", p.pubkey)
p.Stop()
return
}
if c.Get(0).Uint() != ProtocolVersion {
ethutil.Config.Log.Debugf("Invalid peer version. Require protocol: %d. Received: %d\n", ProtocolVersion, c.Get(0).Uint())
peerlogger.Debugf("Invalid peer version. Require protocol: %d. Received: %d\n", ProtocolVersion, c.Get(0).Uint())
p.Stop()
return
}
@ -683,16 +685,16 @@ func (p *Peer) handleHandshake(msg *ethwire.Msg) {
p.ethereum.PushPeer(p)
p.ethereum.reactor.Post("peerList", p.ethereum.Peers())
ethutil.Config.Log.Infof("[SERV] Added peer (%s) %d / %d\n", p.conn.RemoteAddr(), p.ethereum.Peers().Len(), p.ethereum.MaxPeers)
ethlogger.Infof("Added peer (%s) %d / %d\n", p.conn.RemoteAddr(), p.ethereum.Peers().Len(), p.ethereum.MaxPeers)
// Catch up with the connected peer
if !p.ethereum.IsUpToDate() {
ethutil.Config.Log.Debugln("Already syncing up with a peer; sleeping")
peerlogger.Debugln("Already syncing up with a peer; sleeping")
time.Sleep(10 * time.Second)
}
p.SyncWithPeerToLastKnown()
ethutil.Config.Log.Debugln("[PEER]", p)
peerlogger.Debugln(p)
}
func (p *Peer) String() string {
@ -735,7 +737,7 @@ func (p *Peer) FindCommonParentBlock() {
msgInfo := append(hashes, uint64(len(hashes)))
ethutil.Config.Log.Printf(ethutil.LogLevelSystem, "Asking for block from %x (%d total) from %s\n", p.ethereum.BlockChain().CurrentBlock.Hash(), len(hashes), p.conn.RemoteAddr().String())
peerlogger.DebugDetailf("Asking for block from %x (%d total) from %s\n", p.ethereum.BlockChain().CurrentBlock.Hash(), len(hashes), p.conn.RemoteAddr().String())
msg := ethwire.NewMessage(ethwire.MsgGetChainTy, msgInfo)
p.QueueMessage(msg)
@ -747,7 +749,7 @@ func (p *Peer) CatchupWithPeer(blockHash []byte) {
msg := ethwire.NewMessage(ethwire.MsgGetChainTy, []interface{}{blockHash, uint64(50)})
p.QueueMessage(msg)
ethutil.Config.Log.Printf(ethutil.LogLevelSystem, "Requesting blockchain %x... from peer %s\n", p.ethereum.BlockChain().CurrentBlock.Hash()[:4], p.conn.RemoteAddr())
peerlogger.DebugDetailf("Requesting blockchain %x... from peer %s\n", p.ethereum.BlockChain().CurrentBlock.Hash()[:4], p.conn.RemoteAddr())
msg = ethwire.NewMessage(ethwire.MsgGetTxsTy, []interface{}{})
p.QueueMessage(msg)