From 8e9cc3697944c3e568186a5c23ac729f6eb4a1f4 Mon Sep 17 00:00:00 2001 From: zelig Date: Mon, 23 Jun 2014 12:49:04 +0100 Subject: [PATCH 01/10] refactor logging. Details: - 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 - README.md - loggers_test --- ethlog/README.md | 58 +++++++++++++ ethlog/loggers.go | 179 +++++++++++++++++++++++++++++++++++++++++ ethlog/loggers_test.go | 115 ++++++++++++++++++++++++++ 3 files changed, 352 insertions(+) create mode 100644 ethlog/README.md create mode 100644 ethlog/loggers.go create mode 100644 ethlog/loggers_test.go diff --git a/ethlog/README.md b/ethlog/README.md new file mode 100644 index 000000000..f8818d98e --- /dev/null +++ b/ethlog/README.md @@ -0,0 +1,58 @@ +## 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 + +## Usage + +In an ethereum component package: + + import "github.com/ethereum/eth-go/ethlog" + + // package-wide logger using tag + var logger = ethlog.NewLogger("TAG") + + logger.Infoln("this is info") # > [TAG] This 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) + + + + diff --git a/ethlog/loggers.go b/ethlog/loggers.go new file mode 100644 index 000000000..e656ffbe5 --- /dev/null +++ b/ethlog/loggers.go @@ -0,0 +1,179 @@ +package ethlog + +import ( + "fmt" + "sync" + "log" + "io" + "os" +) + +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 +) + +// 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) 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) 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} +} + diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go new file mode 100644 index 000000000..c33082012 --- /dev/null +++ b/ethlog/loggers_test.go @@ -0,0 +1,115 @@ +package ethlog + +import ( + "testing" + "fmt" + "io/ioutil" + "os" +) + +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() +} + + + + + + From b9e8a3e02493d5bbf23cfcab259e66f6ae166612 Mon Sep 17 00:00:00 2001 From: zelig Date: Mon, 23 Jun 2014 12:54:10 +0100 Subject: [PATCH 02/10] modified logging API - package vars for tagged loggers - weed out spurious fmt.PrintX and log.PrintX logging - tried to second guess loglevel for some :) --- ethchain/block_chain.go | 30 +++++++++--------- ethchain/dagger.go | 10 +++--- ethchain/state.go | 2 +- ethchain/state_manager.go | 20 ++++++------ ethchain/state_object.go | 6 ++-- ethchain/state_transition.go | 7 ++--- ethchain/transaction_pool.go | 20 ++++++------ ethchain/vm.go | 15 +++++---- ethereum.go | 36 +++++++++++----------- ethminer/miner.go | 21 +++++++------ ethpub/pub.go | 5 ++- ethrpc/server.go | 12 +++++--- peer.go | 59 +++++++++++++++++++----------------- 13 files changed, 132 insertions(+), 111 deletions(-) diff --git a/ethchain/block_chain.go b/ethchain/block_chain.go index 19b5248d7..f964e0e3a 100644 --- a/ethchain/block_chain.go +++ b/ethchain/block_chain.go @@ -4,11 +4,13 @@ import ( "bytes" "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethwire" - "log" + "github.com/ethereum/eth-go/ethlog" "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 } } @@ -195,7 +197,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()) @@ -203,7 +205,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 } @@ -286,7 +288,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) @@ -294,14 +296,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) { @@ -358,6 +360,6 @@ func (bc *BlockChain) writeBlockInfo(block *Block) { func (bc *BlockChain) Stop() { if bc.CurrentBlock != nil { - log.Println("[CHAIN] Stopped") + chainlogger.Infoln("Stopped") } } diff --git a/ethchain/dagger.go b/ethchain/dagger.go index 565e1e447..43725e336 100644 --- a/ethchain/dagger.go +++ b/ethchain/dagger.go @@ -2,14 +2,16 @@ package ethchain import ( "github.com/ethereum/eth-go/ethutil" + "github.com/ethereum/eth-go/ethlog" "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,14 @@ 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.") + //powlogger.Infoln("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 +83,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 diff --git a/ethchain/state.go b/ethchain/state.go index a08dfac83..e28b91909 100644 --- a/ethchain/state.go +++ b/ethchain/state.go @@ -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 diff --git a/ethchain/state_manager.go b/ethchain/state_manager.go index 36ba1731c..20e0a13a2 100644 --- a/ethchain/state_manager.go +++ b/ethchain/state_manager.go @@ -3,14 +3,16 @@ package ethchain import ( "bytes" "container/list" - "fmt" "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethwire" + "github.com/ethereum/eth-go/ethlog" "math/big" "sync" "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) } } @@ -186,29 +188,29 @@ func (sm *StateManager) ProcessBlock(state *State, parent, block *Block, dontRea 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())) } } }() // 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 } @@ -221,7 +223,7 @@ func (sm *StateManager) ProcessBlock(state *State, parent, block *Block, dontRea 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) @@ -232,7 +234,7 @@ func (sm *StateManager) ProcessBlock(state *State, parent, block *Block, dontRea sm.Ethereum.TxPool().RemoveInvalid(state) } else { - fmt.Println("total diff failed") + statelogger.Errorln("total diff failed") } return nil diff --git a/ethchain/state_object.go b/ethchain/state_object.go index 5b64c3b37..f53f47d7e 100644 --- a/ethchain/state_object.go +++ b/ethchain/state_object.go @@ -124,13 +124,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) { @@ -151,7 +151,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.Infof("%x: fuel (+ %v)", self.Address(), self.gasPool) } func (self *StateObject) BuyGas(gas, price *big.Int) error { diff --git a/ethchain/state_transition.go b/ethchain/state_transition.go index 1f5b4f959..f84c3486b 100644 --- a/ethchain/state_transition.go +++ b/ethchain/state_transition.go @@ -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 diff --git a/ethchain/transaction_pool.go b/ethchain/transaction_pool.go index 24836222a..44218ae28 100644 --- a/ethchain/transaction_pool.go +++ b/ethchain/transaction_pool.go @@ -3,15 +3,15 @@ package ethchain import ( "bytes" "container/list" - "errors" "fmt" - "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethwire" - "log" + "github.com/ethereum/eth-go/ethlog" "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") } diff --git a/ethchain/vm.go b/ethchain/vm.go index b9e8353fb..75bcfd782 100644 --- a/ethchain/vm.go +++ b/ethchain/vm.go @@ -3,10 +3,13 @@ package ethchain import ( "fmt" "github.com/ethereum/eth-go/ethutil" + "github.com/ethereum/eth-go/ethlog" "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("vm err", 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) // Memory for the current closure mem := &Memory{} @@ -638,7 +641,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 { @@ -657,7 +660,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) @@ -692,7 +695,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) } diff --git a/ethereum.go b/ethereum.go index a6cb78b1f..1de671712 100644 --- a/ethereum.go +++ b/ethereum.go @@ -8,8 +8,8 @@ import ( "github.com/ethereum/eth-go/ethrpc" "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethwire" + "github.com/ethereum/eth-go/ethlog" "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 { - log.Println("Connection listening disabled. Acting as client") + ethlogger.Warnln("Connection listening disabled. Acting as client") 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) } @@ -363,7 +365,7 @@ func (s *Ethereum) Start(seed bool) { } 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 +373,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 +393,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 +406,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 +424,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 } @@ -468,13 +470,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 +490,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") } } diff --git a/ethminer/miner.go b/ethminer/miner.go index 4343b4333..5f5c40134 100644 --- a/ethminer/miner.go +++ b/ethminer/miner.go @@ -5,9 +5,12 @@ import ( "github.com/ethereum/eth-go/ethchain" "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethwire" + "github.com/ethereum/eth-go/ethlog" "sort" ) +var logger = ethlog.NewLogger("MINER") + type Miner struct { pow ethchain.PoW ethereum ethchain.EthManager @@ -67,10 +70,10 @@ out: 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 +95,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) } } @@ -137,14 +140,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 +159,18 @@ func (self *Miner) mineNewBlock() { self.block.State().Update() - ethutil.Config.Log.Infoln("[MINER] Mining on block. Includes", len(self.txs), "transactions") + logger.Infoln("Mining on block. Includes", len(self.txs), "transactions") // 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() } diff --git a/ethpub/pub.go b/ethpub/pub.go index b475453af..a49ee2f12 100644 --- a/ethpub/pub.go +++ b/ethpub/pub.go @@ -4,11 +4,14 @@ import ( "encoding/hex" "github.com/ethereum/eth-go/ethchain" "github.com/ethereum/eth-go/ethutil" + "github.com/ethereum/eth-go/ethlog" "math/big" "strings" "sync/atomic" ) +var logger = ethlog.NewLogger("PUB") + type PEthereum struct { manager ethchain.EthManager stateManager *ethchain.StateManager @@ -191,7 +194,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 diff --git a/ethrpc/server.go b/ethrpc/server.go index 3960e641c..b55469b83 100644 --- a/ethrpc/server.go +++ b/ethrpc/server.go @@ -3,12 +3,14 @@ package ethrpc import ( "fmt" "github.com/ethereum/eth-go/ethpub" - "github.com/ethereum/eth-go/ethutil" + "github.com/ethereum/eth-go/ethlog" "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) } } diff --git a/peer.go b/peer.go index b4bde2c1d..fd8a33d65 100644 --- a/peer.go +++ b/peer.go @@ -7,6 +7,7 @@ import ( "github.com/ethereum/eth-go/ethchain" "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethwire" + "github.com/ethereum/eth-go/ethlog" "net" "strconv" "strings" @@ -14,6 +15,8 @@ import ( "time" ) +var peerlogger = ethlog.NewLogger("PEER") + const ( // The size of the output buffer for writing messages outputBufferSize = 50 @@ -176,7 +179,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 } @@ -245,11 +248,11 @@ func (p *Peer) writeMessage(msg *ethwire.Msg) { } } - ethutil.Config.Log.Println(ethutil.LogLevelSystem, "<=", msg.Type, msg.Data) + peerlogger.Infoln("<=", 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 @@ -274,7 +277,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 } @@ -316,10 +319,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.Infoln("=>", msg.Type, msg.Data) switch msg.Type { case ethwire.MsgHandshakeTy: @@ -331,7 +334,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, "")) @@ -351,7 +354,7 @@ func (p *Peer) HandleInbound() { // We requested blocks and now we need to make sure we have a common ancestor somewhere in these blocks so we can find // common ground to start syncing from lastBlock = ethchain.NewBlockFromRlpValue(msg.Data.Get(msg.Data.Len() - 1)) - 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 @@ -372,7 +375,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 @@ -388,9 +391,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 { @@ -407,7 +410,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) { @@ -419,7 +422,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.Infof("Synced chain to #%d %x %x\n", blockInfo.Number, lastBlock.Hash(), blockInfo.Hash) } p.catchingUp = false @@ -486,17 +489,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.Infof("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 { @@ -506,7 +509,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.Infof("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 @@ -527,7 +530,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()) } } } @@ -546,7 +549,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() @@ -620,7 +623,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 } @@ -635,13 +638,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 } @@ -675,16 +678,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 { @@ -727,7 +730,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.Infof("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) @@ -739,7 +742,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.Infof("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) From 63157c798d613f1ca638597515bb89768e2c1aad Mon Sep 17 00:00:00 2001 From: zelig Date: Mon, 23 Jun 2014 12:55:38 +0100 Subject: [PATCH 03/10] refactor config (transitional). Details: - ReadConfig initialiser sets up global ethutil.Config via config file passed from wrappers - does not write out adhoc default (not meant to) but creates empty config file if it does not exist so that globalconf does not complain if persists a flag - default datadir and default config file set together with other flag defaults in wrappers - default assetpath set together with other command line flags defaults in gui wrapper (not in ethutil.Config or ui/ui_lib) - add EnvPrefix, to handle environment variable options too via globalconf - this is still transitional: global Config should just be a wrapper around globalconfig config handler and should be moved to go-ethereum - actual eth stack config should not be global instead config handled properly with explicit dependency injectioninto eth stack component instances --- ethutil/config.go | 200 +++++----------------------------------------- 1 file changed, 20 insertions(+), 180 deletions(-) diff --git a/ethutil/config.go b/ethutil/config.go index a573e108b..52537ffa6 100644 --- a/ethutil/config.go +++ b/ethutil/config.go @@ -4,18 +4,14 @@ import ( "flag" "fmt" "github.com/rakyll/globalconf" - "log" - "os" - "os/user" - "path" "runtime" + "os" ) // Config struct 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 } From e75f7ae3301bb66ca6d4e9c099c6a14bbe2be418 Mon Sep 17 00:00:00 2001 From: zelig Date: Wed, 25 Jun 2014 16:37:38 +0100 Subject: [PATCH 04/10] implement DebugDetail loglevel and named print methods --- ethlog/loggers.go | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/ethlog/loggers.go b/ethlog/loggers.go index e656ffbe5..be42c9fb7 100644 --- a/ethlog/loggers.go +++ b/ethlog/loggers.go @@ -49,6 +49,7 @@ const ( WarnLevel InfoLevel DebugLevel + DebugDetailLevel ) // log messages are dispatched to log writers @@ -123,6 +124,10 @@ 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...) } @@ -139,6 +144,10 @@ 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() From 6465e4c3fd21e7002e5870069c51755bd2c66df5 Mon Sep 17 00:00:00 2001 From: zelig Date: Wed, 25 Jun 2014 16:38:42 +0100 Subject: [PATCH 05/10] update doc: list levels and show usage of named print methods --- ethlog/README.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/ethlog/README.md b/ethlog/README.md index f8818d98e..d9b69e106 100644 --- a/ethlog/README.md +++ b/ethlog/README.md @@ -6,6 +6,7 @@ - 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 @@ -16,7 +17,10 @@ In an ethereum component package: // 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 From a02edf7a9306c9c0b2f0208152347b47f1a4e689 Mon Sep 17 00:00:00 2001 From: zelig Date: Wed, 25 Jun 2014 16:40:06 +0100 Subject: [PATCH 06/10] put back extra debug detail logging to the right places using logger.DebugDetailf --- ethchain/state_object.go | 2 +- peer.go | 14 +++++++------- 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/ethchain/state_object.go b/ethchain/state_object.go index 7d7352af4..26ad3e982 100644 --- a/ethchain/state_object.go +++ b/ethchain/state_object.go @@ -158,7 +158,7 @@ func (c *StateObject) ConvertGas(gas, price *big.Int) error { func (self *StateObject) SetGasPool(gasLimit *big.Int) { self.gasPool = new(big.Int).Set(gasLimit) - statelogger.Infof("%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 { diff --git a/peer.go b/peer.go index 18d1da455..2dcdea474 100644 --- a/peer.go +++ b/peer.go @@ -250,7 +250,7 @@ func (p *Peer) writeMessage(msg *ethwire.Msg) { } } - peerlogger.Infoln("<=", msg.Type, msg.Data) + peerlogger.DebugDetailln("<=", msg.Type, msg.Data) err := ethwire.WriteMessage(p.conn, msg) if err != nil { @@ -324,7 +324,7 @@ func (p *Peer) HandleInbound() { peerlogger.Debugln(err) } for _, msg := range msgs { - peerlogger.Infoln("=>", msg.Type, msg.Data) + peerlogger.DebugDetailln("=>", msg.Type, msg.Data) switch msg.Type { case ethwire.MsgHandshakeTy: @@ -429,7 +429,7 @@ func (p *Peer) HandleInbound() { if p.catchingUp && msg.Data.Len() > 1 { if lastBlock != nil { blockInfo := lastBlock.BlockInfo() - peerlogger.Infof("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 @@ -496,7 +496,7 @@ func (p *Peer) HandleInbound() { // If a parent is found send back a reply if parent != nil { - peerlogger.Infof("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 { //peerlogger.Debugf("Returning %d blocks: %x ", len(chain), parent.Hash()) @@ -516,7 +516,7 @@ func (p *Peer) HandleInbound() { } } case ethwire.MsgNotInChainTy: - peerlogger.Infof("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 @@ -737,7 +737,7 @@ func (p *Peer) FindCommonParentBlock() { msgInfo := append(hashes, uint64(len(hashes))) - peerlogger.Infof("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) @@ -749,7 +749,7 @@ func (p *Peer) CatchupWithPeer(blockHash []byte) { msg := ethwire.NewMessage(ethwire.MsgGetChainTy, []interface{}{blockHash, uint64(50)}) p.QueueMessage(msg) - peerlogger.Infof("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) From a243e3b8588bb3a65af4a7131c279b9d94c62be1 Mon Sep 17 00:00:00 2001 From: zelig Date: Wed, 25 Jun 2014 17:59:35 +0100 Subject: [PATCH 07/10] new logger API for upstream merge --- ethrpc/packages.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethrpc/packages.go b/ethrpc/packages.go index 3f57f6982..710275780 100644 --- a/ethrpc/packages.go +++ b/ethrpc/packages.go @@ -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 From 782f780476afb3c895c30583fc5cbd6d7d830d3d Mon Sep 17 00:00:00 2001 From: zelig Date: Wed, 25 Jun 2014 18:43:35 +0100 Subject: [PATCH 08/10] space in miner logging message --- ethminer/miner.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethminer/miner.go b/ethminer/miner.go index 5f5c40134..2c1645672 100644 --- a/ethminer/miner.go +++ b/ethminer/miner.go @@ -159,7 +159,7 @@ func (self *Miner) mineNewBlock() { self.block.State().Update() - logger.Infoln("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) From 098136b68198083a47408ec5c04cd0c8f9fdcc87 Mon Sep 17 00:00:00 2001 From: zelig Date: Thu, 26 Jun 2014 10:43:02 +0100 Subject: [PATCH 09/10] ethereum logs server started/stopped message --- ethereum.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/ethereum.go b/ethereum.go index 1de671712..28d1c0437 100644 --- a/ethereum.go +++ b/ethereum.go @@ -362,6 +362,7 @@ func (s *Ethereum) Start(seed bool) { if seed { s.Seed() } + ethlogger.Infoln("Server started") } func (s *Ethereum) Seed() { @@ -449,6 +450,7 @@ func (s *Ethereum) Stop() { s.txPool.Stop() s.stateManager.Stop() + ethlogger.Infoln("Server stopped") close(s.shutdownChan) } From 853053a3b204ddf4ae935e70e0aa5b5d8994493e Mon Sep 17 00:00:00 2001 From: zelig Date: Thu, 26 Jun 2014 18:45:57 +0100 Subject: [PATCH 10/10] go fmt --- ethchain/block_chain.go | 2 +- ethchain/dagger.go | 3 +- ethchain/state_manager.go | 2 +- ethchain/transaction_pool.go | 2 +- ethchain/vm.go | 2 +- ethereum.go | 2 +- ethlog/loggers.go | 202 +++++++++++++++++------------------ ethlog/loggers_test.go | 150 +++++++++++++------------- ethminer/miner.go | 10 +- ethpub/pub.go | 2 +- ethrpc/server.go | 2 +- ethutil/config.go | 26 ++--- ethutil/encoding_test.go | 2 +- peer.go | 2 +- 14 files changed, 204 insertions(+), 205 deletions(-) diff --git a/ethchain/block_chain.go b/ethchain/block_chain.go index 05b2564cf..d0fea6641 100644 --- a/ethchain/block_chain.go +++ b/ethchain/block_chain.go @@ -2,9 +2,9 @@ package ethchain import ( "bytes" + "github.com/ethereum/eth-go/ethlog" "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethwire" - "github.com/ethereum/eth-go/ethlog" "math" "math/big" ) diff --git a/ethchain/dagger.go b/ethchain/dagger.go index 43725e336..08c4826db 100644 --- a/ethchain/dagger.go +++ b/ethchain/dagger.go @@ -1,8 +1,8 @@ package ethchain import ( - "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethlog" + "github.com/ethereum/eth-go/ethutil" "github.com/obscuren/sha3" "hash" "math/big" @@ -31,7 +31,6 @@ func (pow *EasyPow) Search(block *Block, reactChan chan ethutil.React) []byte { for { select { case <-reactChan: - //powlogger.Infoln("Received reactor event; breaking out.") return nil default: i++ diff --git a/ethchain/state_manager.go b/ethchain/state_manager.go index e5941b165..312ba3084 100644 --- a/ethchain/state_manager.go +++ b/ethchain/state_manager.go @@ -3,9 +3,9 @@ package ethchain import ( "bytes" "container/list" + "github.com/ethereum/eth-go/ethlog" "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethwire" - "github.com/ethereum/eth-go/ethlog" "math/big" "sync" "time" diff --git a/ethchain/transaction_pool.go b/ethchain/transaction_pool.go index 44218ae28..6ab8d83d9 100644 --- a/ethchain/transaction_pool.go +++ b/ethchain/transaction_pool.go @@ -4,8 +4,8 @@ import ( "bytes" "container/list" "fmt" - "github.com/ethereum/eth-go/ethwire" "github.com/ethereum/eth-go/ethlog" + "github.com/ethereum/eth-go/ethwire" "math/big" "sync" ) diff --git a/ethchain/vm.go b/ethchain/vm.go index 20d355674..82591e274 100644 --- a/ethchain/vm.go +++ b/ethchain/vm.go @@ -2,8 +2,8 @@ package ethchain import ( "fmt" - "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethlog" + "github.com/ethereum/eth-go/ethutil" "math" "math/big" ) diff --git a/ethereum.go b/ethereum.go index 8caa75cbd..a3df23e92 100644 --- a/ethereum.go +++ b/ethereum.go @@ -5,10 +5,10 @@ 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" - "github.com/ethereum/eth-go/ethlog" "io/ioutil" "math/rand" "net" diff --git a/ethlog/loggers.go b/ethlog/loggers.go index be42c9fb7..9ebe59096 100644 --- a/ethlog/loggers.go +++ b/ethlog/loggers.go @@ -1,188 +1,188 @@ package ethlog import ( - "fmt" - "sync" - "log" - "io" - "os" + "fmt" + "io" + "log" + "os" + "sync" ) type LogSystem interface { - GetLogLevel() LogLevel - SetLogLevel(i LogLevel) - Println(v ...interface{}) - Printf(format string, v ...interface{}) + GetLogLevel() LogLevel + SetLogLevel(i LogLevel) + Println(v ...interface{}) + Printf(format string, v ...interface{}) } type logMessage struct { - LogLevel LogLevel - format bool - msg string + 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 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 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) - } + if msg.format { + logger.Printf(msg.msg) + } else { + logger.Println(msg.msg) + } } -var logMessages chan(*logMessage) -var logSystems []LogSystem +var logMessages chan (*logMessage) +var logSystems []LogSystem var drained = true type LogLevel uint8 const ( - Silence LogLevel = iota - ErrorLevel - WarnLevel - InfoLevel - DebugLevel - DebugDetailLevel + 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 - } - } + 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 {} + for !drained { + } } type Logger struct { - tag string + tag string } func NewLogger(tag string) *Logger { - return &Logger{tag} + 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) + 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) 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) 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) Errorln(v ...interface{}) { + logger.sendln(ErrorLevel, v...) } -func (logger *Logger) Warnln(v...interface{}) { - logger.sendln(WarnLevel, v...) +func (logger *Logger) Warnln(v ...interface{}) { + logger.sendln(WarnLevel, v...) } -func (logger *Logger) Infoln(v...interface{}) { - logger.sendln(InfoLevel, v...) +func (logger *Logger) Infoln(v ...interface{}) { + logger.sendln(InfoLevel, v...) } -func (logger *Logger) Debugln(v...interface{}) { - logger.sendln(DebugLevel, v...) +func (logger *Logger) Debugln(v ...interface{}) { + logger.sendln(DebugLevel, v...) } -func (logger *Logger) DebugDetailln(v...interface{}) { - logger.sendln(DebugDetailLevel, 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) 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) 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) 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) 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) 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) 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) +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 + logger *log.Logger + level LogLevel } func (t *StdLogSystem) Println(v ...interface{}) { - t.logger.Println(v...) + t.logger.Println(v...) } func (t *StdLogSystem) Printf(format string, v ...interface{}) { - t.logger.Printf(format, v...) + t.logger.Printf(format, v...) } func (t *StdLogSystem) SetLogLevel(i LogLevel) { - t.level = i + t.level = i } func (t *StdLogSystem) GetLogLevel() LogLevel { - return t.level + return t.level } func NewStdLogSystem(writer io.Writer, flags int, level LogLevel) *StdLogSystem { - logger := log.New(writer, "", flags) - return &StdLogSystem{logger, level} + logger := log.New(writer, "", flags) + return &StdLogSystem{logger, level} } - diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index c33082012..89f416681 100644 --- a/ethlog/loggers_test.go +++ b/ethlog/loggers_test.go @@ -1,115 +1,109 @@ package ethlog import ( - "testing" - "fmt" - "io/ioutil" - "os" + "fmt" + "io/ioutil" + "os" + "testing" ) type TestLogSystem struct { - Output string - level LogLevel + Output string + level LogLevel } func (t *TestLogSystem) Println(v ...interface{}) { - t.Output += fmt.Sprintln(v...) + t.Output += fmt.Sprintln(v...) } func (t *TestLogSystem) Printf(format string, v ...interface{}) { - t.Output += fmt.Sprintf(format, v...) + t.Output += fmt.Sprintf(format, v...) } func (t *TestLogSystem) SetLogLevel(i LogLevel) { - t.level = i + t.level = i } func (t *TestLogSystem) GetLogLevel() LogLevel { - return t.level + return t.level } func quote(s string) string { - return fmt.Sprintf("'%s'", s) + 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)) - } + 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)) - } + 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)) - } + 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) - } + 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() + logger := NewLogger("TEST") + logger.Warnln("warn") + Flush() } - - - - - - diff --git a/ethminer/miner.go b/ethminer/miner.go index 2c1645672..66388723e 100644 --- a/ethminer/miner.go +++ b/ethminer/miner.go @@ -3,9 +3,9 @@ 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" - "github.com/ethereum/eth-go/ethlog" "sort" ) @@ -57,18 +57,23 @@ 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 { //logger.Infoln("Got new block via Reactor") if bytes.Compare(miner.ethereum.BlockChain().CurrentBlock.Hash(), block.Hash()) == 0 { @@ -123,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() { diff --git a/ethpub/pub.go b/ethpub/pub.go index 647e689ce..1bc9e0ce7 100644 --- a/ethpub/pub.go +++ b/ethpub/pub.go @@ -5,8 +5,8 @@ import ( "encoding/hex" "encoding/json" "github.com/ethereum/eth-go/ethchain" - "github.com/ethereum/eth-go/ethutil" "github.com/ethereum/eth-go/ethlog" + "github.com/ethereum/eth-go/ethutil" "math/big" "strings" "sync/atomic" diff --git a/ethrpc/server.go b/ethrpc/server.go index b55469b83..d9d6f695b 100644 --- a/ethrpc/server.go +++ b/ethrpc/server.go @@ -2,8 +2,8 @@ package ethrpc import ( "fmt" - "github.com/ethereum/eth-go/ethpub" "github.com/ethereum/eth-go/ethlog" + "github.com/ethereum/eth-go/ethpub" "net" "net/rpc" "net/rpc/jsonrpc" diff --git a/ethutil/config.go b/ethutil/config.go index 52537ffa6..aa4ae9c3e 100644 --- a/ethutil/config.go +++ b/ethutil/config.go @@ -4,8 +4,8 @@ import ( "flag" "fmt" "github.com/rakyll/globalconf" - "runtime" "os" + "runtime" ) // Config struct @@ -29,21 +29,21 @@ var Config *config // Initialize Config from Config File func ReadConfig(ConfigFile string, Datadir string, Identifier string, EnvPrefix string) *config { if Config == nil { - // create ConfigFile if does not exist, otherwise globalconf panic when trying to persist flags - _, err := os.Stat(ConfigFile) - if err != nil && os.IsNotExist(err) { + // 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, + os.Create(ConfigFile) + } + g, err := globalconf.NewWithOptions(&globalconf.Options{ + Filename: ConfigFile, + EnvPrefix: EnvPrefix, }) if err != nil { - fmt.Println(err) - } else { - g.ParseAll() - } + fmt.Println(err) + } else { + g.ParseAll() + } Config = &config{ExecPath: Datadir, Debug: true, Ver: "0.5.14", conf: g, Identifier: Identifier} Config.SetClientString("Ethereum(G)") } diff --git a/ethutil/encoding_test.go b/ethutil/encoding_test.go index cbfbc0eaf..10e1995c0 100644 --- a/ethutil/encoding_test.go +++ b/ethutil/encoding_test.go @@ -64,4 +64,4 @@ func TestCompactDecode(t *testing.T) { if !CompareIntSlice(res, exp) { t.Error("even terminated compact decode. Expected", exp, "got", res) } -} \ No newline at end of file +} diff --git a/peer.go b/peer.go index 2dcdea474..e50fd43f9 100644 --- a/peer.go +++ b/peer.go @@ -5,9 +5,9 @@ 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" - "github.com/ethereum/eth-go/ethlog" "net" "strconv" "strings"