From e7030c4bf59e8e148822c50ae1a5896c604c38c1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Szil=C3=A1gyi?= Date: Fri, 3 Mar 2017 11:41:52 +0200 Subject: all: update light logs (and a few others) to the new model --- les/handler.go | 68 ++++++++++++++++++++++++++-------------------------------- 1 file changed, 31 insertions(+), 37 deletions(-) (limited to 'les/handler.go') 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 } -- cgit v1.2.3