cleanup and stats accounting organization

This commit is contained in:
John Smith
2021-11-26 09:54:38 -05:00
parent 311dc908fe
commit a80178da54
9 changed files with 341 additions and 231 deletions

View File

@@ -1,15 +1,5 @@
use super::*;
// Latency entry is per round-trip packet (ping or data)
// - Size is number of entries
const ROLLING_LATENCIES_SIZE: usize = 10;
// Transfers entries are in bytes total for the interval
// - Size is number of entries
// - Interval is number of seconds in each entry
const ROLLING_TRANSFERS_SIZE: usize = 10;
pub const ROLLING_TRANSFERS_INTERVAL_SECS: u32 = 10;
// Reliable pings are done with increased spacing between pings
// - Start secs is the number of seconds between the first two pings
// - Max secs is the maximum number of seconds between consecutive pings
@@ -42,9 +32,7 @@ pub struct BucketEntry {
min_max_version: Option<(u8, u8)>,
last_connection: Option<(ConnectionDescriptor, u64)>,
dial_info_entries: VecDeque<DialInfoEntry>,
rolling_latencies: VecDeque<u64>,
rolling_transfers: VecDeque<(u64, u64)>,
current_transfer: (u64, u64),
stats_accounting: StatsAccounting,
peer_stats: PeerStats,
}
@@ -55,15 +43,13 @@ impl BucketEntry {
min_max_version: None,
last_connection: None,
dial_info_entries: VecDeque::new(),
rolling_latencies: VecDeque::new(),
rolling_transfers: VecDeque::new(),
current_transfer: (0, 0),
stats_accounting: StatsAccounting::new(),
peer_stats: PeerStats {
time_added: get_timestamp(),
last_seen: None,
ping_stats: PingStats::default(),
latency: None,
transfer: (TransferStats::default(), TransferStats::default()),
transfer: TransferStatsDownUp::default(),
node_info: None,
},
}
@@ -213,10 +199,7 @@ impl BucketEntry {
}
pub fn last_connection(&self) -> Option<ConnectionDescriptor> {
match self.last_connection.as_ref() {
Some(x) => Some(x.0.clone()),
None => None,
}
self.last_connection.as_ref().map(|x| x.0.clone())
}
pub fn set_min_max_version(&mut self, min_max_version: (u8, u8)) {
@@ -248,71 +231,13 @@ impl BucketEntry {
///// stats methods
// called every ROLLING_TRANSFERS_INTERVAL_SECS seconds
pub(super) fn roll_transfers(&mut self, last_ts: u64, cur_ts: u64) {
let dur_ms = (cur_ts - last_ts) / 1000u64;
while self.rolling_transfers.len() >= ROLLING_TRANSFERS_SIZE {
self.rolling_transfers.pop_front();
}
self.rolling_transfers.push_back(self.current_transfer);
self.current_transfer = (0, 0);
let xd = &mut self.peer_stats.transfer.0;
let xu = &mut self.peer_stats.transfer.1;
xd.maximum = 0;
xu.maximum = 0;
xd.minimum = u64::MAX;
xu.minimum = u64::MAX;
xd.average = 0;
xu.average = 0;
for (rtd, rtu) in &self.rolling_transfers {
let bpsd = rtd * 1000u64 / dur_ms;
let bpsu = rtu * 1000u64 / dur_ms;
if bpsd > xd.maximum {
xd.maximum = bpsd;
}
if bpsu > xu.maximum {
xu.maximum = bpsu;
}
if bpsd < xd.minimum {
xd.minimum = bpsd;
}
if bpsu < xu.minimum {
xu.minimum = bpsu;
}
xd.average += bpsd;
xu.average += bpsu;
}
let len = self.rolling_transfers.len() as u64;
xd.average /= len;
xu.average /= len;
// total remains unchanged
self.stats_accounting
.roll_transfers(last_ts, cur_ts, &mut self.peer_stats.transfer);
}
// Called for every round trip packet we receive
fn record_latency(&mut self, latency: u64) {
while self.rolling_latencies.len() >= ROLLING_LATENCIES_SIZE {
self.rolling_latencies.pop_front();
}
self.rolling_latencies.push_back(latency);
let mut ls = LatencyStats {
fastest: 0,
average: 0,
slowest: 0,
};
for rl in &self.rolling_latencies {
if *rl < ls.fastest {
ls.fastest = *rl;
}
if *rl > ls.slowest {
ls.slowest = *rl;
}
ls.average += *rl;
}
let len = self.rolling_latencies.len() as u64;
ls.average /= len;
self.peer_stats.latency = Some(ls);
self.peer_stats.latency = Some(self.stats_accounting.record_latency(latency));
}
///// state machine handling
@@ -381,23 +306,23 @@ impl BucketEntry {
}
////////////////////////////////////////////////////////////////
/// Called by RPC processor as events happen
/// Called when rpc processor things happen
pub fn ping_sent(&mut self, ts: u64, bytes: u64) {
pub(super) fn ping_sent(&mut self, ts: u64, bytes: u64) {
self.peer_stats.ping_stats.total_sent += 1;
self.current_transfer.1 += bytes;
self.stats_accounting.add_up(bytes);
self.peer_stats.ping_stats.in_flight += 1;
self.peer_stats.ping_stats.last_pinged = Some(ts);
}
pub fn ping_rcvd(&mut self, ts: u64, bytes: u64) {
self.current_transfer.0 += bytes;
pub(super) fn ping_rcvd(&mut self, ts: u64, bytes: u64) {
self.stats_accounting.add_down(bytes);
self.touch_last_seen(ts);
}
pub fn pong_sent(&mut self, _ts: u64, bytes: u64) {
self.current_transfer.1 += bytes;
pub(super) fn pong_sent(&mut self, _ts: u64, bytes: u64) {
self.stats_accounting.add_up(bytes);
}
pub fn pong_rcvd(&mut self, send_ts: u64, recv_ts: u64, bytes: u64) {
self.current_transfer.0 += bytes;
pub(super) fn pong_rcvd(&mut self, send_ts: u64, recv_ts: u64, bytes: u64) {
self.stats_accounting.add_down(bytes);
self.peer_stats.ping_stats.in_flight -= 1;
self.peer_stats.ping_stats.total_returned += 1;
self.peer_stats.ping_stats.consecutive_pongs += 1;
@@ -412,28 +337,28 @@ impl BucketEntry {
self.record_latency(recv_ts - send_ts);
self.touch_last_seen(recv_ts);
}
pub fn ping_lost(&mut self, _ts: u64) {
pub(super) fn ping_lost(&mut self, _ts: u64) {
self.peer_stats.ping_stats.in_flight -= 1;
self.peer_stats.ping_stats.recent_lost_pings += 1;
self.peer_stats.ping_stats.consecutive_pongs = 0;
self.peer_stats.ping_stats.first_consecutive_pong_time = None;
}
pub fn question_sent(&mut self, _ts: u64, bytes: u64) {
self.current_transfer.1 += bytes;
pub(super) fn question_sent(&mut self, _ts: u64, bytes: u64) {
self.stats_accounting.add_up(bytes);
}
pub fn question_rcvd(&mut self, ts: u64, bytes: u64) {
self.current_transfer.0 += bytes;
pub(super) fn question_rcvd(&mut self, ts: u64, bytes: u64) {
self.stats_accounting.add_down(bytes);
self.touch_last_seen(ts);
}
pub fn answer_sent(&mut self, _ts: u64, bytes: u64) {
self.current_transfer.1 += bytes;
pub(super) fn answer_sent(&mut self, _ts: u64, bytes: u64) {
self.stats_accounting.add_up(bytes);
}
pub fn answer_rcvd(&mut self, send_ts: u64, recv_ts: u64, bytes: u64) {
self.current_transfer.0 += bytes;
pub(super) fn answer_rcvd(&mut self, send_ts: u64, recv_ts: u64, bytes: u64) {
self.stats_accounting.add_down(bytes);
self.record_latency(recv_ts - send_ts);
self.touch_last_seen(recv_ts);
}
pub fn question_lost(&mut self, _ts: u64) {
pub(super) fn question_lost(&mut self, _ts: u64) {
self.peer_stats.ping_stats.consecutive_pongs = 0;
self.peer_stats.ping_stats.first_consecutive_pong_time = None;
}

View File

@@ -3,12 +3,7 @@ mod bucket_entry;
mod dial_info_entry;
mod find_nodes;
mod node_ref;
use bucket::*;
pub use bucket_entry::*;
pub use dial_info_entry::*;
pub use find_nodes::*;
pub use node_ref::*;
mod stats_accounting;
use crate::dht::*;
use crate::intf::*;
@@ -18,7 +13,13 @@ use crate::xx::*;
use crate::*;
use alloc::collections::VecDeque;
use alloc::str::FromStr;
use bucket::*;
pub use bucket_entry::*;
pub use dial_info_entry::*;
pub use find_nodes::*;
use futures_util::stream::{FuturesUnordered, StreamExt};
pub use node_ref::*;
pub use stats_accounting::*;
//////////////////////////////////////////////////////////////////////////
@@ -42,16 +43,15 @@ struct RoutingTableInner {
node_id: DHTKey,
node_id_secret: DHTKeySecret,
buckets: Vec<Bucket>,
//recent_nodes: VecDeque<DHTKey>,
//closest_reliable_nodes: Vec<DHTKey>,
//fastest_reliable_nodes: Vec<DHTKey>,
//closest_nodes: Vec<DHTKey>,
//fastest_nodes: Vec<DHTKey>,
local_dial_info: Vec<DialInfoDetail>,
public_dial_info: Vec<DialInfoDetail>,
bucket_entry_count: usize,
// Waiters
eventual_changed_dial_info: Eventual,
// Transfer stats for this node
stats_accounting: StatsAccounting,
// latency: Option<LatencyStats>,
transfer_stats: TransferStatsDownUp,
}
struct RoutingTableUnlockedInner {
@@ -72,25 +72,22 @@ pub struct RoutingTable {
impl RoutingTable {
fn new_inner(network_manager: NetworkManager) -> RoutingTableInner {
RoutingTableInner {
network_manager: network_manager,
network_manager,
node_id: DHTKey::default(),
node_id_secret: DHTKeySecret::default(),
buckets: Vec::new(),
//recent_nodes: VecDeque::new(),
//closest_reliable_nodes: Vec::new(),
//fastest_reliable_nodes: Vec::new(),
//closest_nodes: Vec::new(),
//fastest_nodes: Vec::new(),
local_dial_info: Vec::new(),
public_dial_info: Vec::new(),
bucket_entry_count: 0,
eventual_changed_dial_info: Eventual::new(),
stats_accounting: StatsAccounting::new(),
transfer_stats: TransferStatsDownUp::default(),
}
}
fn new_unlocked_inner(config: VeilidConfig) -> RoutingTableUnlockedInner {
let c = config.get();
RoutingTableUnlockedInner {
rolling_transfers_task: TickTask::new(bucket_entry::ROLLING_TRANSFERS_INTERVAL_SECS),
rolling_transfers_task: TickTask::new(ROLLING_TRANSFERS_INTERVAL_SECS),
bootstrap_task: TickTask::new(1),
peer_minimum_refresh_task: TickTask::new_us(c.network.dht.min_peer_refresh_time),
ping_validator_task: TickTask::new(1),
@@ -155,7 +152,7 @@ impl RoutingTable {
pub fn has_local_dial_info(&self) -> bool {
let inner = self.inner.lock();
inner.local_dial_info.len() > 0
!inner.local_dial_info.is_empty()
}
pub fn local_dial_info(&self) -> Vec<DialInfoDetail> {
@@ -197,14 +194,14 @@ impl RoutingTable {
}
pub fn register_local_dial_info(&self, dial_info: DialInfo, origin: DialInfoOrigin) {
let ts = get_timestamp();
let timestamp = get_timestamp();
let mut inner = self.inner.lock();
inner.local_dial_info.push(DialInfoDetail {
dial_info: dial_info.clone(),
origin: origin,
origin,
network_class: None,
timestamp: ts,
timestamp,
});
info!(
@@ -224,7 +221,7 @@ impl RoutingTable {
pub fn has_public_dial_info(&self) -> bool {
let inner = self.inner.lock();
inner.public_dial_info.len() > 0
!inner.public_dial_info.is_empty()
}
pub fn public_dial_info(&self) -> Vec<DialInfoDetail> {
@@ -278,8 +275,8 @@ impl RoutingTable {
inner.public_dial_info.push(DialInfoDetail {
dial_info: dial_info.clone(),
origin: origin,
network_class: network_class,
origin,
network_class,
timestamp: ts,
});
@@ -466,10 +463,9 @@ impl RoutingTable {
let mut inner = self.inner.lock();
let idx = Self::find_bucket_index(&*inner, node_id);
let bucket = &mut inner.buckets[idx];
match bucket.entry_mut(&node_id) {
None => None,
Some(e) => Some(NodeRef::new(self.clone(), node_id, e)),
}
bucket
.entry_mut(&node_id)
.map(|e| NodeRef::new(self.clone(), node_id, e))
}
// Shortcut function to add a node to our routing table if it doesn't exist
@@ -629,7 +625,7 @@ impl RoutingTable {
let node_id = ndis.node_id.key;
bsmap
.entry(node_id)
.or_insert(Vec::new())
.or_insert_with(Vec::new)
.push(ndis.dial_info);
}
@@ -697,7 +693,14 @@ impl RoutingTable {
// Compute transfer statistics to determine how 'fast' a node is
async fn rolling_transfers_task_routine(self, last_ts: u64, cur_ts: u64) -> Result<(), String> {
let mut inner = self.inner.lock();
let inner = &mut *self.inner.lock();
// Roll our own node's transfers
inner
.stats_accounting
.roll_transfers(last_ts, cur_ts, &mut inner.transfer_stats);
// Roll all bucket entry transfers
for b in &mut inner.buckets {
b.roll_transfers(last_ts, cur_ts);
}
@@ -728,4 +731,66 @@ impl RoutingTable {
Ok(())
}
//////////////////////////////////////////////////////////////////////
// Stats Accounting
pub fn ping_sent(&self, node_ref: NodeRef, ts: u64, bytes: u64) {
self.inner.lock().stats_accounting.add_up(bytes);
node_ref.operate(|e| {
e.ping_sent(ts, bytes);
})
}
pub fn ping_rcvd(&self, node_ref: NodeRef, ts: u64, bytes: u64) {
self.inner.lock().stats_accounting.add_down(bytes);
node_ref.operate(|e| {
e.ping_rcvd(ts, bytes);
})
}
pub fn pong_sent(&self, node_ref: NodeRef, ts: u64, bytes: u64) {
self.inner.lock().stats_accounting.add_up(bytes);
node_ref.operate(|e| {
e.pong_sent(ts, bytes);
})
}
pub fn pong_rcvd(&self, node_ref: NodeRef, send_ts: u64, recv_ts: u64, bytes: u64) {
self.inner.lock().stats_accounting.add_down(bytes);
node_ref.operate(|e| {
e.pong_rcvd(send_ts, recv_ts, bytes);
})
}
pub fn ping_lost(&self, node_ref: NodeRef, ts: u64) {
node_ref.operate(|e| {
e.ping_lost(ts);
})
}
pub fn question_sent(&self, node_ref: NodeRef, ts: u64, bytes: u64) {
self.inner.lock().stats_accounting.add_up(bytes);
node_ref.operate(|e| {
e.question_sent(ts, bytes);
})
}
pub fn question_rcvd(&self, node_ref: NodeRef, ts: u64, bytes: u64) {
self.inner.lock().stats_accounting.add_down(bytes);
node_ref.operate(|e| {
e.question_rcvd(ts, bytes);
})
}
pub fn answer_sent(&self, node_ref: NodeRef, ts: u64, bytes: u64) {
self.inner.lock().stats_accounting.add_up(bytes);
node_ref.operate(|e| {
e.answer_sent(ts, bytes);
})
}
pub fn answer_rcvd(&self, node_ref: NodeRef, send_ts: u64, recv_ts: u64, bytes: u64) {
self.inner.lock().stats_accounting.add_down(bytes);
node_ref.operate(|e| {
e.answer_rcvd(send_ts, recv_ts, bytes);
})
}
pub fn question_lost(&self, node_ref: NodeRef, ts: u64) {
node_ref.operate(|e| {
e.question_lost(ts);
})
}
}

View File

@@ -0,0 +1,104 @@
use crate::xx::*;
use crate::*;
use alloc::collections::VecDeque;
// Latency entry is per round-trip packet (ping or data)
// - Size is number of entries
const ROLLING_LATENCIES_SIZE: usize = 10;
// Transfers entries are in bytes total for the interval
// - Size is number of entries
// - Interval is number of seconds in each entry
const ROLLING_TRANSFERS_SIZE: usize = 10;
pub const ROLLING_TRANSFERS_INTERVAL_SECS: u32 = 10;
#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
pub struct TransferCount {
down: u64,
up: u64,
}
#[derive(Debug, Clone, Default)]
pub struct StatsAccounting {
rolling_latencies: VecDeque<u64>,
rolling_transfers: VecDeque<TransferCount>,
current_transfer: TransferCount,
}
impl StatsAccounting {
pub fn new() -> Self {
Self {
rolling_latencies: VecDeque::new(),
rolling_transfers: VecDeque::new(),
current_transfer: TransferCount::default(),
}
}
pub fn add_down(&mut self, bytes: u64) {
self.current_transfer.down += bytes;
}
pub fn add_up(&mut self, bytes: u64) {
self.current_transfer.up += bytes;
}
pub fn roll_transfers(
&mut self,
last_ts: u64,
cur_ts: u64,
transfer_stats: &mut TransferStatsDownUp,
) {
let dur_ms = (cur_ts - last_ts) / 1000u64;
while self.rolling_transfers.len() >= ROLLING_TRANSFERS_SIZE {
self.rolling_transfers.pop_front();
}
self.rolling_transfers.push_back(self.current_transfer);
transfer_stats.down.total += self.current_transfer.down;
transfer_stats.up.total += self.current_transfer.up;
self.current_transfer = TransferCount::default();
transfer_stats.down.maximum = 0;
transfer_stats.up.maximum = 0;
transfer_stats.down.minimum = u64::MAX;
transfer_stats.up.minimum = u64::MAX;
transfer_stats.down.average = 0;
transfer_stats.up.average = 0;
for xfer in &self.rolling_transfers {
let bpsd = xfer.down * 1000u64 / dur_ms;
let bpsu = xfer.up * 1000u64 / dur_ms;
transfer_stats.down.maximum.max_assign(bpsd);
transfer_stats.up.maximum.max_assign(bpsu);
transfer_stats.down.minimum.min_assign(bpsd);
transfer_stats.up.minimum.min_assign(bpsu);
transfer_stats.down.average += bpsd;
transfer_stats.down.average += bpsu;
}
let len = self.rolling_transfers.len() as u64;
transfer_stats.down.average /= len;
transfer_stats.up.average /= len;
}
pub fn record_latency(&mut self, latency: u64) -> veilid_api::LatencyStats {
while self.rolling_latencies.len() >= ROLLING_LATENCIES_SIZE {
self.rolling_latencies.pop_front();
}
self.rolling_latencies.push_back(latency);
let mut ls = LatencyStats {
fastest: 0,
average: 0,
slowest: 0,
};
for rl in &self.rolling_latencies {
ls.fastest.min_assign(*rl);
ls.slowest.max_assign(*rl);
ls.average += *rl;
}
let len = self.rolling_latencies.len() as u64;
ls.average /= len;
ls
}
}