all: update light logs (and a few others) to the new model

8 files changed, 211 insertions, 214 deletions

diff --git a/les/backend.go b/les/backend.go
index 94563c29f..e96fc9df0 100644
--- a/les/backend.go
+++ b/les/backend.go
@@ -187,7 +187,7 @@ func (s *LightEthereum) Protocols() []p2p.Protocol {
 // Start implements node.Service, starting all internal goroutines needed by the
 // Ethereum protocol implementation.
 func (s *LightEthereum) Start(srvr *p2p.Server) error {
-	log.Info(fmt.Sprintf("WARNING: light client mode is an experimental feature"))
+	log.Warn("Light client mode is an experimental feature")
 	s.netRPCService = ethapi.NewPublicNetAPI(srvr, s.netVersionId)
 	s.protocolManager.Start(srvr)
 	return nil
diff --git a/les/fetcher.go b/les/fetcher.go
index dcaea87e8..f9e517d25 100644
--- a/les/fetcher.go
+++ b/les/fetcher.go
@@ -18,7 +18,6 @@
 package les
 
 import (
-	"fmt"
 	"math/big"
 	"sync"
 	"time"
@@ -174,7 +173,7 @@ func (f *lightFetcher) syncLoop() {
 			f.reqMu.Unlock()
 			if ok {
 				f.pm.serverPool.adjustResponseTime(req.peer.poolEntry, time.Duration(mclock.Now()-req.sent), true)
-				log.Debug(fmt.Sprintf("hard timeout by peer %v", req.peer.id))
+				req.peer.Log().Debug("Fetching data timed out hard")
 				go f.pm.removePeer(req.peer.id)
 			}
 		case resp := <-f.deliverChn:
@@ -192,13 +191,13 @@ func (f *lightFetcher) syncLoop() {
 			}
 			f.lock.Lock()
 			if !ok || !(f.syncing || f.processResponse(req, resp)) {
-				log.Debug(fmt.Sprintf("failed processing response by peer %v", resp.peer.id))
+				resp.peer.Log().Debug("Failed processing response")
 				go f.pm.removePeer(resp.peer.id)
 			}
 			f.lock.Unlock()
 		case p := <-f.syncDone:
 			f.lock.Lock()
-			log.Debug(fmt.Sprintf("done synchronising with peer %v", p.id))
+			p.Log().Debug("Done synchronising with peer")
 			f.checkSyncedHeaders(p)
 			f.syncing = false
 			f.lock.Unlock()
@@ -239,17 +238,17 @@ func (f *lightFetcher) removePeer(p *peer) {
 func (f *lightFetcher) announce(p *peer, head *announceData) {
 	f.lock.Lock()
 	defer f.lock.Unlock()
-	log.Debug(fmt.Sprintf("received announce from peer %v  #%d  %016x  reorg: %d", p.id, head.Number, head.Hash[:8], head.ReorgDepth))
+	p.Log().Debug("Received new announcement", "number", head.Number, "hash", head.Hash, "reorg", head.ReorgDepth)
 
 	fp := f.peers[p]
 	if fp == nil {
-		log.Debug(fmt.Sprintf("announce: unknown peer"))
+		p.Log().Debug("Announcement from unknown peer")
 		return
 	}
 
 	if fp.lastAnnounced != nil && head.Td.Cmp(fp.lastAnnounced.td) <= 0 {
 		// announced tds should be strictly monotonic
-		log.Debug(fmt.Sprintf("non-monotonic Td from peer %v", p.id))
+		p.Log().Debug("Received non-monotonic td", "current", head.Td, "previous", fp.lastAnnounced.td)
 		go f.pm.removePeer(p.id)
 		return
 	}
@@ -355,14 +354,14 @@ func (f *lightFetcher) peerHasBlock(p *peer, hash common.Hash, number uint64) bo
 func (f *lightFetcher) request(p *peer, reqID uint64, n *fetcherTreeNode, amount uint64) (uint64, bool) {
 	fp := f.peers[p]
 	if fp == nil {
-		log.Debug(fmt.Sprintf("request: unknown peer"))
+		p.Log().Debug("Requesting from unknown peer")
 		p.fcServer.DeassignRequest(reqID)
 		return 0, false
 	}
 	if fp.bestConfirmed == nil || fp.root == nil || !f.checkKnownNode(p, fp.root) {
 		f.syncing = true
 		go func() {
-			log.Debug(fmt.Sprintf("synchronising with peer %v", p.id))
+			p.Log().Debug("Synchronisation started")
 			f.pm.synchronise(p)
 			f.syncDone <- p
 		}()
@@ -457,7 +456,7 @@ func (f *lightFetcher) deliverHeaders(peer *peer, reqID uint64, headers []*types
 // processResponse processes header download request responses, returns true if successful
 func (f *lightFetcher) processResponse(req fetchRequest, resp fetchResponse) bool {
 	if uint64(len(resp.headers)) != req.amount || resp.headers[0].Hash() != req.hash {
-		log.Debug(fmt.Sprintf("response mismatch %v %016x != %v %016x", len(resp.headers), resp.headers[0].Hash().Bytes()[:8], req.amount, req.hash[:8]))
+		req.peer.Log().Debug("Response content mismatch", "requested", len(resp.headers), "reqfrom", resp.headers[0], "delivered", req.amount, "delfrom", req.hash)
 		return false
 	}
 	headers := make([]*types.Header, req.amount)
@@ -468,14 +467,14 @@ func (f *lightFetcher) processResponse(req fetchRequest, resp fetchResponse) boo
 		if err == core.BlockFutureErr {
 			return true
 		}
-		log.Debug(fmt.Sprintf("InsertHeaderChain error: %v", err))
+		log.Debug("Failed to insert header chain", "err", err)
 		return false
 	}
 	tds := make([]*big.Int, len(headers))
 	for i, header := range headers {
 		td := f.chain.GetTd(header.Hash(), header.Number.Uint64())
 		if td == nil {
-			log.Debug(fmt.Sprintf("TD not found for header %v of %v", i+1, len(headers)))
+			log.Debug("Total difficulty not found for header", "index", i+1, "number", header.Number, "hash", header.Hash())
 			return false
 		}
 		tds[i] = td
@@ -490,7 +489,7 @@ func (f *lightFetcher) newHeaders(headers []*types.Header, tds []*big.Int) {
 	var maxTd *big.Int
 	for p, fp := range f.peers {
 		if !f.checkAnnouncedHeaders(fp, headers, tds) {
-			log.Debug(fmt.Sprintf("announce inconsistency by peer %v", p.id))
+			p.Log().Debug("Inconsistent announcement")
 			go f.pm.removePeer(p.id)
 		}
 		if fp.confirmedTd != nil && (maxTd == nil || maxTd.Cmp(fp.confirmedTd) > 0) {
@@ -576,7 +575,7 @@ func (f *lightFetcher) checkAnnouncedHeaders(fp *fetcherPeerInfo, headers []*typ
 func (f *lightFetcher) checkSyncedHeaders(p *peer) {
 	fp := f.peers[p]
 	if fp == nil {
-		log.Debug(fmt.Sprintf("checkSyncedHeaders: unknown peer"))
+		p.Log().Debug("Unknown peer to check sync headers")
 		return
 	}
 	n := fp.lastAnnounced
@@ -589,7 +588,7 @@ func (f *lightFetcher) checkSyncedHeaders(p *peer) {
 	}
 	// now n is the latest downloaded header after syncing
 	if n == nil {
-		log.Debug(fmt.Sprintf("synchronisation failed with peer %v", p.id))
+		p.Log().Debug("Synchronisation failed")
 		go f.pm.removePeer(p.id)
 	} else {
 		header := f.chain.GetHeader(n.hash, n.number)
@@ -610,12 +609,12 @@ func (f *lightFetcher) checkKnownNode(p *peer, n *fetcherTreeNode) bool {
 
 	fp := f.peers[p]
 	if fp == nil {
-		log.Debug(fmt.Sprintf("checkKnownNode: unknown peer"))
+		p.Log().Debug("Unknown peer to check known nodes")
 		return false
 	}
 	header := f.chain.GetHeader(n.hash, n.number)
 	if !f.checkAnnouncedHeaders(fp, []*types.Header{header}, []*big.Int{td}) {
-		log.Debug(fmt.Sprintf("announce inconsistency by peer %v", p.id))
+		p.Log().Debug("Inconsistent announcement")
 		go f.pm.removePeer(p.id)
 	}
 	if fp.confirmedTd != nil {
@@ -700,7 +699,7 @@ func (f *lightFetcher) checkUpdateStats(p *peer, newEntry *updateStatsEntry) {
 	now := mclock.Now()
 	fp := f.peers[p]
 	if fp == nil {
-		log.Debug(fmt.Sprintf("checkUpdateStats: unknown peer"))
+		p.Log().Debug("Unknown peer to check update stats")
 		return
 	}
 	if newEntry != nil && fp.firstUpdateStats == nil {
diff --git a/les/handler.go b/les/handler.go
index 1fdb7c43f..4271da8b8 100644
--- a/les/handler.go
+++ b/les/handler.go
@@ -198,7 +198,6 @@ func NewProtocolManager(chainConfig *params.ChainConfig, lightSync bool, network
 	}
 
 	if lightSync {
-		log.Debug(fmt.Sprintf("LES: create downloader"))
 		manager.downloader = downloader.New(downloader.LightSync, chainDb, manager.eventMux, blockchain.HasHeader, nil, blockchain.GetHeaderByHash,
 			nil, blockchain.CurrentHeader, nil, nil, nil, blockchain.GetTdByHash,
 			blockchain.InsertHeaderChain, nil, nil, blockchain.Rollback, removePeer)
@@ -225,16 +224,13 @@ func (pm *ProtocolManager) removePeer(id string) {
 	if peer == nil {
 		return
 	}
+	log.Debug("Removing light Ethereum peer", "peer", id)
 	if err := pm.peers.Unregister(id); err != nil {
 		if err == errNotRegistered {
 			return
 		}
-		log.Error(fmt.Sprint("Removal failed:", err))
 	}
-	log.Debug(fmt.Sprint("Removing peer", id))
-
 	// Unregister the peer from the downloader and Ethereum peer set
-	log.Debug(fmt.Sprintf("LES: unregister peer %v", id))
 	if pm.lightSync {
 		pm.downloader.UnregisterPeer(id)
 		if pm.txrelay != nil {
@@ -267,9 +263,11 @@ func (pm *ProtocolManager) Start(srvr *p2p.Server) {
 	} else {
 		if topicDisc != nil {
 			go func() {
-				log.Info(fmt.Sprint("Starting registering topic", string(lesTopic)))
+				logger := log.New("topic", lesTopic)
+				logger.Info("Starting topic registration")
+				defer logger.Info("Terminated topic registration")
+
 				topicDisc.RegisterTopic(lesTopic, pm.quitSync)
-				log.Info(fmt.Sprint("Stopped registering topic", string(lesTopic)))
 			}()
 		}
 		go func() {
@@ -282,7 +280,7 @@ func (pm *ProtocolManager) Start(srvr *p2p.Server) {
 func (pm *ProtocolManager) Stop() {
 	// Showing a log message. During download / process this could actually
 	// take between 5 to 10 seconds and therefor feedback is required.
-	log.Info(fmt.Sprint("Stopping light ethereum protocol handler..."))
+	log.Info("Stopping light Ethereum protocol")
 
 	// Quit the sync loop.
 	// After this send has completed, no new peers will be accepted.
@@ -299,7 +297,7 @@ func (pm *ProtocolManager) Stop() {
 	// Wait for any process action
 	pm.wg.Wait()
 
-	log.Info(fmt.Sprint("Light ethereum protocol handler stopped"))
+	log.Info("Light Ethereum protocol stopped")
 }
 
 func (pm *ProtocolManager) newPeer(pv, nv int, p *p2p.Peer, rw p2p.MsgReadWriter) *peer {
@@ -309,22 +307,21 @@ func (pm *ProtocolManager) newPeer(pv, nv int, p *p2p.Peer, rw p2p.MsgReadWriter
 // handle is the callback invoked to manage the life cycle of a les peer. When
 // this function terminates, the peer is disconnected.
 func (pm *ProtocolManager) handle(p *peer) error {
-	log.Debug(fmt.Sprintf("%v: peer connected [%s]", p, p.Name()))
+	p.Log().Debug("Light Ethereum peer connected", "name", p.Name())
 
 	// Execute the LES handshake
 	td, head, genesis := pm.blockchain.Status()
 	headNum := core.GetBlockNumber(pm.chainDb, head)
 	if err := p.Handshake(td, head, headNum, genesis, pm.server); err != nil {
-		log.Debug(fmt.Sprintf("%v: handshake failed: %v", p, err))
+		p.Log().Debug("Light Ethereum handshake failed", "err", err)
 		return err
 	}
 	if rw, ok := p.rw.(*meteredMsgReadWriter); ok {
 		rw.Init(p.version)
 	}
 	// Register the peer locally
-	log.Trace(fmt.Sprintf("%v: adding peer", p))
 	if err := pm.peers.Register(p); err != nil {
-		log.Error(fmt.Sprintf("%v: addition failed: %v", p, err))
+		p.Log().Error("Light Ethereum peer registration failed", "err", err)
 		return err
 	}
 	defer func() {
@@ -333,9 +330,7 @@ func (pm *ProtocolManager) handle(p *peer) error {
 		}
 		pm.removePeer(p.id)
 	}()
-
 	// Register the peer in the downloader. If the downloader considers it banned, we disconnect
-	log.Debug(fmt.Sprintf("LES: register peer %v", p.id))
 	if pm.lightSync {
 		requestHeadersByHash := func(origin common.Hash, amount int, skip int, reverse bool) error {
 			reqID := getNextReqID()
@@ -389,7 +384,7 @@ func (pm *ProtocolManager) handle(p *peer) error {
 	// main loop. handle incoming messages.
 	for {
 		if err := pm.handleMsg(p); err != nil {
-			log.Debug(fmt.Sprintf("%v: message handling failed: %v", p, err))
+			p.Log().Debug("Light Ethereum message handling failed", "err", err)
 			return err
 		}
 	}
@@ -405,8 +400,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 	if err != nil {
 		return err
 	}
-
-	log.Debug(fmt.Sprint("msg:", msg.Code, msg.Size))
+	p.Log().Trace("Light Ethereum message arrived", "code", msg.Code, "bytes", msg.Size)
 
 	costs := p.fcCosts[msg.Code]
 	reject := func(reqCnt, maxCnt uint64) bool {
@@ -419,7 +413,8 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 			cost = pm.server.defParams.BufLimit
 		}
 		if cost > bufValue {
-			log.Error(fmt.Sprintf("Request from %v came %v too early", p.id, time.Duration((cost-bufValue)*1000000/pm.server.defParams.MinRecharge)))
+			recharge := time.Duration((cost - bufValue) * 1000000 / pm.server.defParams.MinRecharge)
+			p.Log().Error("Request came too early", "recharge", common.PrettyDuration(recharge))
 			return true
 		}
 		return false
@@ -435,25 +430,25 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 	// Handle the message depending on its contents
 	switch msg.Code {
 	case StatusMsg:
-		log.Debug(fmt.Sprintf("<=== StatusMsg from peer %v", p.id))
+		p.Log().Trace("Received status message")
 		// Status messages should never arrive after the handshake
 		return errResp(ErrExtraStatusMsg, "uncontrolled status message")
 
 	// Block header query, collect the requested headers and reply
 	case AnnounceMsg:
-		log.Debug(fmt.Sprintf("<=== AnnounceMsg from peer %v:", p.id))
+		p.Log().Trace("Received announce message")
 
 		var req announceData
 		if err := msg.Decode(&req); err != nil {
 			return errResp(ErrDecode, "%v: %v", msg, err)
 		}
-		log.Trace(fmt.Sprint("AnnounceMsg:", req.Number, req.Hash, req.Td, req.ReorgDepth))
+		p.Log().Trace("Announce message content", "number", req.Number, "hash", req.Hash, "td", req.Td, "reorg", req.ReorgDepth)
 		if pm.fetcher != nil {
 			pm.fetcher.announce(p, &req)
 		}
 
 	case GetBlockHeadersMsg:
-		log.Debug(fmt.Sprintf("<=== GetBlockHeadersMsg from peer %v", p.id))
+		p.Log().Trace("Received block header request")
 		// Decode the complex header query
 		var req struct {
 			ReqID uint64
@@ -538,7 +533,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 			return errResp(ErrUnexpectedResponse, "")
 		}
 
-		log.Debug(fmt.Sprintf("<=== BlockHeadersMsg from peer %v", p.id))
+		p.Log().Trace("Received block header response message")
 		// A batch of headers arrived to one of our previous requests
 		var resp struct {
 			ReqID, BV uint64
@@ -558,7 +553,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 		}
 
 	case GetBlockBodiesMsg:
-		log.Debug(fmt.Sprintf("<===  GetBlockBodiesMsg from peer %v", p.id))
+		p.Log().Trace("Received block bodies request")
 		// Decode the retrieval message
 		var req struct {
 			ReqID  uint64
@@ -595,7 +590,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 			return errResp(ErrUnexpectedResponse, "")
 		}
 
-		log.Debug(fmt.Sprintf("<===  BlockBodiesMsg from peer %v", p.id))
+		p.Log().Trace("Received block bodies response")
 		// A batch of block bodies arrived to one of our previous requests
 		var resp struct {
 			ReqID, BV uint64
@@ -612,7 +607,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 		}
 
 	case GetCodeMsg:
-		log.Debug(fmt.Sprintf("<===  GetCodeMsg from peer %v", p.id))
+		p.Log().Trace("Received code request")
 		// Decode the retrieval message
 		var req struct {
 			ReqID uint64
@@ -656,7 +651,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 			return errResp(ErrUnexpectedResponse, "")
 		}
 
-		log.Debug(fmt.Sprintf("<=== CodeMsg from peer %v", p.id))
+		p.Log().Trace("Received code response")
 		// A batch of node state data arrived to one of our previous requests
 		var resp struct {
 			ReqID, BV uint64
@@ -673,7 +668,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 		}
 
 	case GetReceiptsMsg:
-		log.Debug(fmt.Sprintf("<===  GetReceiptsMsg from peer %v", p.id))
+		p.Log().Trace("Received receipts request")
 		// Decode the retrieval message
 		var req struct {
 			ReqID  uint64
@@ -704,7 +699,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 			}
 			// If known, encode and queue for response packet
 			if encoded, err := rlp.EncodeToBytes(results); err != nil {
-				log.Error(fmt.Sprintf("failed to encode receipt: %v", err))
+				log.Error("Failed to encode receipt", "err", err)
 			} else {
 				receipts = append(receipts, encoded)
 				bytes += len(encoded)
@@ -719,7 +714,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 			return errResp(ErrUnexpectedResponse, "")
 		}
 
-		log.Debug(fmt.Sprintf("<=== ReceiptsMsg from peer %v", p.id))
+		p.Log().Trace("Received receipts response")
 		// A batch of receipts arrived to one of our previous requests
 		var resp struct {
 			ReqID, BV uint64
@@ -736,7 +731,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 		}
 
 	case GetProofsMsg:
-		log.Debug(fmt.Sprintf("<=== GetProofsMsg from peer %v", p.id))
+		p.Log().Trace("Received proofs request")
 		// Decode the retrieval message
 		var req struct {
 			ReqID uint64
@@ -786,7 +781,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 			return errResp(ErrUnexpectedResponse, "")
 		}
 
-		log.Debug(fmt.Sprintf("<=== ProofsMsg from peer %v", p.id))
+		p.Log().Trace("Received proofs response")
 		// A batch of merkle proofs arrived to one of our previous requests
 		var resp struct {
 			ReqID, BV uint64
@@ -803,7 +798,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 		}
 
 	case GetHeaderProofsMsg:
-		log.Debug(fmt.Sprintf("<=== GetHeaderProofsMsg from peer %v", p.id))
+		p.Log().Trace("Received headers proof request")
 		// Decode the retrieval message
 		var req struct {
 			ReqID uint64
@@ -847,7 +842,7 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 			return errResp(ErrUnexpectedResponse, "")
 		}
 
-		log.Debug(fmt.Sprintf("<=== HeaderProofsMsg from peer %v", p.id))
+		p.Log().Trace("Received headers proof response")
 		var resp struct {
 			ReqID, BV uint64
 			Data      []ChtResp
@@ -884,14 +879,13 @@ func (pm *ProtocolManager) handleMsg(p *peer) error {
 		pm.server.fcCostStats.update(msg.Code, uint64(reqCnt), rcost)
 
 	default:
-		log.Debug(fmt.Sprintf("<=== unknown message with code %d from peer %v", msg.Code, p.id))
+		p.Log().Trace("Received unknown message", "code", msg.Code)
 		return errResp(ErrInvalidMsgCode, "%v", msg.Code)
 	}
 
 	if deliverMsg != nil {
 		return pm.odr.Deliver(p, deliverMsg)
 	}
-
 	return nil
 }
 
diff --git a/les/odr.go b/les/odr.go
index 78c7c1af4..afc894ab5 100644
--- a/les/odr.go
+++ b/les/odr.go
@@ -19,7 +19,6 @@ package les
 import (
 	"crypto/rand"
 	"encoding/binary"
-	"fmt"
 	"sync"
 	"time"
 
@@ -70,9 +69,8 @@ func (odr *LesOdr) Database() ethdb.Database {
 	return odr.db
 }
 
-// validatorFunc is a function that processes a message and returns true if
-// it was a meaningful answer to a given request
-type validatorFunc func(ethdb.Database, *Msg) bool
+// validatorFunc is a function that processes a message.
+type validatorFunc func(ethdb.Database, *Msg) error
 
 // sentReq is a request waiting for an answer that satisfies its valFunc
 type sentReq struct {
@@ -113,18 +111,19 @@ func (self *LesOdr) Deliver(peer *peer, msg *Msg) error {
 		return errResp(ErrUnexpectedResponse, "reqID = %v", msg.ReqID)
 	}
 
-	if req.valFunc(self.db, msg) {
-		close(delivered)
-		req.lock.Lock()
-		delete(req.sentTo, peer)
-		if req.answered != nil {
-			close(req.answered)
-			req.answered = nil
-		}
-		req.lock.Unlock()
-		return nil
+	if err := req.valFunc(self.db, msg); err != nil {
+		peer.Log().Warn("Invalid odr response", "err", err)
+		return errResp(ErrInvalidResponse, "reqID = %v", msg.ReqID)
+	}
+	close(delivered)
+	req.lock.Lock()
+	delete(req.sentTo, peer)
+	if req.answered != nil {
+		close(req.answered)
+		req.answered = nil
 	}
-	return errResp(ErrInvalidResponse, "reqID = %v", msg.ReqID)
+	req.lock.Unlock()
+	return nil
 }
 
 func (self *LesOdr) requestPeer(req *sentReq, peer *peer, delivered, timeout chan struct{}, reqWg *sync.WaitGroup) {
@@ -151,7 +150,7 @@ func (self *LesOdr) requestPeer(req *sentReq, peer *peer, delivered, timeout cha
 	select {
 	case <-delivered:
 	case <-time.After(hardRequestTimeout):
-		log.Debug(fmt.Sprintf("ODR hard request timeout from peer %v", peer.id))
+		peer.Log().Debug("Request timed out hard")
 		go self.removePeer(peer.id)
 	case <-self.stop:
 		return
@@ -237,7 +236,7 @@ func (self *LesOdr) Retrieve(ctx context.Context, req light.OdrRequest) (err err
 		// retrieved from network, store in db
 		req.StoreResult(self.db)
 	} else {
-		log.Debug(fmt.Sprintf("networkRequest  err = %v", err))
+		log.Debug("Failed to retrieve data from network", "err", err)
 	}
 	return
 }
diff --git a/les/odr_requests.go b/les/odr_requests.go
index 5321a68cb..53aced93c 100644
--- a/les/odr_requests.go
+++ b/les/odr_requests.go
@@ -19,8 +19,8 @@
 package les
 
 import (
-	"bytes"
 	"encoding/binary"
+	"errors"
 	"fmt"
 
 	"github.com/ethereum/go-ethereum/common"
@@ -34,11 +34,22 @@ import (
 	"github.com/ethereum/go-ethereum/trie"
 )
 
+var (
+	errInvalidMessageType  = errors.New("invalid message type")
+	errMultipleEntries     = errors.New("multiple response entries")
+	errHeaderUnavailable   = errors.New("header unavailable")
+	errTxHashMismatch      = errors.New("transaction hash mismatch")
+	errUncleHashMismatch   = errors.New("uncle hash mismatch")
+	errReceiptHashMismatch = errors.New("receipt hash mismatch")
+	errDataHashMismatch    = errors.New("data hash mismatch")
+	errCHTHashMismatch     = errors.New("cht hash mismatch")
+)
+
 type LesOdrRequest interface {
 	GetCost(*peer) uint64
 	CanSend(*peer) bool
 	Request(uint64, *peer) error
-	Valid(ethdb.Database, *Msg) bool // if true, keeps the retrieved object
+	Valid(ethdb.Database, *Msg) error // if true, keeps the retrieved object
 }
 
 func LesRequest(req light.OdrRequest) LesOdrRequest {
@@ -63,59 +74,55 @@ type BlockRequest light.BlockRequest
 
 // GetCost returns the cost of the given ODR request according to the serving
 // peer's cost table (implementation of LesOdrRequest)
-func (self *BlockRequest) GetCost(peer *peer) uint64 {
+func (r *BlockRequest) GetCost(peer *peer) uint64 {
 	return peer.GetRequestCost(GetBlockBodiesMsg, 1)
 }
 
 // CanSend tells if a certain peer is suitable for serving the given request
-func (self *BlockRequest) CanSend(peer *peer) bool {
-	return peer.HasBlock(self.Hash, self.Number)
+func (r *BlockRequest) CanSend(peer *peer) bool {
+	return peer.HasBlock(r.Hash, r.Number)
 }
 
 // Request sends an ODR request to the LES network (implementation of LesOdrRequest)
-func (self *BlockRequest) Request(reqID uint64, peer *peer) error {
-	log.Debug(fmt.Sprintf("ODR: requesting body of block %08x from peer %v", self.Hash[:4], peer.id))
-	return peer.RequestBodies(reqID, self.GetCost(peer), []common.Hash{self.Hash})
+func (r *BlockRequest) Request(reqID uint64, peer *peer) error {
+	peer.Log().Debug("Requesting block body", "hash", r.Hash)
+	return peer.RequestBodies(reqID, r.GetCost(peer), []common.Hash{r.Hash})
 }
 
 // Valid processes an ODR request reply message from the LES network
 // returns true and stores results in memory if the message was a valid reply
 // to the request (implementation of LesOdrRequest)
-func (self *BlockRequest) Valid(db ethdb.Database, msg *Msg) bool {
-	log.Debug(fmt.Sprintf("ODR: validating body of block %08x", self.Hash[:4]))
+func (r *BlockRequest) Valid(db ethdb.Database, msg *Msg) error {
+	log.Debug("Validating block body", "hash", r.Hash)
+
+	// Ensure we have a correct message with a single block body
 	if msg.MsgType != MsgBlockBodies {
-		log.Debug(fmt.Sprintf("ODR: invalid message type"))
-		return false
+		return errInvalidMessageType
 	}
 	bodies := msg.Obj.([]*types.Body)
 	if len(bodies) != 1 {
-		log.Debug(fmt.Sprintf("ODR: invalid number of entries: %d", len(bodies)))
-		return false
+		return errMultipleEntries
 	}
 	body := bodies[0]
-	header := core.GetHeader(db, self.Hash, self.Number)
+
+	// Retrieve our stored header and validate block content against it
+	header := core.GetHeader(db, r.Hash, r.Number)
 	if header == nil {
-		log.Debug(fmt.Sprintf("ODR: header not found for block %08x", self.Hash[:4]))
-		return false
+		return errHeaderUnavailable
 	}
-	txHash := types.DeriveSha(types.Transactions(body.Transactions))
-	if header.TxHash != txHash {
-		log.Debug(fmt.Sprintf("ODR: header.TxHash %08x does not match received txHash %08x", header.TxHash[:4], txHash[:4]))
-		return false
+	if header.TxHash != types.DeriveSha(types.Transactions(body.Transactions)) {
+		return errTxHashMismatch
 	}
-	uncleHash := types.CalcUncleHash(body.Uncles)
-	if header.UncleHash != uncleHash {
-		log.Debug(fmt.Sprintf("ODR: header.UncleHash %08x does not match received uncleHash %08x", header.UncleHash[:4], uncleHash[:4]))
-		return false
+	if header.UncleHash != types.CalcUncleHash(body.Uncles) {
+		return errUncleHashMismatch
 	}
+	// Validations passed, encode and store RLP
 	data, err := rlp.EncodeToBytes(body)
 	if err != nil {
-		log.Debug(fmt.Sprintf("ODR: body RLP encode error: %v", err))
-		return false
+		return err
 	}
-	self.Rlp = data
-	log.Debug(fmt.Sprintf("ODR: validation successful"))
-	return true
+	r.Rlp = data
+	return nil
 }
 
 // ReceiptsRequest is the ODR request type for block receipts by block hash
@@ -123,48 +130,48 @@ type ReceiptsRequest light.ReceiptsRequest
 
 // GetCost returns the cost of the given ODR request according to the serving
 // peer's cost table (implementation of LesOdrRequest)
-func (self *ReceiptsRequest) GetCost(peer *peer) uint64 {
+func (r *ReceiptsRequest) GetCost(peer *peer) uint64 {
 	return peer.GetRequestCost(GetReceiptsMsg, 1)
 }
 
 // CanSend tells if a certain peer is suitable for serving the given request
-func (self *ReceiptsRequest) CanSend(peer *peer) bool {
-	return peer.HasBlock(self.Hash, self.Number)
+func (r *ReceiptsRequest) CanSend(peer *peer) bool {
+	return peer.HasBlock(r.Hash, r.Number)
 }
 
 // Request sends an ODR request to the LES network (implementation of LesOdrRequest)
-func (self *ReceiptsRequest) Request(reqID uint64, peer *peer) error {
-	log.Debug(fmt.Sprintf("ODR: requesting receipts for block %08x from peer %v", self.Hash[:4], peer.id))
-	return peer.RequestReceipts(reqID, self.GetCost(peer), []common.Hash{self.Hash})
+func (r *ReceiptsRequest) Request(reqID uint64, peer *peer) error {
+	peer.Log().Debug("Requesting block receipts", "hash", r.Hash)
+	return peer.RequestReceipts(reqID, r.GetCost(peer), []common.Hash{r.Hash})
 }
 
 // Valid processes an ODR request reply message from the LES network
 // returns true and stores results in memory if the message was a valid reply
 // to the request (implementation of LesOdrRequest)
-func (self *ReceiptsRequest) Valid(db ethdb.Database, msg *Msg) bool {
-	log.Debug(fmt.Sprintf("ODR: validating receipts for block %08x", self.Hash[:4]))
+func (r *ReceiptsRequest) Valid(db ethdb.Database, msg *Msg) error {
+	log.Debug("Validating block receipts", "hash", r.Hash)
+
+	// Ensure we have a correct message with a single block receipt
 	if msg.MsgType != MsgReceipts {
-		log.Debug(fmt.Sprintf("ODR: invalid message type"))
-		return false
+		return errInvalidMessageType
 	}
 	receipts := msg.Obj.([]types.Receipts)
 	if len(receipts) != 1 {
-		log.Debug(fmt.Sprintf("ODR: invalid number of entries: %d", len(receipts)))
-		return false
+		return errMultipleEntries
 	}
-	hash := types.DeriveSha(receipts[0])
-	header := core.GetHeader(db, self.Hash, self.Number)
+	receipt := receipts[0]
+
+	// Retrieve our stored header and validate receipt content against it
+	header := core.GetHeader(db, r.Hash, r.Number)
 	if header == nil {
-		log.Debug(fmt.Sprintf("ODR: header not found for block %08x", self.Hash[:4]))
-		return false
+		return errHeaderUnavailable
 	}
-	if !bytes.Equal(header.ReceiptHash[:], hash[:]) {
-		log.Debug(fmt.Sprintf("ODR: header receipts hash %08x does not match calculated RLP hash %08x", header.ReceiptHash[:4], hash[:4]))
-		return false
+	if header.ReceiptHash != types.DeriveSha(receipt) {
+		return errReceiptHashMismatch
 	}
-	self.Receipts = receipts[0]
-	log.Debug(fmt.Sprintf("ODR: validation successful"))
-	return true
+	// Validations passed, store and return
+	r.Receipts = receipt
+	return nil
 }
 
 type ProofReq struct {
@@ -178,49 +185,46 @@ type TrieRequest light.TrieRequest
 
 // GetCost returns the cost of the given ODR request according to the serving
 // peer's cost table (implementation of LesOdrRequest)
-func (self *TrieRequest) GetCost(peer *peer) uint64 {
+func (r *TrieRequest) GetCost(peer *peer) uint64 {
 	return peer.GetRequestCost(GetProofsMsg, 1)
 }
 
 // CanSend tells if a certain peer is suitable for serving the given request
-func (self *TrieRequest) CanSend(peer *peer) bool {
-	return peer.HasBlock(self.Id.BlockHash, self.Id.BlockNumber)
+func (r *TrieRequest) CanSend(peer *peer) bool {
+	return peer.HasBlock(r.Id.BlockHash, r.Id.BlockNumber)
 }
 
 // Request sends an ODR request to the LES network (implementation of LesOdrRequest)
-func (self *TrieRequest) Request(reqID uint64, peer *peer) error {
-	log.Debug(fmt.Sprintf("ODR: requesting trie root %08x key %08x from peer %v", self.Id.Root[:4], self.Key[:4], peer.id))
+func (r *TrieRequest) Request(reqID uint64, peer *peer) error {
+	peer.Log().Debug("Requesting trie proof", "root", r.Id.Root, "key", r.Key)
 	req := &ProofReq{
-		BHash:  self.Id.BlockHash,
-		AccKey: self.Id.AccKey,
-		Key:    self.Key,
+		BHash:  r.Id.BlockHash,
+		AccKey: r.Id.AccKey,
+		Key:    r.Key,
 	}
-	return peer.RequestProofs(reqID, self.GetCost(peer), []*ProofReq{req})
+	return peer.RequestProofs(reqID, r.GetCost(peer), []*ProofReq{req})
 }
 
 // Valid processes an ODR request reply message from the LES network
 // returns true and stores results in memory if the message was a valid reply
 // to the request (implementation of LesOdrRequest)
-func (self *TrieRequest) Valid(db ethdb.Database, msg *Msg) bool {
-	log.Debug(fmt.Sprintf("ODR: validating trie root %08x key %08x", self.Id.Root[:4], self.Key[:4]))
+func (r *TrieRequest) Valid(db ethdb.Database, msg *Msg) error {
+	log.Debug("Validating trie proof", "root", r.Id.Root, "key", r.Key)
 
+	// Ensure we have a correct message with a single proof
 	if msg.MsgType != MsgProofs {
-		log.Debug(fmt.Sprintf("ODR: invalid message type"))
-		return false
+		return errInvalidMessageType
 	}
 	proofs := msg.Obj.([][]rlp.RawValue)
 	if len(proofs) != 1 {
-		log.Debug(fmt.Sprintf("ODR: invalid number of entries: %d", len(proofs)))
-		return false
+		return errMultipleEntries
 	}
-	_, err := trie.VerifyProof(self.Id.Root, self.Key, proofs[0])
-	if err != nil {
-		log.Debug(fmt.Sprintf("ODR: merkle proof verification error: %v", err))
-		return false
+	// Verify the proof and store if checks out
+	if _, err := trie.VerifyProof(r.Id.Root, r.Key, proofs[0]); err != nil {
+		return fmt.Errorf("merkle proof verification failed: %v", err)
 	}
-	self.Proof = proofs[0]
-	log.Debug(fmt.Sprintf("ODR: validation successful"))
-	return true
+	r.Proof = proofs[0]
+	return nil
 }
 
 type CodeReq struct {
@@ -233,47 +237,47 @@ type CodeRequest light.CodeRequest
 
 // GetCost returns the cost of the given ODR request according to the serving
 // peer's cost table (implementation of LesOdrRequest)
-func (self *CodeRequest) GetCost(peer *peer) uint64 {
+func (r *CodeRequest) GetCost(peer *peer) uint64 {
 	return peer.GetRequestCost(GetCodeMsg, 1)
 }
 
 // CanSend tells if a certain peer is suitable for serving the given request
-func (self *CodeRequest) CanSend(peer *peer) bool {
-	return peer.HasBlock(self.Id.BlockHash, self.Id.BlockNumber)
+func (r *CodeRequest) CanSend(peer *peer) bool {
+	return peer.HasBlock(r.Id.BlockHash, r.Id.BlockNumber)
 }
 
 // Request sends an ODR request to the LES network (implementation of LesOdrRequest)
-func (self *CodeRequest) Request(reqID uint64, peer *peer) error {
-	log.Debug(fmt.Sprintf("ODR: requesting node data for hash %08x from peer %v", self.Hash[:4], peer.id))
+func (r *CodeRequest) Request(reqID uint64, peer *peer) error {
+	peer.Log().Debug("Requesting code data", "hash", r.Hash)
 	req := &CodeReq{
-		BHash:  self.Id.BlockHash,
-		AccKey: self.Id.AccKey,
+		BHash:  r.Id.BlockHash,
+		AccKey: r.Id.AccKey,
 	}
-	return peer.RequestCode(reqID, self.GetCost(peer), []*CodeReq{req})
+	return peer.RequestCode(reqID, r.GetCost(peer), []*CodeReq{req})
 }
 
 // Valid processes an ODR request reply message from the LES network
 // returns true and stores results in memory if the message was a valid reply
 // to the request (implementation of LesOdrRequest)
-func (self *CodeRequest) Valid(db ethdb.Database, msg *Msg) bool {
-	log.Debug(fmt.Sprintf("ODR: validating node data for hash %08x", self.Hash[:4]))
+func (r *CodeRequest) Valid(db ethdb.Database, msg *Msg) error {
+	log.Debug("Validating code data", "hash", r.Hash)
+
+	// Ensure we have a correct message with a single code element
 	if msg.MsgType != MsgCode {
-		log.Debug(fmt.Sprintf("ODR: invalid message type"))
-		return false
+		return errInvalidMessageType
 	}
 	reply := msg.Obj.([][]byte)
 	if len(reply) != 1 {
-		log.Debug(fmt.Sprintf("ODR: invalid number of entries: %d", len(reply)))
-		return false
+		return errMultipleEntries
 	}
 	data := reply[0]
-	if hash := crypto.Keccak256Hash(data); self.Hash != hash {
-		log.Debug(fmt.Sprintf("ODR: requested hash %08x does not match received data hash %08x", self.Hash[:4], hash[:4]))
-		return false
+
+	// Verify the data and store if checks out
+	if hash := crypto.Keccak256Hash(data); r.Hash != hash {
+		return errDataHashMismatch
 	}
-	self.Data = data
-	log.Debug(fmt.Sprintf("ODR: validation successful"))
-	return true
+	r.Data = data
+	return nil
 }
 
 type ChtReq struct {
@@ -290,64 +294,63 @@ type ChtRequest light.ChtRequest
 
 // GetCost returns the cost of the given ODR request according to the serving
 // peer's cost table (implementation of LesOdrRequest)
-func (self *ChtRequest) GetCost(peer *peer) uint64 {
+func (r *ChtRequest) GetCost(peer *peer) uint64 {
 	return peer.GetRequestCost(GetHeaderProofsMsg, 1)
 }
 
 // CanSend tells if a certain peer is suitable for serving the given request
-func (self *ChtRequest) CanSend(peer *peer) bool {
+func (r *ChtRequest) CanSend(peer *peer) bool {
 	peer.lock.RLock()
 	defer peer.lock.RUnlock()
 
-	return self.ChtNum <= (peer.headInfo.Number-light.ChtConfirmations)/light.ChtFrequency
+	return r.ChtNum <= (peer.headInfo.Number-light.ChtConfirmations)/light.ChtFrequency
 }
 
 // Request sends an ODR request to the LES network (implementation of LesOdrRequest)
-func (self *ChtRequest) Request(reqID uint64, peer *peer) error {
-	log.Debug(fmt.Sprintf("ODR: requesting CHT #%d block #%d from peer %v", self.ChtNum, self.BlockNum, peer.id))
+func (r *ChtRequest) Request(reqID uint64, peer *peer) error {
+	peer.Log().Debug("Requesting CHT", "cht", r.ChtNum, "block", r.BlockNum)
 	req := &ChtReq{
-		ChtNum:   self.ChtNum,
-		BlockNum: self.BlockNum,
+		ChtNum:   r.ChtNum,
+		BlockNum: r.BlockNum,
 	}
-	return peer.RequestHeaderProofs(reqID, self.GetCost(peer), []*ChtReq{req})
+	return peer.RequestHeaderProofs(reqID, r.GetCost(peer), []*ChtReq{req})
 }
 
 // Valid processes an ODR request reply message from the LES network
 // returns true and stores results in memory if the message was a valid reply
 // to the request (implementation of LesOdrRequest)
-func (self *ChtRequest) Valid(db ethdb.Database, msg *Msg) bool {
-	log.Debug(fmt.Sprintf("ODR: validating CHT #%d block #%d", self.ChtNum, self.BlockNum))
+func (r *ChtRequest) Valid(db ethdb.Database, msg *Msg) error {
+	log.Debug("Validating CHT", "cht", r.ChtNum, "block", r.BlockNum)
 
+	// Ensure we have a correct message with a single proof element
 	if msg.MsgType != MsgHeaderProofs {
-		log.Debug(fmt.Sprintf("ODR: invalid message type"))
-		return false
+		return errInvalidMessageType
 	}
 	proofs := msg.Obj.([]ChtResp)
 	if len(proofs) != 1 {
-		log.Debug(fmt.Sprintf("ODR: invalid number of entries: %d", len(proofs)))
-		return false
+		return errMultipleEntries
 	}
 	proof := proofs[0]
+
+	// Verify the CHT
 	var encNumber [8]byte
-	binary.BigEndian.PutUint64(encNumber[:], self.BlockNum)
-	value, err := trie.VerifyProof(self.ChtRoot, encNumber[:], proof.Proof)
+	binary.BigEndian.PutUint64(encNumber[:], r.BlockNum)
+
+	value, err := trie.VerifyProof(r.ChtRoot, encNumber[:], proof.Proof)
 	if err != nil {
-		log.Debug(fmt.Sprintf("ODR: CHT merkle proof verification error: %v", err))
-		return false
+		return err
 	}
 	var node light.ChtNode
 	if err := rlp.DecodeBytes(value, &node); err != nil {
-		log.Debug(fmt.Sprintf("ODR: error decoding CHT node: %v", err))
-		return false
+		return err
 	}
 	if node.Hash != proof.Header.Hash() {
-		log.Debug(fmt.Sprintf("ODR: CHT header hash does not match"))
-		return false
+		return errCHTHashMismatch
 	}
+	// Verifications passed, store and return
+	r.Header = proof.Header
+	r.Proof = proof.Proof
+	r.Td = node.Td
 
-	self.Proof = proof.Proof
-	self.Header = proof.Header
-	self.Td = node.Td
-	log.Debug(fmt.Sprintf("ODR: validation successful"))
-	return true
+	return nil
 }
diff --git a/les/peer.go b/les/peer.go
index 4d00f3df9..ef5f8a6ce 100644
--- a/les/peer.go
+++ b/les/peer.go
@@ -27,7 +27,6 @@ import (
 	"github.com/ethereum/go-ethereum/core/types"
 	"github.com/ethereum/go-ethereum/eth"
 	"github.com/ethereum/go-ethereum/les/flowcontrol"
-	"github.com/ethereum/go-ethereum/log"
 	"github.com/ethereum/go-ethereum/p2p"
 	"github.com/ethereum/go-ethereum/rlp"
 )
@@ -195,51 +194,51 @@ func (p *peer) SendHeaderProofs(reqID, bv uint64, proofs []ChtResp) error {
 // RequestHeadersByHash fetches a batch of blocks' headers corresponding to the
 // specified header query, based on the hash of an origin block.
 func (p *peer) RequestHeadersByHash(reqID, cost uint64, origin common.Hash, amount int, skip int, reverse bool) error {
-	log.Debug(fmt.Sprintf("%v fetching %d headers from %x, skipping %d (reverse = %v)", p, amount, origin[:4], skip, reverse))
+	p.Log().Debug("Fetching batch of headers", "count", amount, "fromhash", origin, "skip", skip, "reverse", reverse)
 	return sendRequest(p.rw, GetBlockHeadersMsg, reqID, cost, &getBlockHeadersData{Origin: hashOrNumber{Hash: origin}, Amount: uint64(amount), Skip: uint64(skip), Reverse: reverse})
 }
 
 // RequestHeadersByNumber fetches a batch of blocks' headers corresponding to the
 // specified header query, based on the number of an origin block.
 func (p *peer) RequestHeadersByNumber(reqID, cost, origin uint64, amount int, skip int, reverse bool) error {
-	log.Debug(fmt.Sprintf("%v fetching %d headers from #%d, skipping %d (reverse = %v)", p, amount, origin, skip, reverse))
+	p.Log().Debug("Fetching batch of headers", "count", amount, "fromnum", origin, "skip", skip, "reverse", reverse)
 	return sendRequest(p.rw, GetBlockHeadersMsg, reqID, cost, &getBlockHeadersData{Origin: hashOrNumber{Number: origin}, Amount: uint64(amount), Skip: uint64(skip), Reverse: reverse})
 }
 
 // RequestBodies fetches a batch of blocks' bodies corresponding to the hashes
 // specified.
 func (p *peer) RequestBodies(reqID, cost uint64, hashes []common.Hash) error {
-	log.Debug(fmt.Sprintf("%v fetching %d block bodies", p, len(hashes)))
+	p.Log().Debug("Fetching batch of block bodies", "count", len(hashes))
 	return sendRequest(p.rw, GetBlockBodiesMsg, reqID, cost, hashes)
 }
 
 // RequestCode fetches a batch of arbitrary data from a node's known state
 // data, corresponding to the specified hashes.
 func (p *peer) RequestCode(reqID, cost uint64, reqs []*CodeReq) error {
-	log.Debug(fmt.Sprintf("%v fetching %v state data", p, len(reqs)))
+	p.Log().Debug("Fetching batch of codes", "count", len(reqs))
 	return sendRequest(p.rw, GetCodeMsg, reqID, cost, reqs)
 }
 
 // RequestReceipts fetches a batch of transaction receipts from a remote node.
 func (p *peer) RequestReceipts(reqID, cost uint64, hashes []common.Hash) error {
-	log.Debug(fmt.Sprintf("%v fetching %v receipts", p, len(hashes)))
+	p.Log().Debug("Fetching batch of receipts", "count", len(hashes))
 	return sendRequest(p.rw, GetReceiptsMsg, reqID, cost, hashes)
 }
 
 // RequestProofs fetches a batch of merkle proofs from a remote node.
 func (p *peer) RequestProofs(reqID, cost uint64, reqs []*ProofReq) error {
-	log.Debug(fmt.Sprintf("%v fetching %v proofs", p, len(reqs)))
+	p.Log().Debug("Fetching batch of proofs", "count", len(reqs))
 	return sendRequest(p.rw, GetProofsMsg, reqID, cost, reqs)
 }
 
 // RequestHeaderProofs fetches a batch of header merkle proofs from a remote node.
 func (p *peer) RequestHeaderProofs(reqID, cost uint64, reqs []*ChtReq) error {
-	log.Debug(fmt.Sprintf("%v fetching %v header proofs", p, len(reqs)))
+	p.Log().Debug("Fetching batch of header proofs", "count", len(reqs))
 	return sendRequest(p.rw, GetHeaderProofsMsg, reqID, cost, reqs)
 }
 
 func (p *peer) SendTxs(cost uint64, txs types.Transactions) error {
-	log.Debug(fmt.Sprintf("%v relaying %v txs", p, len(txs)))
+	p.Log().Debug("Fetching batch of transactions", "count", len(txs))
 	reqID := getNextReqID()
 	p.fcServer.MustAssignRequest(reqID)
 	p.fcServer.SendRequest(reqID, cost)
diff --git a/les/server.go b/les/server.go
index b04c9c4ca..04bfa0292 100644
--- a/les/server.go
+++ b/les/server.go
@@ -19,7 +19,6 @@ package les
 
 import (
 	"encoding/binary"
-	"fmt"
 	"math"
 	"sync"
 	"time"
@@ -292,7 +291,7 @@ func (pm *ProtocolManager) blockLoop() {
 						lastHead = header
 						lastBroadcastTd = td
 
-						log.Debug(fmt.Sprint("===> ", number, hash, td, reorg))
+						log.Debug("Announcing block to peers", "number", number, "hash", hash, "td", td, "reorg", reorg)
 
 						announce := announceData{Hash: hash, Number: number, Td: td, ReorgDepth: reorg}
 						for _, p := range peers {
@@ -396,7 +395,7 @@ func makeCht(db ethdb.Database) bool {
 	} else {
 		lastChtNum++
 
-		log.Trace(fmt.Sprintf("cht: %d %064x", lastChtNum, root))
+		log.Trace("Generated CHT", "number", lastChtNum, "root", root.Hex())
 
 		storeChtRoot(db, lastChtNum, root)
 		var data [8]byte
diff --git a/les/serverpool.go b/les/serverpool.go
index 95a8242b3..55d481dbf 100644
--- a/les/serverpool.go
+++ b/les/serverpool.go
@@ -162,7 +162,7 @@ func (pool *serverPool) connect(p *peer, ip net.IP, port uint16) *poolEntry {
 	if entry == nil {
 		entry = pool.findOrNewNode(p.ID(), ip, port)
 	}
-	log.Debug(fmt.Sprintf("connecting to %v, state: %v", p.id, entry.state))
+	p.Log().Debug("Connecting to new peer", "state", entry.state)
 	if entry.state == psConnected || entry.state == psRegistered {
 		return nil
 	}
@@ -184,7 +184,7 @@ func (pool *serverPool) connect(p *peer, ip net.IP, port uint16) *poolEntry {
 
 // registered should be called after a successful handshake
 func (pool *serverPool) registered(entry *poolEntry) {
-	log.Debug(fmt.Sprintf("registered %v", entry.id.String()))
+	log.Debug("Registered new entry", "enode", entry.id)
 	pool.lock.Lock()
 	defer pool.lock.Unlock()
 
@@ -202,7 +202,7 @@ func (pool *serverPool) registered(entry *poolEntry) {
 // can be updated optionally (not updated if no registration happened, in this case
 // only connection statistics are updated, just like in case of timeout)
 func (pool *serverPool) disconnect(entry *poolEntry) {
-	log.Debug(fmt.Sprintf("disconnected %v", entry.id.String()))
+	log.Debug("Disconnected old entry", "enode", entry.id)
 	pool.lock.Lock()
 	defer pool.lock.Unlock()
 
@@ -418,7 +418,7 @@ func (pool *serverPool) findOrNewNode(id discover.NodeID, ip net.IP, port uint16
 	now := mclock.Now()
 	entry := pool.entries[id]
 	if entry == nil {
-		log.Debug(fmt.Sprintf("discovered %v", id.String()))
+		log.Debug("Discovered new entry", "id", id)
 		entry = &poolEntry{
 			id:         id,
 			addr:       make(map[string]*poolEntryAddress),
@@ -459,11 +459,15 @@ func (pool *serverPool) loadNodes() {
 	var list []*poolEntry
 	err = rlp.DecodeBytes(enc, &list)
 	if err != nil {
-		log.Debug(fmt.Sprintf("node list decode error: %v", err))
+		log.Debug("Failed to decode node list", "err", err)
 		return
 	}
 	for _, e := range list {
-		log.Debug(fmt.Sprintf("loaded server stats %016x  fails: %v  connStats: %v / %v  delayStats: %v / %v  responseStats: %v / %v  timeoutStats: %v / %v", e.id[0:8], e.lastConnected.fails, e.connectStats.avg, e.connectStats.weight, time.Duration(e.delayStats.avg), e.delayStats.weight, time.Duration(e.responseStats.avg), e.responseStats.weight, e.timeoutStats.avg, e.timeoutStats.weight))
+		log.Debug("Loaded server stats", "id", e.id, "fails", e.lastConnected.fails,
+			"conn", fmt.Sprintf("%v/%v", e.connectStats.avg, e.connectStats.weight),
+			"delay", fmt.Sprintf("%v/%v", time.Duration(e.delayStats.avg), e.delayStats.weight),
+			"response", fmt.Sprintf("%v/%v", time.Duration(e.responseStats.avg), e.responseStats.weight),
+			"timeout", fmt.Sprintf("%v/%v", e.timeoutStats.avg, e.timeoutStats.weight))
 		pool.entries[e.id] = e
 		pool.knownQueue.setLatest(e)
 		pool.knownSelect.update((*knownEntry)(e))
@@ -568,7 +572,7 @@ func (pool *serverPool) dial(entry *poolEntry, knownSelected bool) {
 		pool.newSelected++
 	}
 	addr := entry.addrSelect.choose().(*poolEntryAddress)
-	log.Debug(fmt.Sprintf("dialing %v out of %v, known: %v", entry.id.String()+"@"+addr.strKey(), len(entry.addr), knownSelected))
+	log.Debug("Dialing new peer", "lesaddr", entry.id.String()+"@"+addr.strKey(), "set", len(entry.addr), "known", knownSelected)
 	entry.dialed = addr
 	go func() {
 		pool.server.AddPeer(discover.NewNode(entry.id, addr.ip, addr.port, addr.port))
@@ -589,7 +593,7 @@ func (pool *serverPool) checkDialTimeout(entry *poolEntry) {
 	if entry.state != psDialed {
 		return
 	}
-	log.Debug(fmt.Sprintf("timeout %v", entry.id.String()+"@"+entry.dialed.strKey()))
+	log.Debug("Dial timeout", "lesaddr", entry.id.String()+"@"+entry.dialed.strKey())
 	entry.state = psNotConnected
 	if entry.knownSelected {
 		pool.knownSelected--