enhancement(logging): leverage trace level

cmd/thor/node/node.go

@@ -266,7 +266,7 @@ func (n *Node) txStashLoop(ctx context.Context) {
 			if err := stash.Save(txEv.Tx); err != nil {
 				logger.Warn("stash tx", "id", txEv.Tx.ID(), "err", err)
 			} else {
-				logger.Debug("stashed tx", "id", txEv.Tx.ID())
+				logger.Trace("stashed tx", "id", txEv.Tx.ID())
 			}
 		}
 	}
@@ -392,7 +392,7 @@ func (n *Node) processBlock(newBlock *block.Block, stats *blockStats) (bool, err
 		commitElapsed := mclock.Now() - startTime - execElapsed
 
 		if v, updated := n.bandwidth.Update(newBlock.Header(), time.Duration(realElapsed)); updated {
-			logger.Debug("bandwidth updated", "gps", v)
+			logger.Trace("bandwidth updated", "gps", v)
 		}
 		stats.UpdateProcessed(1, len(receipts), execElapsed, commitElapsed, realElapsed, newBlock.Header().GasUsed())
 

cmd/thor/node/packer_loop.go

@@ -205,7 +205,7 @@ func (n *Node) pack(flow *packer.Flow) (err error) {
 		)
 
 		if v, updated := n.bandwidth.Update(newBlock.Header(), time.Duration(realElapsed)); updated {
-			logger.Debug("bandwidth updated", "gps", v)
+			logger.Trace("bandwidth updated", "gps", v)
 		}
 
 		metricBlockProcessedTxs().SetWithLabel(int64(len(receipts)), map[string]string{"type": "proposed"})

comm/handle_rpc.go

@@ -21,7 +21,7 @@ import (
 // peer will be disconnected if error returned
 func (c *Communicator) handleRPC(peer *Peer, msg *p2p.Msg, write func(interface{}), txsToSync *txsToSync) (err error) {
 	log := peer.logger.New("msg", proto.MsgName(msg.Code))
-	log.Debug("received RPC call")
+	log.Trace("received RPC call")
 	defer func() {
 		if err != nil {
 			log.Debug("failed to handle RPC call", "err", err)

comm/sync.go

@@ -196,7 +196,7 @@ func findCommonAncestor(ctx context.Context, repo *chain.Repository, peer *Peer,
 
 func (c *Communicator) syncTxs(peer *Peer) {
 	for i := 0; ; i++ {
-		peer.logger.Debug(fmt.Sprintf("sync txs loop %v", i))
+		peer.logger.Trace(fmt.Sprintf("sync txs loop %v", i))
 		result, err := proto.GetTxs(c.ctx, peer)
 		if err != nil {
 			peer.logger.Debug("failed to request txs", "err", err)

p2psrv/server.go

@@ -87,7 +87,7 @@ func (s *Server) Start(protocols []*p2p.Protocol, topic discv5.Topic) error {
 			}
 			log := logger.New("peer", peer, "dir", dir)
 
-			log.Debug("peer connected")
+			log.Trace("peer connected")
 			metricConnectedPeers().Add(1)
 
 			startTime := mclock.Now()
@@ -252,7 +252,7 @@ func (s *Server) discoverLoop(topic discv5.Topic) {
 			if _, found := s.discoveredNodes.Get(node.ID); !found {
 				metricDiscoveredNodes().Add(1)
 				s.discoveredNodes.Set(node.ID, node)
-				logger.Debug("discovered node", "node", node)
+				logger.Trace("discovered node", "node", node)
 			}
 		case <-s.done:
 			close(setPeriod)

txpool/tx_pool.go

@@ -135,7 +135,7 @@ func (p *TxPool) housekeeping() {
 				}
 
 				metricTxPoolGauge().AddWithLabel(0-int64(removed), map[string]string{"source": "washed", "total": "true"})
-				logger.Debug("wash done", ctx...)
+				logger.Trace("wash done", ctx...)
 			}
 		}
 	}
@@ -275,7 +275,7 @@ func (p *TxPool) add(newTx *tx.Transaction, rejectNonExecutable bool, localSubmi
 		p.goes.Go(func() {
 			p.txFeed.Send(&TxEvent{newTx, &executable})
 		})
-		logger.Debug("tx added", "id", newTx.ID(), "executable", executable)
+		logger.Trace("tx added", "id", newTx.ID(), "executable", executable)
 	} else {
 		// we skip steps that rely on head block when chain is not synced,
 		// but check the pool's limit
@@ -287,7 +287,7 @@ func (p *TxPool) add(newTx *tx.Transaction, rejectNonExecutable bool, localSubmi
 		if err := p.all.Add(txObj, p.options.LimitPerAccount, func(_ thor.Address, _ *big.Int) error { return nil }); err != nil {
 			return txRejectedError{err.Error()}
 		}
-		logger.Debug("tx added", "id", newTx.ID())
+		logger.Trace("tx added", "id", newTx.ID())
 		p.goes.Go(func() {
 			p.txFeed.Send(&TxEvent{newTx, nil})
 		})
@@ -408,29 +408,29 @@ func (p *TxPool) wash(headSummary *chain.BlockSummary) (executables tx.Transacti
 	for _, txObj := range all {
 		if thor.IsOriginBlocked(txObj.Origin()) || p.blocklist.Contains(txObj.Origin()) {
 			toRemove = append(toRemove, txObj)
-			logger.Debug("tx washed out", "id", txObj.ID(), "err", "blocked")
+			logger.Trace("tx washed out", "id", txObj.ID(), "err", "blocked")
 			continue
 		}
 
 		// out of lifetime
 		if !txObj.localSubmitted && now > txObj.timeAdded+int64(p.options.MaxLifetime) {
 			toRemove = append(toRemove, txObj)
-			logger.Debug("tx washed out", "id", txObj.ID(), "err", "out of lifetime")
+			logger.Trace("tx washed out", "id", txObj.ID(), "err", "out of lifetime")
 			continue
 		}
 		// settled, out of energy or dep broken
 		executable, err := txObj.Executable(chain, newState(), headSummary.Header)
 		if err != nil {
 			toRemove = append(toRemove, txObj)
-			logger.Debug("tx washed out", "id", txObj.ID(), "err", err)
+			logger.Trace("tx washed out", "id", txObj.ID(), "err", err)
 			continue
 		}
 
 		if executable {
 			provedWork, err := txObj.ProvedWork(headSummary.Header.Number(), chain.GetBlockID)
 			if err != nil {
 				toRemove = append(toRemove, txObj)
-				logger.Debug("tx washed out", "id", txObj.ID(), "err", err)
+				logger.Trace("tx washed out", "id", txObj.ID(), "err", err)
 				continue
 			}
 			txObj.overallGasPrice = txObj.OverallGasPrice(baseGasPrice, provedWork)