Skip to content

Commit

Permalink
Add missing verbo logs checks (ava-labs#1504)
Browse files Browse the repository at this point in the history
Co-authored-by: dhrubabasu <7675102+dhrubabasu@users.noreply.github.com>
  • Loading branch information
gyuho and dhrubabasu committed May 18, 2023
1 parent 467b905 commit 0c391e8
Show file tree
Hide file tree
Showing 4 changed files with 97 additions and 73 deletions.
30 changes: 17 additions & 13 deletions snow/engine/avalanche/bootstrap/bootstrapper.go
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ import (
"github.com/ava-labs/avalanchego/snow/consensus/avalanche"
"github.com/ava-labs/avalanchego/snow/engine/avalanche/vertex"
"github.com/ava-labs/avalanchego/snow/engine/common"
"github.com/ava-labs/avalanchego/utils/logging"
"github.com/ava-labs/avalanchego/utils/set"
"github.com/ava-labs/avalanchego/version"
)
Expand Down Expand Up @@ -134,19 +135,22 @@ func (b *bootstrapper) Ancestors(ctx context.Context, nodeID ids.NodeID, request
)
return nil
}
b.Ctx.Log.Debug("failed to parse requested vertex",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Stringer("vtxID", requestedVtxID),
zap.Error(err),
)
b.Ctx.Log.Verbo("failed to parse requested vertex",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Stringer("vtxID", requestedVtxID),
zap.Binary("vtxBytes", vtxs[0]),
zap.Error(err),
)
if b.Ctx.Log.Enabled(logging.Verbo) {
b.Ctx.Log.Verbo("failed to parse requested vertex",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Stringer("vtxID", requestedVtxID),
zap.Binary("vtxBytes", vtxs[0]),
zap.Error(err),
)
} else {
b.Ctx.Log.Debug("failed to parse requested vertex",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Stringer("vtxID", requestedVtxID),
zap.Error(err),
)
}
return b.fetch(ctx, requestedVtxID)
}

Expand Down
51 changes: 29 additions & 22 deletions snow/engine/snowman/transitive.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ import (
"github.com/ava-labs/avalanchego/snow/events"
"github.com/ava-labs/avalanchego/snow/validators"
"github.com/ava-labs/avalanchego/utils/bag"
"github.com/ava-labs/avalanchego/utils/logging"
"github.com/ava-labs/avalanchego/utils/set"
"github.com/ava-labs/avalanchego/utils/wrappers"
)
Expand Down Expand Up @@ -127,17 +128,20 @@ func newTransitive(config Config) (*Transitive, error) {
func (t *Transitive) Put(ctx context.Context, nodeID ids.NodeID, requestID uint32, blkBytes []byte) error {
blk, err := t.VM.ParseBlock(ctx, blkBytes)
if err != nil {
t.Ctx.Log.Debug("failed to parse block",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Error(err),
)
t.Ctx.Log.Verbo("failed to parse block",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Binary("block", blkBytes),
zap.Error(err),
)
if t.Ctx.Log.Enabled(logging.Verbo) {
t.Ctx.Log.Verbo("failed to parse block",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Binary("block", blkBytes),
zap.Error(err),
)
} else {
t.Ctx.Log.Debug("failed to parse block",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Error(err),
)
}
// because GetFailed doesn't utilize the assumption that we actually
// sent a Get message, we can safely call GetFailed here to potentially
// abandon the request.
Expand Down Expand Up @@ -212,17 +216,20 @@ func (t *Transitive) PushQuery(ctx context.Context, nodeID ids.NodeID, requestID
blk, err := t.VM.ParseBlock(ctx, blkBytes)
// If parsing fails, we just drop the request, as we didn't ask for it
if err != nil {
t.Ctx.Log.Debug("failed to parse block",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Error(err),
)
t.Ctx.Log.Verbo("failed to parse block",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Binary("block", blkBytes),
zap.Error(err),
)
if t.Ctx.Log.Enabled(logging.Verbo) {
t.Ctx.Log.Verbo("failed to parse block",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Binary("block", blkBytes),
zap.Error(err),
)
} else {
t.Ctx.Log.Debug("failed to parse block",
zap.Stringer("nodeID", nodeID),
zap.Uint32("requestID", requestID),
zap.Error(err),
)
}
return nil
}

Expand Down
60 changes: 35 additions & 25 deletions snow/networking/handler/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ import (
"github.com/ava-labs/avalanchego/snow/validators"
"github.com/ava-labs/avalanchego/subnets"
"github.com/ava-labs/avalanchego/utils"
"github.com/ava-labs/avalanchego/utils/logging"
"github.com/ava-labs/avalanchego/utils/timer/mockable"
)

Expand Down Expand Up @@ -432,15 +433,18 @@ func (h *handler) handleSyncMsg(ctx context.Context, msg Message) error {
// execution (may change during execution)
isNormalOp = h.ctx.State.Get().State == snow.NormalOp
)
h.ctx.Log.Debug("forwarding sync message to consensus",
zap.Stringer("nodeID", nodeID),
zap.Stringer("messageOp", op),
)
h.ctx.Log.Verbo("forwarding sync message to consensus",
zap.Stringer("nodeID", nodeID),
zap.Stringer("messageOp", op),
zap.Any("message", body),
)
if h.ctx.Log.Enabled(logging.Verbo) {
h.ctx.Log.Verbo("forwarding sync message to consensus",
zap.Stringer("nodeID", nodeID),
zap.Stringer("messageOp", op),
zap.Any("message", body),
)
} else {
h.ctx.Log.Debug("forwarding sync message to consensus",
zap.Stringer("nodeID", nodeID),
zap.Stringer("messageOp", op),
)
}
h.resourceTracker.StartProcessing(nodeID, startTime)
h.ctx.Lock.Lock()
lockAcquiredTime := h.clock.Time()
Expand Down Expand Up @@ -756,15 +760,18 @@ func (h *handler) executeAsyncMsg(ctx context.Context, msg Message) error {
body = msg.Message()
startTime = h.clock.Time()
)
h.ctx.Log.Debug("forwarding async message to consensus",
zap.Stringer("nodeID", nodeID),
zap.Stringer("messageOp", op),
)
h.ctx.Log.Verbo("forwarding async message to consensus",
zap.Stringer("nodeID", nodeID),
zap.Stringer("messageOp", op),
zap.Any("message", body),
)
if h.ctx.Log.Enabled(logging.Verbo) {
h.ctx.Log.Verbo("forwarding async message to consensus",
zap.Stringer("nodeID", nodeID),
zap.Stringer("messageOp", op),
zap.Any("message", body),
)
} else {
h.ctx.Log.Debug("forwarding async message to consensus",
zap.Stringer("nodeID", nodeID),
zap.Stringer("messageOp", op),
)
}
h.resourceTracker.StartProcessing(nodeID, startTime)
defer func() {
var (
Expand Down Expand Up @@ -854,13 +861,16 @@ func (h *handler) handleChanMsg(msg message.InboundMessage) error {
// execution (may change during execution)
isNormalOp = h.ctx.State.Get().State == snow.NormalOp
)
h.ctx.Log.Debug("forwarding chan message to consensus",
zap.Stringer("messageOp", op),
)
h.ctx.Log.Verbo("forwarding chan message to consensus",
zap.Stringer("messageOp", op),
zap.Any("message", body),
)
if h.ctx.Log.Enabled(logging.Verbo) {
h.ctx.Log.Verbo("forwarding chan message to consensus",
zap.Stringer("messageOp", op),
zap.Any("message", body),
)
} else {
h.ctx.Log.Debug("forwarding chan message to consensus",
zap.Stringer("messageOp", op),
)
}
h.ctx.Lock.Lock()
lockAcquiredTime := h.clock.Time()
defer func() {
Expand Down
29 changes: 16 additions & 13 deletions snow/networking/sender/sender.go
Original file line number Diff line number Diff line change
Expand Up @@ -878,19 +878,22 @@ func (s *sender) SendPut(_ context.Context, nodeID ids.NodeID, requestID uint32,
s.subnet,
)
if sentTo.Len() == 0 {
s.ctx.Log.Debug("failed to send message",
zap.Stringer("messageOp", message.PutOp),
zap.Stringer("nodeID", nodeID),
zap.Stringer("chainID", s.ctx.ChainID),
zap.Uint32("requestID", requestID),
)
s.ctx.Log.Verbo("failed to send message",
zap.Stringer("messageOp", message.PutOp),
zap.Stringer("nodeID", nodeID),
zap.Stringer("chainID", s.ctx.ChainID),
zap.Uint32("requestID", requestID),
zap.Binary("container", container),
)
if s.ctx.Log.Enabled(logging.Verbo) {
s.ctx.Log.Verbo("failed to send message",
zap.Stringer("messageOp", message.PutOp),
zap.Stringer("nodeID", nodeID),
zap.Stringer("chainID", s.ctx.ChainID),
zap.Uint32("requestID", requestID),
zap.Binary("container", container),
)
} else {
s.ctx.Log.Debug("failed to send message",
zap.Stringer("messageOp", message.PutOp),
zap.Stringer("nodeID", nodeID),
zap.Stringer("chainID", s.ctx.ChainID),
zap.Uint32("requestID", requestID),
)
}
}
}

Expand Down

0 comments on commit 0c391e8

Please sign in to comment.