Skip to content
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

libp2p: Enhance logging targets for granular control #7494

Open
wants to merge 9 commits into
base: master
Choose a base branch
from
+239 −206
Open

libp2p: Enhance logging targets for granular control #7494

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
a766be7
libp2p/notifications: Fix log target
lexnv Feb 6, 2025
83d3939
libp2p/notif: Fix log for behaviour
lexnv Feb 6, 2025
5d73594
libp2p/notif: Fix target for upgrade
lexnv Feb 6, 2025
1621742
libp2p/notif: Fix target for service
lexnv Feb 6, 2025
e9c9293
libp2p/discovery: Fix log target
lexnv Feb 6, 2025
21f7214
libp2p/req-resp: Fix log target
lexnv Feb 6, 2025
5bd2c96
libp2p/service: Fix log target to constant
lexnv Feb 6, 2025
393ede3
Add PR doc
lexnv Feb 6, 2025
71027cb
Merge branch 'master' into lexnv/fine-control-logs-libp2p
lexnv Feb 11, 2025
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
18 changes: 18 additions & 0 deletions prdoc/pr_7494.prdoc
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
title: Enhance libp2p logging targets for granular control

doc:
- audience: [Node Dev, Node Operator]
description: |
This PR modifies the libp2p networking-specific log targets for granular control (e.g., just enabling trace for req-resp).

Previously, all logs were outputted to `sub-libp2p` target, flooding the log messages on busy validators.
- Discover: `sub-libp2p::discovery`;
- Notification/behaviour: `sub-libp2p::notification::behaviour`;
- Notification/handler: `sub-libp2p::notification::handler`;
- Notification/service: `sub-libp2p::notification::service`;
- Notification/upgrade: `sub-libp2p::notification::upgrade`;
- Request response: `sub-libp2p::request-response`.

crates:
- name: sc-network
bump: patch
65 changes: 34 additions & 31 deletions substrate/client/network/src/discovery.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,9 @@ use std::{
time::{Duration, Instant},
};

/// Logging target for the file.
const LOG_TARGET: &str = "sub-libp2p::discovery";

/// Maximum number of known external addresses that we will cache.
/// This only affects whether we will log whenever we (re-)discover
/// a given address.
Expand Down Expand Up @@ -262,7 +265,7 @@ impl DiscoveryConfig {
match TokioMdns::new(mdns::Config::default(), local_peer_id) {
Ok(mdns) => Toggle::from(Some(mdns)),
Err(err) => {
warn!(target: "sub-libp2p", "Failed to initialize mDNS: {:?}", err);
warn!(target: LOG_TARGET, "Failed to initialize mDNS: {:?}", err);
Toggle::from(None)
},
}
Expand Down Expand Up @@ -375,7 +378,7 @@ impl DiscoveryBehaviour {
if let Some(kademlia) = self.kademlia.as_mut() {
if !self.allow_non_globals_in_dht && !Self::can_add_to_dht(&addr) {
trace!(
target: "sub-libp2p",
target: LOG_TARGET,
"Ignoring self-reported non-global address {} from {}.", addr, peer_id
);
return
Expand All @@ -393,15 +396,15 @@ impl DiscoveryBehaviour {
.expect("kademlia protocol was checked above to be enabled; qed")
}) {
trace!(
target: "sub-libp2p",
target: LOG_TARGET,
"Ignoring self-reported address {} from {} as remote node is not part of the \
Kademlia DHT supported by the local node.", addr, peer_id,
);
return
}

trace!(
target: "sub-libp2p",
target: LOG_TARGET,
"Adding self-reported address {} from {} to Kademlia DHT.",
addr, peer_id
);
Expand All @@ -425,7 +428,7 @@ impl DiscoveryBehaviour {
pub fn put_value(&mut self, key: RecordKey, value: Vec<u8>) {
if let Some(k) = self.kademlia.as_mut() {
if let Err(e) = k.put_record(Record::new(key.clone(), value.clone()), Quorum::All) {
warn!(target: "sub-libp2p", "Libp2p => Failed to put record: {:?}", e);
warn!(target: LOG_TARGET, "Libp2p => Failed to put record: {:?}", e);
self.pending_events
.push_back(DiscoveryOut::ValuePutFailed(key.clone(), Duration::from_secs(0)));
}
Expand All @@ -444,7 +447,7 @@ impl DiscoveryBehaviour {
if let Some(kad) = self.kademlia.as_mut() {
if update_local_storage {
if let Err(_e) = kad.store_mut().put(record.clone()) {
warn!(target: "sub-libp2p", "Failed to update local starage");
warn!(target: LOG_TARGET, "Failed to update local starage");
}
}

Expand All @@ -462,7 +465,7 @@ impl DiscoveryBehaviour {
pub fn start_providing(&mut self, key: RecordKey) {
if let Some(kad) = self.kademlia.as_mut() {
if let Err(e) = kad.start_providing(key.clone()) {
warn!(target: "sub-libp2p", "Libp2p => Failed to start providing {key:?}: {e}.");
warn!(target: LOG_TARGET, "Libp2p => Failed to start providing {key:?}: {e}.");
self.pending_events.push_back(DiscoveryOut::StartProvidingFailed(key));
}
}
Expand Down Expand Up @@ -498,7 +501,7 @@ impl DiscoveryBehaviour {
expires,
}) {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Failed to store record with key: {:?}",
err
);
Expand Down Expand Up @@ -712,7 +715,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
});
}

trace!(target: "sub-libp2p", "Addresses of {:?}: {:?}", peer_id, list);
trace!(target: LOG_TARGET, "Addresses of {:?}: {:?}", peer_id, list);

Ok(list.into_iter().collect())
}
Expand Down Expand Up @@ -781,7 +784,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
if let Some(Protocol::P2p(peer_id)) = addr.iter().last() {
if peer_id != self.local_peer_id {
warn!(
target: "sub-libp2p",
target: LOG_TARGET,
"🔍 Discovered external address for a peer that is not us: {addr}",
);
// Ensure this address is not propagated to kademlia.
Expand All @@ -796,7 +799,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
// in which case we just want to refrain from logging.
if self.known_external_addresses.insert(address.clone()) {
info!(
target: "sub-libp2p",
target: LOG_TARGET,
"🔍 Discovered new external address for our node: {address}",
);
}
Expand All @@ -805,7 +808,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
self.kademlia.on_swarm_event(FromSwarm::ExternalAddrConfirmed(e));
},
event => {
debug!(target: "sub-libp2p", "New unknown `FromSwarm` libp2p event: {event:?}");
debug!(target: LOG_TARGET, "New unknown `FromSwarm` libp2p event: {event:?}");
self.kademlia.on_swarm_event(event);
},
}
Expand Down Expand Up @@ -834,15 +837,15 @@ impl NetworkBehaviour for DiscoveryBehaviour {
if self.num_connections < self.discovery_only_if_under_num {
let random_peer_id = PeerId::random();
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p <= Starting random Kademlia request for {:?}",
random_peer_id,
);
kademlia.get_closest_peers(random_peer_id);
true
} else {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Kademlia paused due to high number of connections ({})",
self.num_connections
);
Expand Down Expand Up @@ -899,20 +902,20 @@ impl NetworkBehaviour for DiscoveryBehaviour {
} => match res {
Err(GetClosestPeersError::Timeout { key, peers }) => {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Query for {:?} timed out with {} results",
HexDisplay::from(&key), peers.len(),
);
},
Ok(ok) => {
trace!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Query for {:?} yielded {:?} results",
HexDisplay::from(&ok.key), ok.peers.len(),
);
if ok.peers.is_empty() && self.num_connections != 0 {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Random Kademlia query has yielded empty results",
);
}
Expand All @@ -927,7 +930,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
let ev = match res {
Ok(GetRecordOk::FoundRecord(r)) => {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Found record ({:?}) with value: {:?} id {:?} stats {:?}",
r.record.key,
r.record.value,
Expand Down Expand Up @@ -959,7 +962,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
cache_candidates,
}) => {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Finished with no-additional-record {:?} stats {:?} took {:?} ms",
id,
stats,
Expand All @@ -986,7 +989,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
},
Err(e @ libp2p::kad::GetRecordError::NotFound { .. }) => {
trace!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Failed to get record: {:?}",
e,
);
Expand All @@ -997,7 +1000,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
},
Err(e) => {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Failed to get record: {:?}",
e,
);
Expand All @@ -1018,7 +1021,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
let ev = match res {
Ok(GetProvidersOk::FoundProviders { key, providers }) => {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Found providers {:?} for key {:?}, id {:?}, stats {:?}",
providers,
key,
Expand All @@ -1036,7 +1039,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
closest_peers: _,
}) => {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Finished with no additional providers {:?}, stats {:?}, took {:?} ms",
id,
stats,
Expand All @@ -1047,7 +1050,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
},
Err(GetProvidersError::Timeout { key, closest_peers: _ }) => {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Failed to get providers for {key:?} due to timeout.",
);

Expand All @@ -1069,7 +1072,7 @@ impl NetworkBehaviour for DiscoveryBehaviour {
DiscoveryOut::ValuePut(ok.key, stats.duration().unwrap_or_default()),
Err(e) => {
debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Failed to put record: {:?}",
e,
);
Expand All @@ -1086,12 +1089,12 @@ impl NetworkBehaviour for DiscoveryBehaviour {
..
} => match res {
Ok(ok) => debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Record republished: {:?}",
ok.key,
),
Err(e) => debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => Republishing of record {:?} failed with: {:?}",
e.key(), e,
),
Expand All @@ -1101,20 +1104,20 @@ impl NetworkBehaviour for DiscoveryBehaviour {
..
} => match res {
Ok(ok) => debug!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => DHT bootstrap progressed: {ok:?}",
),
Err(e) => warn!(
target: "sub-libp2p",
target: LOG_TARGET,
"Libp2p => DHT bootstrap error: {e:?}",
),
},
// We never start any other type of query.
KademliaEvent::OutboundQueryProgressed { result: e, .. } => {
warn!(target: "sub-libp2p", "Libp2p => Unhandled Kademlia event: {:?}", e)
warn!(target: LOG_TARGET, "Libp2p => Unhandled Kademlia event: {:?}", e)
},
Event::ModeChanged { new_mode } => {
debug!(target: "sub-libp2p", "Libp2p => Kademlia mode changed: {new_mode}")
debug!(target: LOG_TARGET, "Libp2p => Kademlia mode changed: {new_mode}")
},
},
ToSwarm::Dial { opts } => return Poll::Ready(ToSwarm::Dial { opts }),
Expand Down
Loading
Loading