Move error logging to debug (#437)

* Log level of errors on appending transaction to UTX set to DEBUG * Network connection errrors moved to DEBUG level * More network log messages moved to DEBUG level. Fixed an issue with invalid blocks added to blocks cache. Naming fixed. * Error on state changing while mining micro block moved to DEBUG level. Handling of micro-block mining task added to Sync FSM.
wavesplatform · Mar 18, 2021 · fb209f1 · fb209f1
1 parent e2fb049
commit fb209f1
Show file tree

Hide file tree

Showing 15 changed files with 170 additions and 156 deletions.
diff --git a/pkg/node/blocks_applier/blocks_applier.go b/pkg/node/blocks_applier/blocks_applier.go
@@ -72,8 +72,8 @@ func (a *innerBlocksApplier) apply(storage innerState, blocks []*proto.Block) (p
 	}
 	cumulativeScore := forkScore.Add(forkScore, parentScore)
 	if currentScore.Cmp(cumulativeScore) >= 0 { // current score is higher or the same as fork score - do not apply blocks
-		return 0, errors.Errorf("low fork score: current blockchain score (%s) is higher than or equal to fork's score (%s)",
-			currentScore.String(), cumulativeScore.String())
+		return 0, proto.NewInfoMsg(errors.Errorf("low fork score: current blockchain score (%s) is higher than or equal to fork's score (%s)",
+			currentScore.String(), cumulativeScore.String()))
 	}
 
 	// so, new blocks has higher score, try apply it.

diff --git a/pkg/node/node.go b/pkg/node/node.go
@@ -94,7 +94,7 @@ func (a *Node) Serve(ctx context.Context) error {
 
 		go func() {
 			if err := a.peers.SpawnIncomingConnection(ctx, conn); err != nil {
-				zap.S().Error(err)
+				zap.S().Debugf("Incoming connection error: %v", err)
 				return
 			}
 		}()

diff --git a/pkg/node/peer_manager/peer_manager.go b/pkg/node/peer_manager/peer_manager.go
@@ -185,23 +185,23 @@ func (a *PeerManagerImpl) NewConnection(p peer.Peer) error {
 		)
 		a.Suspend(p, err.Error())
 		_ = p.Close()
-		return err
+		return proto.NewInfoMsg(err)
 	}
 
 	in, out := a.InOutCount()
 	switch p.Direction() {
 	case peer.Incoming:
 		if in >= a.limitConnections {
 			_ = p.Close()
-			return errors.New("exceed incoming connections limit")
+			return proto.NewInfoMsg(errors.New("exceed incoming connections limit"))
 		}
 	case peer.Outgoing:
 		if !p.Handshake().DeclaredAddr.Empty() {
 			_ = a.state.AddKnown(proto.TCPAddr(p.Handshake().DeclaredAddr))
 		}
 		if out >= a.limitConnections {
 			_ = p.Close()
-			return errors.New("exceed outgoing connections limit")
+			return proto.NewInfoMsg(errors.New("exceed outgoing connections limit"))
 		}
 	default:
 		_ = p.Close()
@@ -300,11 +300,7 @@ func (a *PeerManagerImpl) AddAddress(ctx context.Context, addr string) {
 	_ = a.state.Add([]proto.TCPAddr{proto.NewTCPAddrFromString(addr)})
 	go func() {
 		if err := a.spawner.SpawnOutgoing(ctx, proto.NewTCPAddrFromString(addr)); err != nil {
-			if !errors.Is(err, context.Canceled) {
-				zap.S().Warn(err)
-			} else {
-				zap.S().Debug(err)
-			}
+			zap.S().Debug(err)
 		}
 	}()
 }

diff --git a/pkg/node/state_fsm/default.go b/pkg/node/state_fsm/default.go
@@ -2,6 +2,7 @@ package state_fsm
 
 import (
 	. "github.com/wavesplatform/gowaves/pkg/p2p/peer"
+	"github.com/wavesplatform/gowaves/pkg/proto"
 )
 
 type Default interface {
@@ -27,6 +28,9 @@ func (a DefaultImpl) PeerError(fsm FSM, p Peer, baseInfo BaseInfo, _ error) (FSM
 
 func (a DefaultImpl) NewPeer(fsm FSM, p Peer, info BaseInfo) (FSM, Async, error) {
 	err := info.peers.NewConnection(p)
+	if err != nil {
+		return fsm, nil, proto.NewInfoMsg(err)
+	}
 	info.Reschedule()
-	return fsm, nil, err
+	return fsm, nil, nil
 }
diff --git a/pkg/node/state_fsm/fsm_common.go b/pkg/node/state_fsm/fsm_common.go
@@ -10,7 +10,10 @@ import (
 
 func newPeer(fsm FSM, p Peer, peers peer_manager.PeerManager) (FSM, Async, error) {
 	err := peers.NewConnection(p)
-	return fsm, nil, err
+	if err != nil {
+		return fsm, nil, proto.NewInfoMsg(err)
+	}
+	return fsm, nil, nil
 }
 
 // TODO handle no peers

diff --git a/pkg/node/state_fsm/fsm_idle.go b/pkg/node/state_fsm/fsm_idle.go
@@ -50,6 +50,8 @@ func (a *IdleFsm) Task(task AsyncTask) (FSM, Async, error) {
 	case AskPeers:
 		a.baseInfo.peers.AskPeers()
 		return a, nil, nil
+	case MineMicro: // Do nothing
+		return a, nil, nil
 	default:
 		return a, nil, errors.Errorf("IdleFsm Task: unknown task type %d, data %+v", task.TaskType, task.Data)
 	}

diff --git a/pkg/node/state_fsm/fsm_ng.go b/pkg/node/state_fsm/fsm_ng.go
@@ -74,7 +74,8 @@ func (a *NGFsm) rollbackToStateFromCache(blockFromCache *proto.Block) error {
 	previousBlockID := blockFromCache.Parent
 	err := a.storage.RollbackTo(previousBlockID)
 	if err != nil {
-		return errors.Wrapf(err, "failed to rollback to height %d", blockFromCache.Height)
+		return errors.Wrapf(err, "failed to rollback to parent block '%s' of cached block '%s'",
+			previousBlockID.String(), blockFromCache.ID.String())
 	}
 	_, err = a.blocksApplier.Apply(a.storage, []*proto.Block{blockFromCache})
 	if err != nil {
@@ -106,15 +107,17 @@ func (a *NGFsm) Block(peer peer.Peer, block *proto.Block) (FSM, Async, error) {
 			}
 		}
 	}
-	a.blocksCache.Clear()
-	a.blocksCache.AddBlockState(block)
 
 	_, err = a.blocksApplier.Apply(a.storage, []*proto.Block{block})
 	if err != nil {
 		metrics.FSMKeyBlockDeclined("ng", block, err)
 		return a, nil, err
 	}
 	metrics.FSMKeyBlockApplied("ng", block)
+
+	a.blocksCache.Clear()
+	a.blocksCache.AddBlockState(block)
+
 	a.Scheduler.Reschedule()
 	a.actions.SendScore(a.storage)
 	a.CleanUtx()
@@ -189,10 +192,12 @@ func (a *NGFsm) mineMicro(minedBlock *proto.Block, rest proto.MiningLimits, keyP
 	if err == miner.NoTransactionsErr {
 		return a, Tasks(NewMineMicroTask(5*time.Second, minedBlock, rest, keyPair, vrf)), nil
 	}
+	if err == miner.StateChangedErr {
+		return a, nil, proto.NewInfoMsg(err)
+	}
 	if err != nil {
 		return a, nil, errors.Wrap(err, "NGFsm.mineMicro")
 	}
-	a.blocksCache.AddBlockState(block)
 	metrics.FSMMicroBlockGenerated("ng", micro)
 	err = a.storage.Map(func(s state.NonThreadSafeState) error {
 		_, err := a.blocksApplier.ApplyMicro(s, block)
@@ -201,6 +206,7 @@ func (a *NGFsm) mineMicro(minedBlock *proto.Block, rest proto.MiningLimits, keyP
 	if err != nil {
 		return a, nil, err
 	}
+	a.blocksCache.AddBlockState(block)
 	a.Reschedule()
 	metrics.FSMMicroBlockApplied("ng", micro)
 	inv := proto.NewUnsignedMicroblockInv(

diff --git a/pkg/node/state_fsm/fsm_sync.go b/pkg/node/state_fsm/fsm_sync.go
@@ -68,6 +68,8 @@ func (a *SyncFsm) Task(task AsyncTask) (FSM, Async, error) {
 			return NewIdleFsm(a.baseInfo), nil, TimeoutErr
 		}
 		return a, nil, nil
+	case MineMicro: // Do nothing
+		return a, nil, nil
 	default:
 		return a, nil, errors.Errorf("SyncFsm Task: unknown task type %d, data %+v", task.TaskType, task.Data)
 	}
@@ -119,7 +121,10 @@ func (a *SyncFsm) BlockIDs(peer Peer, signatures []proto.BlockID) (FSM, Async, e
 
 func (a *SyncFsm) NewPeer(p Peer) (FSM, Async, error) {
 	err := a.baseInfo.peers.NewConnection(p)
-	return a, nil, err
+	if err != nil {
+		return a, nil, proto.NewInfoMsg(err)
+	}
+	return a, nil, nil
 }
 
 func (a *SyncFsm) Score(p Peer, score *proto.Score) (FSM, Async, error) {

diff --git a/pkg/p2p/incoming/Incoming.go b/pkg/p2p/incoming/Incoming.go
@@ -41,7 +41,7 @@ func runIncomingPeer(ctx context.Context, cancel context.CancelFunc, params Inco
 	readHandshake := proto.Handshake{}
 	_, err := readHandshake.ReadFrom(c)
 	if err != nil {
-		zap.S().Error("failed to read handshake: ", err)
+		zap.S().Debug("Failed to read handshake: ", err)
 		_ = c.Close()
 		return err
 	}
@@ -64,7 +64,7 @@ func runIncomingPeer(ctx context.Context, cancel context.CancelFunc, params Inco
 
 	_, err = writeHandshake.WriteTo(c)
 	if err != nil {
-		zap.S().Error("failed to write handshake: ", err)
+		zap.S().Debug("failed to write handshake: ", err)
 		_ = c.Close()
 		return err
 	}

diff --git a/pkg/p2p/outgoing/outgoing.go b/pkg/p2p/outgoing/outgoing.go
@@ -45,7 +45,7 @@ func EstablishConnection(ctx context.Context, params EstablishParams, v proto.Ve
 
 	connection, handshake, err := p.connect(ctx, c, v)
 	if err != nil {
-		zap.S().Debug(err, params.Address)
+		zap.S().Debugf("Outgoing connection to address %s failed with error: %v", params.Address.String(), err)
 		return errors.Wrapf(err, "%q", params.Address)
 	}
 	p.connection = connection
@@ -92,7 +92,7 @@ func (a *connector) connect(ctx context.Context, c net.Conn, v proto.Version) (c
 
 	_, err := handshake.WriteTo(c)
 	if err != nil {
-		zap.S().Error("failed to send handshake: ", err, a.params.Address)
+		zap.S().Error("Failed to send handshake: ", err, a.params.Address)
 		return nil, nil, err
 	}
 
@@ -105,7 +105,7 @@ func (a *connector) connect(ctx context.Context, c net.Conn, v proto.Version) (c
 
 	_, err = handshake.ReadFrom(c)
 	if err != nil {
-		zap.S().Debugf("failed to read handshake: %s %s", err, a.params.Address)
+		zap.S().Debugf("Failed to read handshake: %s %s", err, a.params.Address)
 		select {
 		case <-ctx.Done():
 			return nil, nil, errors.Wrap(ctx.Err(), "connector.connect")

diff --git a/pkg/proto/microblock.go b/pkg/proto/microblock.go
@@ -296,7 +296,7 @@ func (a *MicroBlockInvMessage) WriteTo(w io.Writer) (n int64, err error) {
 	if err != nil {
 		return 0, err
 	}
-	copy(h.PayloadCsum[:], dig[:4])
+	copy(h.PayloadChecksum[:], dig[:4])
 	n1, err := h.WriteTo(w)
 	if err != nil {
 		return 0, err
@@ -339,7 +339,7 @@ func (a *MicroBlockRequestMessage) WriteTo(w io.Writer) (int64, error) {
 	if err != nil {
 		return 0, err
 	}
-	copy(h.PayloadCsum[:], dig[:4])
+	copy(h.PayloadChecksum[:], dig[:4])
 	n2, err := h.WriteTo(w)
 	if err != nil {
 		return 0, err