Skip to content
This repository has been archived by the owner on Nov 15, 2023. It is now read-only.

Improve warning about notifications queue and remove spurious triggers #5512

Merged
merged 5 commits into from
Apr 3, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
19 changes: 12 additions & 7 deletions client/network/src/protocol/generic_proto/handler/notif_out.rs
Original file line number Diff line number Diff line change
Expand Up @@ -79,13 +79,14 @@ impl IntoProtocolsHandler for NotifsOutHandlerProto {
DeniedUpgrade
}

fn into_handler(self, _: &PeerId, _: &ConnectedPoint) -> Self::Handler {
fn into_handler(self, peer_id: &PeerId, _: &ConnectedPoint) -> Self::Handler {
NotifsOutHandler {
protocol_name: self.protocol_name,
when_connection_open: Instant::now(),
queue_size_report: self.queue_size_report,
state: State::Disabled,
events_queue: SmallVec::new(),
peer_id: peer_id.clone(),
}
}
}
Expand Down Expand Up @@ -116,6 +117,9 @@ pub struct NotifsOutHandler {
/// This queue must only ever be modified to insert elements at the back, or remove the first
/// element.
events_queue: SmallVec<[ProtocolsHandlerEvent<NotificationsOut, (), NotifsOutHandlerOut, void::Void>; 16]>,

/// Who we are connected to.
peer_id: PeerId,
}

/// Our relationship with the node we're connected to.
Expand Down Expand Up @@ -308,16 +312,17 @@ impl ProtocolsHandler for NotifsOutHandler {

NotifsOutHandlerIn::Send(msg) =>
if let State::Open { substream, .. } = &mut self.state {
if let Some(Ok(_)) = substream.send(msg).now_or_never() {
if let Some(metric) = &self.queue_size_report {
metric.observe(substream.queue_len() as f64);
}
} else {
if substream.push_message(msg).is_err() {
log::warn!(
target: "sub-libp2p",
"📞 Failed to push message to queue, dropped it"
"📞 Notifications queue with peer {} is full, dropped message (protocol: {:?})",
self.peer_id,
self.protocol_name,
);
}
if let Some(metric) = &self.queue_size_report {
metric.observe(substream.queue_len() as f64);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In regards to observing even though the message is dropped: If we only observe when the message was actually sent, the histogram count metric would tell us how many messages went into the channel. Later on we could add an additional metric (a simple counter) to count the messages being dropped. What do you think @tomaka? Would that enable us to deeper understand the behavior?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Totally fine if you see this more as a hack than a useful feature.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The way I see it, dropping messages is something that is really not supposed to happen, and knowing how many messages are dropped isn't necessarily useful, as we have to treat 1 dropped message the same as 500 dropped messages.

Additionally #5481 would consist in reworking this code anyway.

}
} else {
// This is an API misuse.
log::warn!(
Expand Down
22 changes: 14 additions & 8 deletions client/network/src/protocol/generic_proto/upgrade/notifications.rs
Original file line number Diff line number Diff line change
Expand Up @@ -43,8 +43,7 @@ use unsigned_varint::codec::UviBytes;

/// Maximum allowed size of the two handshake messages, in bytes.
const MAX_HANDSHAKE_SIZE: usize = 1024;
/// Maximum number of buffered messages before we consider the remote unresponsive and kill the
/// substream.
/// Maximum number of buffered messages before we refuse to accept more.
const MAX_PENDING_MESSAGES: usize = 256;

/// Upgrade that accepts a substream, sends back a status message, then becomes a unidirectional
Expand Down Expand Up @@ -285,6 +284,18 @@ impl<TSubstream> NotificationsOutSubstream<TSubstream> {
pub fn queue_len(&self) -> u32 {
u32::try_from(self.messages_queue.len()).unwrap_or(u32::max_value())
}

/// Push a message to the queue of messages.
///
/// This has the same effect as the `Sink::start_send` implementation.
pub fn push_message(&mut self, item: Vec<u8>) -> Result<(), NotificationsOutError> {
if self.messages_queue.len() >= MAX_PENDING_MESSAGES {
return Err(NotificationsOutError::Clogged);
}

self.messages_queue.push_back(item);
Ok(())
}
}

impl<TSubstream> Sink<Vec<u8>> for NotificationsOutSubstream<TSubstream>
Expand All @@ -297,12 +308,7 @@ impl<TSubstream> Sink<Vec<u8>> for NotificationsOutSubstream<TSubstream>
}

fn start_send(mut self: Pin<&mut Self>, item: Vec<u8>) -> Result<(), Self::Error> {
if self.messages_queue.len() >= MAX_PENDING_MESSAGES {
return Err(NotificationsOutError::Clogged);
}

self.messages_queue.push_back(item);
Ok(())
self.push_message(item)
}

fn poll_flush(self: Pin<&mut Self>, cx: &mut Context) -> Poll<Result<(), Self::Error>> {
Expand Down