Updated logging

blockpool/blockpool.go

@@ -12,6 +12,7 @@ import (
 	"github.com/ethereum/go-ethereum/errs"
 	"github.com/ethereum/go-ethereum/event"
 	ethlogger "github.com/ethereum/go-ethereum/logger"
+	"github.com/ethereum/go-ethereum/logger/glog"
 	"github.com/ethereum/go-ethereum/pow"
 )
 
@@ -260,7 +261,7 @@ func (self *BlockPool) Start() {
 			}
 		}
 	}()
-	plog.Infoln("Started")
+	glog.V(ethlogger.Info).Infoln("Blockpool started")
 }
 
 func (self *BlockPool) Stop() {

cmd/utils/cmd.go

@@ -33,10 +33,10 @@ import (
 	"github.com/ethereum/go-ethereum/core/types"
 	"github.com/ethereum/go-ethereum/eth"
 	"github.com/ethereum/go-ethereum/logger"
+	"github.com/ethereum/go-ethereum/logger/glog"
 	"github.com/ethereum/go-ethereum/rlp"
 )
 
-var clilogger = logger.NewLogger("CLI")
 var interruptCallbacks = []func(os.Signal){}
 
 // Register interrupt handlers callbacks
@@ -50,7 +50,7 @@ func HandleInterrupt() {
 	go func() {
 		signal.Notify(c, os.Interrupt)
 		for sig := range c {
-			clilogger.Errorf("Shutting down (%v) ... \n", sig)
+			glog.V(logger.Error).Infof("Shutting down (%v) ... \n", sig)
 			RunInterruptCallbacks(sig)
 		}
 	}()
@@ -113,7 +113,7 @@ func Fatalf(format string, args ...interface{}) {
 }
 
 func StartEthereum(ethereum *eth.Ethereum) {
-	clilogger.Infoln("Starting ", ethereum.Name())
+	glog.V(logger.Info).Infoln("Starting ", ethereum.Name())
 	if err := ethereum.Start(); err != nil {
 		exit(err)
 	}
@@ -124,7 +124,7 @@ func StartEthereum(ethereum *eth.Ethereum) {
 }
 
 func StartEthereumForTest(ethereum *eth.Ethereum) {
-	clilogger.Infoln("Starting ", ethereum.Name())
+	glog.V(logger.Info).Infoln("Starting ", ethereum.Name())
 	ethereum.StartForTest()
 	RegisterInterrupt(func(sig os.Signal) {
 		ethereum.Stop()

cmd/utils/flags.go

@@ -194,6 +194,11 @@ var (
 		Name:  "logtostderr",
 		Usage: "Logs are written to standard error instead of to files.",
 	}
+	LogVModuleFlag = cli.GenericFlag{
+		Name:  "vmodule",
+		Usage: "The syntax of the argument is a comma-separated list of pattern=N, where pattern is a literal file name (minus the \".go\" suffix) or \"glob\" pattern and N is a V level.",
+		Value: glog.GetVModule(),
+	}
 )
 
 func GetNAT(ctx *cli.Context) nat.Interface {
@@ -227,6 +232,8 @@ func MakeEthConfig(clientID, version string, ctx *cli.Context) *eth.Config {
 	glog.SetV(ctx.GlobalInt(LogLevelFlag.Name))
 	// Set the log type
 	glog.SetToStderr(ctx.GlobalBool(LogToStdErrFlag.Name))
+	// Set the log dir
+	glog.SetLogDir(ctx.GlobalString(LogFileFlag.Name))
 
 	return &eth.Config{
 		Name:            common.MakeName(clientID, version),

core/chain_manager.go

@@ -452,7 +452,7 @@ func (self *ChainManager) InsertChain(chain types.Blocks) error {
 	var (
 		queue      = make([]interface{}, len(chain))
 		queueEvent = queueEvent{queue: queue}
-		stats      struct{ delayed, processed int }
+		stats      struct{ queued, processed int }
 		tstart     = time.Now()
 	)
 	for i, block := range chain {
@@ -472,13 +472,13 @@ func (self *ChainManager) InsertChain(chain types.Blocks) error {
 			// future block for future use
 			if err == BlockFutureErr {
 				self.futureBlocks.Push(block)
-				stats.delayed++
+				stats.queued++
 				continue
 			}
 
 			if IsParentErr(err) && self.futureBlocks.Has(block.ParentHash()) {
 				self.futureBlocks.Push(block)
-				stats.delayed++
+				stats.queued++
 				continue
 			}
 
@@ -545,10 +545,10 @@ func (self *ChainManager) InsertChain(chain types.Blocks) error {
 
 	}
 
-	if (stats.delayed > 0 || stats.processed > 0) && bool(glog.V(logger.Info)) {
+	if (stats.queued > 0 || stats.processed > 0) && bool(glog.V(logger.Info)) {
 		tend := time.Since(tstart)
 		start, end := chain[0], chain[len(chain)-1]
-		glog.Infof("imported %d block(s) %d delayed in %v. #%v [%x / %x]\n", stats.processed, stats.delayed, tend, end.Number(), start.Hash().Bytes()[:4], end.Hash().Bytes()[:4])
+		glog.Infof("imported %d block(s) %d queued in %v. #%v [%x / %x]\n", stats.processed, stats.queued, tend, end.Number(), start.Hash().Bytes()[:4], end.Hash().Bytes()[:4])
 	}
 
 	go self.eventMux.Post(queueEvent)

eth/backend.go

@@ -18,6 +18,7 @@ import (
 	"github.com/ethereum/go-ethereum/ethdb"
 	"github.com/ethereum/go-ethereum/event"
 	"github.com/ethereum/go-ethereum/logger"
+	"github.com/ethereum/go-ethereum/logger/glog"
 	"github.com/ethereum/go-ethereum/miner"
 	"github.com/ethereum/go-ethereum/p2p"
 	"github.com/ethereum/go-ethereum/p2p/discover"
@@ -26,7 +27,6 @@ import (
 )
 
 var (
-	servlogger = logger.NewLogger("SERV")
 	jsonlogger = logger.NewJsonLogger()
 
 	defaultBootNodes = []*discover.Node{
@@ -83,7 +83,7 @@ func (cfg *Config) parseBootNodes() []*discover.Node {
 		}
 		n, err := discover.ParseNode(url)
 		if err != nil {
-			servlogger.Errorf("Bootstrap URL %s: %v\n", url, err)
+			glog.V(logger.Error).Infof("Bootstrap URL %s: %v\n", url, err)
 			continue
 		}
 		ns = append(ns, n)
@@ -107,7 +107,7 @@ func (cfg *Config) nodeKey() (*ecdsa.PrivateKey, error) {
 		return nil, fmt.Errorf("could not generate server key: %v", err)
 	}
 	if err := ioutil.WriteFile(keyfile, crypto.FromECDSA(key), 0600); err != nil {
-		servlogger.Errorln("could not persist nodekey: ", err)
+		glog.V(logger.Error).Infoln("could not persist nodekey: ", err)
 	}
 	return key, nil
 }
@@ -177,7 +177,7 @@ func New(config *Config) (*Ethereum, error) {
 		return nil, fmt.Errorf("Database version mismatch. Protocol(%d / %d). `rm -rf %s`", protov, config.ProtocolVersion, path)
 	}
 	saveProtocolVersion(blockDb, config.ProtocolVersion)
-	servlogger.Infof("Protocol Version: %v, Network Id: %v", config.ProtocolVersion, config.NetworkId)
+	glog.V(logger.Info).Infof("Protocol Version: %v, Network Id: %v", config.ProtocolVersion, config.NetworkId)
 
 	eth := &Ethereum{
 		shutdownChan:   make(chan bool),
@@ -303,7 +303,7 @@ func (s *Ethereum) StartMining() error {
 	eb, err := s.Etherbase()
 	if err != nil {
 		err = fmt.Errorf("Cannot start mining without etherbase address: %v", err)
-		servlogger.Errorln(err)
+		glog.V(logger.Error).Infoln(err)
 		return err
 
 	}
@@ -380,7 +380,7 @@ func (s *Ethereum) Start() error {
 	s.blockSub = s.eventMux.Subscribe(core.ChainHeadEvent{})
 	go s.blockBroadcastLoop()
 
-	servlogger.Infoln("Server started")
+	glog.V(logger.Info).Infoln("Server started")
 	return nil
 }
 
@@ -420,7 +420,7 @@ func (s *Ethereum) Stop() {
 		s.whisper.Stop()
 	}
 
-	servlogger.Infoln("Server stopped")
+	glog.V(logger.Info).Infoln("Server stopped")
 	close(s.shutdownChan)
 }
 

eth/protocol_test.go

@@ -250,7 +250,7 @@ func TestNewBlockMsg(t *testing.T) {
 
 	var delay = 1 * time.Second
 	// eth.reset()
-	block := types.NewBlock(common.Hash{1}, common.Address{1}, common.Hash{1}, common.Big1, 1, "extra")
+	block := types.NewBlock(common.Hash{1}, common.Address{1}, common.Hash{1}, common.Big1, 1, []byte("extra"))
 
 	go p2p.Send(eth, NewBlockMsg, &newBlockMsgData{Block: block})
 	timer := time.After(delay)
@@ -315,7 +315,7 @@ func TestBlockMsg(t *testing.T) {
 	var delay = 3 * time.Second
 	// eth.reset()
 	newblock := func(i int64) *types.Block {
-		return types.NewBlock(common.Hash{byte(i)}, common.Address{byte(i)}, common.Hash{byte(i)}, big.NewInt(i), uint64(i), string(i))
+		return types.NewBlock(common.Hash{byte(i)}, common.Address{byte(i)}, common.Hash{byte(i)}, big.NewInt(i), uint64(i), []byte{byte(i)})
 	}
 	b := newblock(0)
 	b.Header().Difficulty = nil // check if nil as *big.Int decodes as 0

logger/glog/glog.go

@@ -128,6 +128,10 @@ func GetTraceLocation() *TraceLocation {
 	return &logging.traceLocation
 }
 
+func GetVModule() *moduleSpec {
+	return &logging.vmodule
+}
+
 // get returns the value of the severity.
 func (s *severity) get() severity {
 	return severity(atomic.LoadInt32((*int32)(s)))

logger/glog/glog_file.go

@@ -40,6 +40,10 @@ var logDirs []string
 //var logDir = flag.String("log_dir", "", "If non-empty, write log files in this directory")
 var logDir *string = new(string)
 
+func SetLogDir(str string) {
+	*logDir = str
+}
+
 func createLogDirs() {
 	if *logDir != "" {
 		logDirs = append(logDirs, *logDir)

miner/worker.go

@@ -276,12 +276,12 @@ gasLimit:
 			self.chain.TxState().RemoveNonce(from, tx.Nonce())
 			remove = append(remove, tx)
 
-			if glog.V(logger.Info) {
+			if glog.V(logger.Debug) {
 				glog.Infof("TX (%x) failed, will be removed: %v\n", tx.Hash().Bytes()[:4], err)
+				glog.Infoln(tx)
 			}
-			glog.V(logger.Debug).Infoln(tx)
 		case state.IsGasLimitErr(err):
-			glog.V(logger.Info).Infof("Gas limit reached for block. %d TXs included in this block\n", i)
+			glog.V(logger.Debug).Infof("Gas limit reached for block. %d TXs included in this block\n", i)
 			// Break on gas limit
 			break gasLimit
 		default:
@@ -300,15 +300,20 @@ gasLimit:
 		}
 
 		if err := self.commitUncle(uncle.Header()); err != nil {
-			glog.V(logger.Info).Infof("Bad uncle found and will be removed (%x)\n", hash[:4])
+			glog.V(logger.Debug).Infof("Bad uncle found and will be removed (%x)\n", hash[:4])
 			glog.V(logger.Debug).Infoln(uncle)
 			badUncles = append(badUncles, hash)
 		} else {
-			glog.V(logger.Info).Infof("commiting %x as uncle\n", hash[:4])
+			glog.V(logger.Debug).Infof("commiting %x as uncle\n", hash[:4])
 			uncles = append(uncles, uncle.Header())
 		}
 	}
+
+	// We only care about logging if we're actually mining
+	if atomic.LoadInt64(&self.mining) == 1 {
 		glog.V(logger.Info).Infof("commit new work on block %v with %d txs & %d uncles\n", self.current.block.Number(), tcount, len(uncles))
+	}
+
 	for _, hash := range badUncles {
 		delete(self.possibleUncles, hash)
 	}

p2p/discover/udp.go

@@ -10,12 +10,11 @@ import (
 
 	"github.com/ethereum/go-ethereum/crypto"
 	"github.com/ethereum/go-ethereum/logger"
+	"github.com/ethereum/go-ethereum/logger/glog"
 	"github.com/ethereum/go-ethereum/p2p/nat"
 	"github.com/ethereum/go-ethereum/rlp"
 )
 
-var log = logger.NewLogger("P2P Discovery")
-
 const Version = 3
 
 // Errors
@@ -155,7 +154,7 @@ func ListenUDP(priv *ecdsa.PrivateKey, laddr string, natm nat.Interface) (*Table
 		return nil, err
 	}
 	tab, _ := newUDP(priv, conn, natm)
-	log.Infoln("Listening,", tab.self)
+	glog.V(logger.Info).Infoln("Listening,", tab.self)
 	return tab, nil
 }
 
@@ -336,9 +335,9 @@ func (t *udp) send(toaddr *net.UDPAddr, ptype byte, req interface{}) error {
 	if err != nil {
 		return err
 	}
-	log.DebugDetailf(">>> %v %T %v\n", toaddr, req, req)
+	glog.V(logger.Detail).Infof(">>> %v %T %v\n", toaddr, req, req)
 	if _, err = t.conn.WriteToUDP(packet, toaddr); err != nil {
-		log.DebugDetailln("UDP send failed:", err)
+		glog.V(logger.Detail).Infoln("UDP send failed:", err)
 	}
 	return err
 }
@@ -348,13 +347,13 @@ func encodePacket(priv *ecdsa.PrivateKey, ptype byte, req interface{}) ([]byte,
 	b.Write(headSpace)
 	b.WriteByte(ptype)
 	if err := rlp.Encode(b, req); err != nil {
-		log.Errorln("error encoding packet:", err)
+		glog.V(logger.Error).Infoln("error encoding packet:", err)
 		return nil, err
 	}
 	packet := b.Bytes()
 	sig, err := crypto.Sign(crypto.Sha3(packet[headSize:]), priv)
 	if err != nil {
-		log.Errorln("could not sign packet:", err)
+		glog.V(logger.Error).Infoln("could not sign packet:", err)
 		return nil, err
 	}
 	copy(packet[macSize:], sig)
@@ -376,13 +375,13 @@ func (t *udp) readLoop() {
 		}
 		packet, fromID, hash, err := decodePacket(buf[:nbytes])
 		if err != nil {
-			log.Debugf("Bad packet from %v: %v\n", from, err)
+			glog.V(logger.Debug).Infof("Bad packet from %v: %v\n", from, err)
 			continue
 		}
-		log.DebugDetailf("<<< %v %T %v\n", from, packet, packet)
+		glog.V(logger.Detail).Infof("<<< %v %T %v\n", from, packet, packet)
 		go func() {
 			if err := packet.handle(t, from, fromID, hash); err != nil {
-				log.Debugf("error handling %T from %v: %v", packet, from, err)
+				glog.V(logger.Debug).Infof("error handling %T from %v: %v", packet, from, err)
 			}
 		}()
 	}

p2p/nat/nat.go

@@ -10,11 +10,10 @@ import (
 	"time"
 
 	"github.com/ethereum/go-ethereum/logger"
+	"github.com/ethereum/go-ethereum/logger/glog"
 	"github.com/jackpal/go-nat-pmp"
 )
 
-var log = logger.NewLogger("P2P NAT")
-
 // An implementation of nat.Interface can map local ports to ports
 // accessible from the Internet.
 type Interface interface {
@@ -87,12 +86,12 @@ func Map(m Interface, c chan struct{}, protocol string, extport, intport int, na
 	refresh := time.NewTimer(mapUpdateInterval)
 	defer func() {
 		refresh.Stop()
-		log.Debugf("Deleting port mapping: %s %d -> %d (%s) using %s\n", protocol, extport, intport, name, m)
+		glog.V(logger.Debug).Infof("Deleting port mapping: %s %d -> %d (%s) using %s\n", protocol, extport, intport, name, m)
 		m.DeleteMapping(protocol, extport, intport)
 	}()
-	log.Debugf("add mapping: %s %d -> %d (%s) using %s\n", protocol, extport, intport, name, m)
+	glog.V(logger.Debug).Infof("add mapping: %s %d -> %d (%s) using %s\n", protocol, extport, intport, name, m)
 	if err := m.AddMapping(protocol, intport, extport, name, mapTimeout); err != nil {
-		log.Errorf("mapping error: %v\n", err)
+		glog.V(logger.Error).Infof("mapping error: %v\n", err)
 	}
 	for {
 		select {
@@ -101,9 +100,9 @@ func Map(m Interface, c chan struct{}, protocol string, extport, intport int, na
 				return
 			}
 		case <-refresh.C:
-			log.DebugDetailf("refresh mapping: %s %d -> %d (%s) using %s\n", protocol, extport, intport, name, m)
+			glog.V(logger.Detail).Infof("refresh mapping: %s %d -> %d (%s) using %s\n", protocol, extport, intport, name, m)
 			if err := m.AddMapping(protocol, intport, extport, name, mapTimeout); err != nil {
-				log.Errorf("mapping error: %v\n", err)
+				glog.V(logger.Error).Infof("mapping error: %v\n", err)
 			}
 			refresh.Reset(mapUpdateInterval)
 		}

p2p/server.go

@@ -10,6 +10,7 @@ import (
 	"time"
 
 	"github.com/ethereum/go-ethereum/logger"
+	"github.com/ethereum/go-ethereum/logger/glog"
 	"github.com/ethereum/go-ethereum/p2p/discover"
 	"github.com/ethereum/go-ethereum/p2p/nat"
 	"github.com/ethereum/go-ethereum/rlp"
@@ -29,7 +30,6 @@ const (
 	frameWriteTimeout = 5 * time.Second
 )
 
-var srvlog = logger.NewLogger("P2P Server")
 var srvjslog = logger.NewJsonLogger()
 
 // Server manages all peer connections.
@@ -161,7 +161,7 @@ func (srv *Server) Start() (err error) {
 	if srv.running {
 		return errors.New("server already running")
 	}
-	srvlog.Infoln("Starting Server")
+	glog.V(logger.Info).Infoln("Starting Server")
 
 	// static fields
 	if srv.PrivateKey == nil {
@@ -204,7 +204,7 @@ func (srv *Server) Start() (err error) {
 		go srv.dialLoop()
 	}
 	if srv.NoDial && srv.ListenAddr == "" {
-		srvlog.Warnln("I will be kind-of useless, neither dialing nor listening.")
+		glog.V(logger.Warn).Infoln("I will be kind-of useless, neither dialing nor listening.")
 	}
 
 	srv.running = true
@@ -242,7 +242,7 @@ func (srv *Server) Stop() {
 	srv.running = false
 	srv.lock.Unlock()
 
-	srvlog.Infoln("Stopping Server")
+	glog.V(logger.Info).Infoln("Stopping Server")
 	srv.ntab.Close()
 	if srv.listener != nil {
 		// this unblocks listener Accept
@@ -263,13 +263,13 @@ func (srv *Server) Stop() {
 // main loop for adding connections via listening
 func (srv *Server) listenLoop() {
 	defer srv.loopWG.Done()
-	srvlog.Infoln("Listening on", srv.listener.Addr())
+	glog.V(logger.Info).Infoln("Listening on", srv.listener.Addr())
 	for {
 		conn, err := srv.listener.Accept()
 		if err != nil {
 			return
 		}
-		srvlog.Debugf("Accepted conn %v\n", conn.RemoteAddr())
+		glog.V(logger.Debug).Infof("Accepted conn %v\n", conn.RemoteAddr())
 		srv.peerWG.Add(1)
 		go srv.startPeer(conn, nil)
 	}
@@ -328,10 +328,10 @@ func (srv *Server) dialLoop() {
 
 func (srv *Server) dialNode(dest *discover.Node) {
 	addr := &net.TCPAddr{IP: dest.IP, Port: dest.TCPPort}
-	srvlog.Debugf("Dialing %v\n", dest)
+	glog.V(logger.Debug).Infof("Dialing %v\n", dest)
 	conn, err := srv.Dialer.Dial("tcp", addr.String())
 	if err != nil {
-		srvlog.DebugDetailf("dial error: %v", err)
+		glog.V(logger.Detail).Infof("dial error: %v", err)
 		return
 	}
 	srv.startPeer(conn, dest)
@@ -365,7 +365,7 @@ func (srv *Server) startPeer(fd net.Conn, dest *discover.Node) {
 	conn, err := srv.setupFunc(fd, srv.PrivateKey, srv.ourHandshake, dest)
 	if err != nil {
 		fd.Close()
-		srvlog.Debugf("Handshake with %v failed: %v", fd.RemoteAddr(), err)
+		glog.V(logger.Debug).Infof("Handshake with %v failed: %v", fd.RemoteAddr(), err)
 		return
 	}
 
@@ -375,12 +375,12 @@ func (srv *Server) startPeer(fd net.Conn, dest *discover.Node) {
 	}
 	p := newPeer(fd, conn, srv.Protocols)
 	if ok, reason := srv.addPeer(conn.ID, p); !ok {
-		srvlog.DebugDetailf("Not adding %v (%v)\n", p, reason)
+		glog.V(logger.Detail).Infof("Not adding %v (%v)\n", p, reason)
 		p.politeDisconnect(reason)
 		return
 	}
 
-	srvlog.Debugf("Added %v\n", p)
+	glog.V(logger.Debug).Infof("Added %v\n", p)
 	srvjslog.LogJson(&logger.P2PConnected{
 		RemoteId:            fmt.Sprintf("%x", conn.ID[:]),
 		RemoteAddress:       fd.RemoteAddr().String(),
@@ -394,7 +394,7 @@ func (srv *Server) startPeer(fd net.Conn, dest *discover.Node) {
 	discreason := p.run()
 	srv.removePeer(p)
 
-	srvlog.Debugf("Removed %v (%v)\n", p, discreason)
+	glog.V(logger.Debug).Infof("Removed %v (%v)\n", p, discreason)
 	srvjslog.LogJson(&logger.P2PDisconnected{
 		RemoteId:       fmt.Sprintf("%x", conn.ID[:]),
 		NumConnections: srv.PeerCount(),

whisper/whisper.go

@@ -11,6 +11,7 @@ import (
 	"github.com/ethereum/go-ethereum/crypto/ecies"
 	"github.com/ethereum/go-ethereum/event/filter"
 	"github.com/ethereum/go-ethereum/logger"
+	"github.com/ethereum/go-ethereum/logger/glog"
 	"github.com/ethereum/go-ethereum/p2p"
 	"gopkg.in/fatih/set.v0"
 )
@@ -29,8 +30,6 @@ type MessageEvent struct {
 
 const DefaultTtl = 50 * time.Second
 
-var wlogger = logger.NewLogger("SHH")
-
 type Whisper struct {
 	protocol p2p.Protocol
 	filters  *filter.Filters
@@ -70,7 +69,7 @@ func (self *Whisper) Version() uint {
 }
 
 func (self *Whisper) Start() {
-	wlogger.Infoln("Whisper started")
+	glog.V(logger.Info).Infoln("Whisper started")
 	go self.update()
 }
 
@@ -195,7 +194,7 @@ func (self *Whisper) add(envelope *Envelope) error {
 		go self.postEvent(envelope)
 	}
 
-	wlogger.DebugDetailf("added whisper envelope %x\n", envelope)
+	glog.V(logger.Detail).Infof("added whisper envelope %x\n", envelope)
 
 	return nil
 }