time to establish connection (#3134)

Implementing #2745 , adding  a metric to break down time from connection pending to connection established, per protocol stack.

````
$curl -s http://127.0.0.1:42183/metrics | grep nt_duration
# HELP libp2p_swarm_connection_establishment_duration Time it took (locally) to finish establishing connections.
# TYPE libp2p_swarm_connection_establishment_duration histogram
libp2p_swarm_connection_establishment_duration_sum{role="Listener",protocols="/ip4/tcp"} 0.007
libp2p_swarm_connection_establishment_duration_count{role="Listener",protocols="/ip4/tcp"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.001"} 0
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.002"} 0
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.004"} 0
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.008"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.016"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.032"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.064"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.128"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.256"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="0.512"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Listener",protocols="/ip4/tcp",le="+Inf"} 1

lbl@chomp:~lbl
$curl -s http://127.0.0.1:34283/metrics | grep nt_duration
# HELP libp2p_swarm_connection_establishment_duration Time it took (locally) to finish establishing connections.
# TYPE libp2p_swarm_connection_establishment_duration histogram
libp2p_swarm_connection_establishment_duration_sum{role="Dialer",protocols="/ip4/tcp"} 0.009
libp2p_swarm_connection_establishment_duration_count{role="Dialer",protocols="/ip4/tcp"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.001"} 0
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.002"} 0
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.004"} 0
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.008"} 0
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.016"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.032"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.064"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.128"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.256"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="0.512"} 1
libp2p_swarm_connection_establishment_duration_bucket{role="Dialer",protocols="/ip4/tcp",le="+Inf"} 1
````
This commit is contained in:
John Turpish
2022-12-12 09:40:36 -05:00
committed by GitHub
parent 63ffc7fb0f
commit f8f19baad0
6 changed files with 58 additions and 10 deletions

View File

@ -38,6 +38,7 @@ use futures::{
ready,
stream::FuturesUnordered,
};
use instant::Instant;
use libp2p_core::connection::{ConnectionId, Endpoint, PendingPoint};
use libp2p_core::muxing::{StreamMuxerBox, StreamMuxerExt};
use std::{
@ -195,6 +196,8 @@ struct PendingConnection<THandler> {
endpoint: PendingPoint,
/// When dropped, notifies the task which then knows to terminate.
abort_notifier: Option<oneshot::Sender<Void>>,
/// The moment we became aware of this possible connection, useful for timing metrics.
accepted_at: Instant,
}
impl<THandler> PendingConnection<THandler> {
@ -237,6 +240,8 @@ where
/// Addresses are dialed in parallel. Contains the addresses and errors
/// of dial attempts that failed before the one successful dial.
concurrent_dial_errors: Option<Vec<(Multiaddr, TransportError<TTrans::Error>)>>,
/// How long it took to establish this connection.
established_in: std::time::Duration,
},
/// An established connection was closed.
@ -493,6 +498,7 @@ where
handler,
endpoint,
abort_notifier: Some(abort_notifier),
accepted_at: Instant::now(),
},
);
Ok(connection_id)
@ -540,6 +546,7 @@ where
handler,
endpoint: endpoint.into(),
abort_notifier: Some(abort_notifier),
accepted_at: Instant::now(),
},
);
Ok(connection_id)
@ -634,6 +641,7 @@ where
handler,
endpoint,
abort_notifier: _,
accepted_at,
} = self
.pending
.remove(&id)
@ -783,13 +791,14 @@ where
)
.boxed(),
);
let established_in = accepted_at.elapsed();
return Poll::Ready(PoolEvent::ConnectionEstablished {
peer_id: obtained_peer_id,
endpoint,
id,
other_established_connection_ids,
concurrent_dial_errors,
established_in,
});
}
task::PendingConnectionEvent::PendingFailed { id, error } => {
@ -798,6 +807,7 @@ where
handler,
endpoint,
abort_notifier: _,
accepted_at: _, // Ignoring the time it took for the connection to fail.
}) = self.pending.remove(&id)
{
self.counters.dec_pending(&endpoint);

View File

@ -191,6 +191,8 @@ pub enum SwarmEvent<TBehaviourOutEvent, THandlerErr> {
/// Addresses are dialed concurrently. Contains the addresses and errors
/// of dial attempts that failed before the one successful dial.
concurrent_dial_errors: Option<Vec<(Multiaddr, TransportError<io::Error>)>>,
/// How long it took to establish this connection
established_in: std::time::Duration,
},
/// A connection with the given peer has been closed,
/// possibly as a result of an error.
@ -808,6 +810,7 @@ where
endpoint,
other_established_connection_ids,
concurrent_dial_errors,
established_in,
} => {
if self.banned_peers.contains(&peer_id) {
// Mark the connection for the banned peer as banned, thus withholding any
@ -848,6 +851,7 @@ where
num_established,
endpoint,
concurrent_dial_errors,
established_in,
});
}
}