Skip to content

snow/networking/sender: add missing verbo check #1504

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 10 commits into from
May 18, 2023
Merged

snow/networking/sender: add missing verbo check #1504

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
dadc320
snow/networking/sender: add missing verbo check
gyuho May 14, 2023
ed07e0f
snowman/transitive: add more missing verbo check
gyuho May 14, 2023
059e844
handler: check verbo log
gyuho May 14, 2023
4535e83
handler: log
gyuho May 14, 2023
1f3abd3
add missing verbo
gyuho May 14, 2023
0406422
nit
dhrubabasu May 14, 2023
52644f9
Merge branch 'dev' into verbo
StephenButtolph May 15, 2023
d68d7cf
Merge branch 'dev' into verbo
dhrubabasu May 16, 2023
16b837e
Merge branch 'dev' into verbo
dhrubabasu May 17, 2023
5c10a1b
Merge branch 'dev' into verbo
StephenButtolph May 18, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
30 changes: 17 additions & 13 deletions snow/engine/avalanche/bootstrap/bootstrapper.go
View file
Open in desktop
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
View file
Open in desktop
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
View file
Open in desktop
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
View file
Open in desktop
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