Repository navigation
fix(gossipsub): log non-priority send-queue drops at debug - #1
Closed
pablodeymo wants to merge 1 commit into
Closed
pablodeymo wants to merge 1 commit into
pablodeymo wants to merge 1 commit into
Conversation
A full send queue drops the RPC, counts it in `failed_messages` and charges the peer's score; the log line was the only part of that at WARN. On a beacon node subscribed to 64 attestation subnets a slow peer produces one such line per heartbeat, each carrying every IHAVE message id, so the warning drowns the log without saying anything the counters do not. Control messages (GRAFT, PRUNE, IDONTWANT) keep the warning: a dropped one leaves the peer's view of the mesh out of step with ours. Subscriptions cannot reach this branch at all, since their queue is unbounded.
Author
|
Closing: ethlambda caps the gossipsub crate at ERROR in its own log filter instead (lambdaclass/ethlambda#719), so the fork stays untouched. The branch stays for reference, and the WARN/DEBUG split here is still a reasonable proposal for upstream. |
dicethedev
pushed a commit
to dicethedev/ethlambda
that referenced
this pull request
Nov 4, 2026
…ambdaclass#719) ## 🗒️ Description / Motivation - A beacon node on Hoodi logs `WARN libp2p_gossipsub::behaviour: Send Queue full. Could not send Rpc.` once per heartbeat for every slow peer, each line listing every IHAVE id dropped on an attestation subnet. The drop is already counted in the peer's `failed_messages` and charged to its score, so the line adds noise, not information. - The line is emitted inside the gossipsub crate. Rather than patching the libp2p fork, the node's default log filter now caps that crate at ERROR, which is how an operator sees the dependency's noise anyway. Lighthouse goes further and routes all `libp2p_gossipsub` and `discv5` output to separate files. ## What Changed - `bin/ethlambda/src/main.rs`: `init_node_logging` builds its filter from `node_log_filter(RUST_LOG)`. With no `RUST_LOG` the directives are `info,libp2p_gossipsub=error`; with one they are `libp2p_gossipsub=error,<RUST_LOG>`. A `RUST_LOG` directive on `libp2p_gossipsub` replaces the cap, one on any other target adds to it, and `RUST_LOG` keeps replacing the `info` floor the way `from_env_lossy` always did. The floor is spelled out because `EnvFilter` only applies a default directive when it was given no directive at all. - Besides the send-queue line, the cap hides gossipsub's other warnings (bad signatures, substream limits, anonymous-mode field checks), all per-peer protocol violations that peer scoring already handles. Its 19 error sites still show. - The benchmark and keygen filters are untouched; neither runs a network. - `docs/beacon_wire.md`: one sentence next to the existing `RUST_LOG` example, saying how to see gossipsub's warnings. ## Correctness / Behavior Guarantees - Default output changes only for the `libp2p_gossipsub` target: WARN and below are dropped, ERROR stays. - `RUST_LOG` semantics are preserved, including the pre-existing quirk that a `RUST_LOG` without its own `info` silences other targets. Verified against tracing-subscriber 0.3.23: an equal-specificity directive added later replaces the earlier one, and `Ordering::Equal` implies the same target, so no other directive is clobbered. - A bare `RUST_LOG=debug` keeps the cap, since the more specific directive wins; the doc comment says to name the crate. ## Tests Added / Run - Three tests in `main.rs` drive real events through the filter: default behaviour (INFO floor, gossipsub WARN dropped, gossipsub ERROR kept), the lift via `RUST_LOG=…,libp2p_gossipsub=warn,…` alongside another directive, and the floor-replacement quirk. - `cargo test --locked --profile release-fast -p ethlambda --bin ethlambda -- tests::node_logging tests::rust_log`: 3 passed. - `cargo clippy --locked -p ethlambda --all-targets -- -D warnings`: clean. `cargo fmt --all -- --check`: clean. ## Related Issues / PRs - Supersedes lambdaclass#717 and lambdaclass/rust-libp2p#1, which fixed the same symptom in the fork; both are being closed. - Follow-up worth an issue: ethlambda does not handle gossipsub's `Event::SlowPeer`. Lighthouse reports a peer after more than 10 priority or 10 non-priority drops, so the peer producing these lines gets disconnected instead of staying in the mesh. ## ✅ Verification Checklist - [x] Ran `make fmt` — clean - [ ] Ran `make lint` (clippy with `-D warnings`) — run as `cargo clippy -p ethlambda --all-targets -- -D warnings`, the only crate changed; CI runs the workspace - [ ] Ran `make test` (`test-consensus` plus `test-node`, at `release-fast`) — the three new tests run at `release-fast`; CI runs the rest
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Description
send_messagelogs every RPC dropped by a full send queue at WARN, with the whole RPC in the line. On an ethlambda beacon node subscribed to 64 attestation subnets, a slow peer produces one of these per heartbeat, each listing every IHAVE message id:The drop is already recorded: it increments
failed_messagesfor the peer and callsfailed_message_slow_peeron the score, so the log line adds nothing the counters do not. This PR logs the drop at DEBUG for non-priority RPCs (IHAVE, IWANT, publish, forward) and keeps WARN for control messages (GRAFT, PRUNE, IDONTWANT), since a dropped one leaves the peer's view of the mesh out of step with ours. Subscriptions never reach this branch:Queue::try_pushsends them on the unbounded priority queue.Based on
2f14d0ec, the commit ethlambda pins, so ethlambda can pick up this change alone without the rest of the branch.Notes & open questions
RawMessage'sDebugoutput and does not help IHAVE lists. Worth proposing upstream separately.cargo check,cargo fmt --checkandcargo clippy -p libp2p-gossipsubpass on the changed lines; the one clippy hit with rustc 1.98 (types.rs:228,useless_borrows_in_formatting) is pre-existing and not raised by the 1.93.1 clippy that CI pins.