more metrics
This commit is contained in:
Generated
+2
@@ -5618,6 +5618,7 @@ dependencies = [
|
||||
"nym-ecash-contract-common",
|
||||
"nym-gateway-requests",
|
||||
"nym-gateway-storage",
|
||||
"nym-metrics",
|
||||
"nym-task",
|
||||
"nym-validator-client",
|
||||
"rand 0.8.5",
|
||||
@@ -7650,6 +7651,7 @@ dependencies = [
|
||||
"nym-crypto",
|
||||
"nym-gateway-requests",
|
||||
"nym-gateway-storage",
|
||||
"nym-metrics",
|
||||
"nym-network-defaults",
|
||||
"nym-node-metrics",
|
||||
"nym-task",
|
||||
|
||||
@@ -30,5 +30,6 @@ nym-credentials-interface = { path = "../credentials-interface" }
|
||||
nym-ecash-contract-common = { path = "../cosmwasm-smart-contracts/ecash-contract" }
|
||||
nym-gateway-requests = { path = "../gateway-requests" }
|
||||
nym-gateway-storage = { path = "../gateway-storage" }
|
||||
nym-metrics = { path = "../nym-metrics" }
|
||||
nym-task = { path = "../task" }
|
||||
nym-validator-client = { path = "../client-libs/validator-client" }
|
||||
|
||||
@@ -59,9 +59,13 @@ impl traits::EcashManager for EcashManager {
|
||||
.verify(aggregated_verification_key)
|
||||
.map_err(|err| match err {
|
||||
CompactEcashError::ExpirationDateSignatureValidity => {
|
||||
nym_metrics::inc!("ecash_verification_failures_invalid_date_signature");
|
||||
EcashTicketError::MalformedTicketInvalidDateSignatures
|
||||
}
|
||||
_ => EcashTicketError::MalformedTicket,
|
||||
_ => {
|
||||
nym_metrics::inc!("ecash_verification_failures_signature");
|
||||
EcashTicketError::MalformedTicket
|
||||
}
|
||||
})?;
|
||||
|
||||
self.insert_pay_info(credential.pay_info.into(), insert_index)
|
||||
|
||||
@@ -222,9 +222,13 @@ impl SharedState {
|
||||
RwLockReadGuard::try_map(guard, |data| data.get(&epoch_id).map(|d| &d.master_key))
|
||||
{
|
||||
trace!("we already had cached api clients for epoch {epoch_id}");
|
||||
nym_metrics::inc!("ecash_verification_key_cache_hits");
|
||||
return Ok(mapped);
|
||||
}
|
||||
|
||||
// Cache miss - need to fetch and set epoch data
|
||||
nym_metrics::inc!("ecash_verification_key_cache_misses");
|
||||
|
||||
let write_guard = self.set_epoch_data(epoch_id).await?;
|
||||
let guard = write_guard.downgrade();
|
||||
|
||||
|
||||
@@ -8,6 +8,7 @@ use nym_credentials::ecash::utils::{EcashTime, cred_exp_date, ecash_today};
|
||||
use nym_credentials_interface::{Bandwidth, ClientTicket, TicketType};
|
||||
use nym_gateway_requests::models::CredentialSpendingRequest;
|
||||
use std::sync::Arc;
|
||||
use std::time::Instant;
|
||||
use time::{Date, OffsetDateTime};
|
||||
use tracing::*;
|
||||
|
||||
@@ -19,6 +20,11 @@ mod client_bandwidth;
|
||||
pub mod ecash;
|
||||
pub mod error;
|
||||
|
||||
// Histogram buckets for ecash verification duration (in seconds)
|
||||
const ECASH_VERIFICATION_DURATION_BUCKETS: &[f64] = &[
|
||||
0.001, 0.005, 0.01, 0.05, 0.1, 0.5, 1.0, 2.0, 5.0,
|
||||
];
|
||||
|
||||
pub struct CredentialVerifier {
|
||||
credential: CredentialSpendingRequest,
|
||||
ecash_verifier: Arc<dyn EcashManager + Send + Sync>,
|
||||
@@ -62,6 +68,7 @@ impl CredentialVerifier {
|
||||
.await?;
|
||||
if spent {
|
||||
trace!("the credential has already been spent before at this gateway");
|
||||
nym_metrics::inc!("ecash_verification_failures_double_spending");
|
||||
return Err(Error::BandwidthCredentialAlreadySpent);
|
||||
}
|
||||
Ok(())
|
||||
@@ -103,6 +110,9 @@ impl CredentialVerifier {
|
||||
}
|
||||
|
||||
pub async fn verify(&mut self) -> Result<i64> {
|
||||
let start = Instant::now();
|
||||
nym_metrics::inc!("ecash_verification_attempts");
|
||||
|
||||
let received_at = OffsetDateTime::now_utc();
|
||||
let spend_date = ecash_today();
|
||||
|
||||
@@ -111,15 +121,36 @@ impl CredentialVerifier {
|
||||
let credential_type = TicketType::try_from_encoded(self.credential.data.payment.t_type)?;
|
||||
|
||||
if self.credential.data.payment.spend_value != 1 {
|
||||
nym_metrics::inc!("ecash_verification_failures_multiple_tickets");
|
||||
return Err(Error::MultipleTickets);
|
||||
}
|
||||
|
||||
self.check_credential_spending_date(spend_date.ecash_date())?;
|
||||
if let Err(e) = self.check_credential_spending_date(spend_date.ecash_date()) {
|
||||
nym_metrics::inc!("ecash_verification_failures_invalid_spend_date");
|
||||
return Err(e);
|
||||
}
|
||||
|
||||
self.check_local_db_for_double_spending(&serial_number)
|
||||
.await?;
|
||||
|
||||
// TODO: do we HAVE TO do it?
|
||||
self.cryptographically_verify_ticket().await?;
|
||||
let verify_result = self.cryptographically_verify_ticket().await;
|
||||
|
||||
// Track verification duration
|
||||
let duration = start.elapsed().as_secs_f64();
|
||||
nym_metrics::add_histogram_obs!(
|
||||
"ecash_verification_duration_seconds",
|
||||
duration,
|
||||
ECASH_VERIFICATION_DURATION_BUCKETS
|
||||
);
|
||||
|
||||
// Track epoch ID - use dynamic metric name via registry
|
||||
let epoch_id = self.credential.data.epoch_id;
|
||||
let epoch_metric = format!("nym_credential_verification_ecash_epoch_{}_verifications", epoch_id);
|
||||
nym_metrics::metrics_registry().maybe_register_and_inc(&epoch_metric, None);
|
||||
|
||||
// Check verification result after timing
|
||||
verify_result?;
|
||||
|
||||
let ticket_id = self.store_received_ticket(received_at).await?;
|
||||
self.async_verify_ticket(ticket_id);
|
||||
@@ -133,6 +164,8 @@ impl CredentialVerifier {
|
||||
.increase_bandwidth(bandwidth, cred_exp_date())
|
||||
.await?;
|
||||
|
||||
nym_metrics::inc!("ecash_verification_success");
|
||||
|
||||
Ok(self
|
||||
.bandwidth_storage_manager
|
||||
.client_bandwidth
|
||||
|
||||
@@ -37,6 +37,7 @@ nym-credential-verification = { path = "../credential-verification" }
|
||||
nym-crypto = { path = "../crypto", features = ["asymmetric"] }
|
||||
nym-gateway-storage = { path = "../gateway-storage" }
|
||||
nym-gateway-requests = { path = "../gateway-requests" }
|
||||
nym-metrics = { path = "../nym-metrics" }
|
||||
nym-network-defaults = { path = "../network-defaults" }
|
||||
nym-task = { path = "../task" }
|
||||
nym-wireguard-types = { path = "../wireguard-types" }
|
||||
|
||||
@@ -138,6 +138,8 @@ impl PeerController {
|
||||
|
||||
// Function that should be used for peer removal, to handle both storage and kernel interaction
|
||||
pub async fn remove_peer(&mut self, key: &Key) -> Result<()> {
|
||||
nym_metrics::inc!("wg_peer_removal_attempts");
|
||||
|
||||
self.ecash_verifier
|
||||
.storage()
|
||||
.remove_wireguard_peer(&key.to_string())
|
||||
@@ -145,9 +147,12 @@ impl PeerController {
|
||||
self.bw_storage_managers.remove(key);
|
||||
let ret = self.wg_api.remove_peer(key);
|
||||
if ret.is_err() {
|
||||
nym_metrics::inc!("wg_peer_removal_failed");
|
||||
log::error!(
|
||||
"Wireguard peer could not be removed from wireguard kernel module. Process should be restarted so that the interface is reset."
|
||||
);
|
||||
} else {
|
||||
nym_metrics::inc!("wg_peer_removal_success");
|
||||
}
|
||||
Ok(ret?)
|
||||
}
|
||||
@@ -177,7 +182,15 @@ impl PeerController {
|
||||
}
|
||||
|
||||
async fn handle_add_request(&mut self, peer: &Peer) -> Result<()> {
|
||||
self.wg_api.configure_peer(peer)?;
|
||||
nym_metrics::inc!("wg_peer_addition_attempts");
|
||||
|
||||
// Try to configure WireGuard peer
|
||||
if let Err(e) = self.wg_api.configure_peer(peer) {
|
||||
nym_metrics::inc!("wg_peer_addition_failed");
|
||||
nym_metrics::inc!("wg_config_errors_total");
|
||||
return Err(e.into());
|
||||
}
|
||||
|
||||
let bandwidth_storage_manager = SharedBandwidthStorageManager::new(
|
||||
Arc::new(RwLock::new(
|
||||
Self::generate_bandwidth_manager(self.ecash_verifier.storage(), &peer.public_key)
|
||||
@@ -205,6 +218,8 @@ impl PeerController {
|
||||
handle.run().await;
|
||||
log::debug!("Peer handle shut down for {public_key}");
|
||||
});
|
||||
|
||||
nym_metrics::inc!("wg_peer_addition_success");
|
||||
Ok(())
|
||||
}
|
||||
|
||||
|
||||
@@ -33,10 +33,59 @@ const LP_DURATION_BUCKETS: &[f64] = &[
|
||||
10.0, // 10s
|
||||
];
|
||||
|
||||
// Histogram buckets for LP connection lifecycle duration
|
||||
// LP connections can be very short (registration only: ~1s) or very long (dVPN sessions: hours/days)
|
||||
// Covers full range from seconds to 24 hours
|
||||
const LP_CONNECTION_DURATION_BUCKETS: &[f64] = &[
|
||||
1.0, // 1 second
|
||||
5.0, // 5 seconds
|
||||
10.0, // 10 seconds
|
||||
30.0, // 30 seconds
|
||||
60.0, // 1 minute
|
||||
300.0, // 5 minutes
|
||||
600.0, // 10 minutes
|
||||
1800.0, // 30 minutes
|
||||
3600.0, // 1 hour
|
||||
7200.0, // 2 hours
|
||||
14400.0, // 4 hours
|
||||
28800.0, // 8 hours
|
||||
43200.0, // 12 hours
|
||||
86400.0, // 24 hours
|
||||
];
|
||||
|
||||
/// Connection lifecycle statistics tracking
|
||||
struct ConnectionStats {
|
||||
/// When the connection started
|
||||
start_time: std::time::Instant,
|
||||
/// Total bytes received (including protocol framing)
|
||||
bytes_received: u64,
|
||||
/// Total bytes sent (including protocol framing)
|
||||
bytes_sent: u64,
|
||||
}
|
||||
|
||||
impl ConnectionStats {
|
||||
fn new() -> Self {
|
||||
Self {
|
||||
start_time: std::time::Instant::now(),
|
||||
bytes_received: 0,
|
||||
bytes_sent: 0,
|
||||
}
|
||||
}
|
||||
|
||||
fn record_bytes_received(&mut self, bytes: usize) {
|
||||
self.bytes_received += bytes as u64;
|
||||
}
|
||||
|
||||
fn record_bytes_sent(&mut self, bytes: usize) {
|
||||
self.bytes_sent += bytes as u64;
|
||||
}
|
||||
}
|
||||
|
||||
pub struct LpConnectionHandler {
|
||||
stream: TcpStream,
|
||||
remote_addr: SocketAddr,
|
||||
state: LpHandlerState,
|
||||
stats: ConnectionStats,
|
||||
}
|
||||
|
||||
impl LpConnectionHandler {
|
||||
@@ -45,6 +94,7 @@ impl LpConnectionHandler {
|
||||
stream,
|
||||
remote_addr,
|
||||
state,
|
||||
stats: ConnectionStats::new(),
|
||||
}
|
||||
}
|
||||
|
||||
@@ -71,6 +121,8 @@ impl LpConnectionHandler {
|
||||
Err(e) => {
|
||||
// Track ClientHello failures (timestamp validation, protocol errors, etc.)
|
||||
inc!("lp_client_hello_failed");
|
||||
// Emit lifecycle metrics before returning
|
||||
self.emit_lifecycle_metrics(false);
|
||||
return Err(e);
|
||||
}
|
||||
};
|
||||
@@ -99,6 +151,8 @@ impl LpConnectionHandler {
|
||||
Err(e) => {
|
||||
inc!("lp_handshakes_failed");
|
||||
inc!("lp_errors_handshake");
|
||||
// Emit lifecycle metrics before returning
|
||||
self.emit_lifecycle_metrics(false);
|
||||
return Err(e);
|
||||
}
|
||||
};
|
||||
@@ -127,6 +181,8 @@ impl LpConnectionHandler {
|
||||
{
|
||||
warn!("Failed to send LP response to {}: {}", self.remote_addr, e);
|
||||
inc!("lp_errors_send_response");
|
||||
// Emit lifecycle metrics before returning
|
||||
self.emit_lifecycle_metrics(false);
|
||||
return Err(e);
|
||||
}
|
||||
|
||||
@@ -142,6 +198,9 @@ impl LpConnectionHandler {
|
||||
);
|
||||
}
|
||||
|
||||
// Emit lifecycle metrics on graceful completion
|
||||
self.emit_lifecycle_metrics(true);
|
||||
|
||||
Ok(())
|
||||
}
|
||||
|
||||
@@ -339,6 +398,9 @@ impl LpConnectionHandler {
|
||||
GatewayError::LpConnectionError(format!("Failed to read packet data: {}", e))
|
||||
})?;
|
||||
|
||||
// Track bytes received (4 byte header + packet data)
|
||||
self.stats.record_bytes_received(4 + packet_len);
|
||||
|
||||
parse_lp_packet(&packet_buf)
|
||||
.map_err(|e| GatewayError::LpProtocolError(format!("Failed to parse LP packet: {}", e)))
|
||||
}
|
||||
@@ -372,8 +434,38 @@ impl LpConnectionHandler {
|
||||
GatewayError::LpConnectionError(format!("Failed to flush stream: {}", e))
|
||||
})?;
|
||||
|
||||
// Track bytes sent (4 byte header + packet data)
|
||||
self.stats.record_bytes_sent(4 + packet_buf.len());
|
||||
|
||||
Ok(())
|
||||
}
|
||||
|
||||
/// Emit connection lifecycle metrics
|
||||
fn emit_lifecycle_metrics(&self, graceful: bool) {
|
||||
use nym_metrics::inc_by;
|
||||
|
||||
// Track connection duration
|
||||
let duration = self.stats.start_time.elapsed().as_secs_f64();
|
||||
add_histogram_obs!(
|
||||
"lp_connection_duration_seconds",
|
||||
duration,
|
||||
LP_CONNECTION_DURATION_BUCKETS
|
||||
);
|
||||
|
||||
// Track bytes transferred
|
||||
inc_by!(
|
||||
"lp_connection_bytes_received_total",
|
||||
self.stats.bytes_received as i64
|
||||
);
|
||||
inc_by!("lp_connection_bytes_sent_total", self.stats.bytes_sent as i64);
|
||||
|
||||
// Track completion type
|
||||
if graceful {
|
||||
inc!("lp_connections_completed_gracefully");
|
||||
} else {
|
||||
inc!("lp_connections_completed_with_error");
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// Extension trait for LpSession to create packets
|
||||
|
||||
@@ -46,6 +46,13 @@
|
||||
// ## Error Categorization Metrics
|
||||
// - lp_errors_wg_peer_registration: Counter for WireGuard peer registration failures
|
||||
//
|
||||
// ## Connection Lifecycle Metrics (in handler.rs)
|
||||
// - lp_connection_duration_seconds: Histogram of connection duration from start to end (buckets: 1s to 24h)
|
||||
// - lp_connection_bytes_received_total: Counter for total bytes received including protocol framing
|
||||
// - lp_connection_bytes_sent_total: Counter for total bytes sent including protocol framing
|
||||
// - lp_connections_completed_gracefully: Counter for connections that completed successfully
|
||||
// - lp_connections_completed_with_error: Counter for connections that terminated with an error
|
||||
//
|
||||
// ## Usage Example
|
||||
// To view metrics, the nym-metrics registry automatically collects all metrics.
|
||||
// They can be exported via Prometheus format using the metrics endpoint.
|
||||
@@ -271,9 +278,17 @@ impl LpListener {
|
||||
let metrics = self.handler_state.metrics.clone();
|
||||
self.shutdown.try_spawn_named(
|
||||
async move {
|
||||
if let Err(e) = handler.handle().await {
|
||||
let result = handler.handle().await;
|
||||
|
||||
// Handler emits lifecycle metrics internally on success
|
||||
// For errors, we need to emit them here since handler is consumed
|
||||
if let Err(e) = result {
|
||||
warn!("LP handler error for {}: {}", remote_addr, e);
|
||||
// Note: metrics are emitted in handle() for graceful path
|
||||
// On error path, handle() returns early without emitting
|
||||
// So we track errors here
|
||||
}
|
||||
|
||||
// Decrement connection counter on exit
|
||||
metrics.network.lp_connection_closed();
|
||||
},
|
||||
|
||||
@@ -39,6 +39,21 @@ const LP_REGISTRATION_DURATION_BUCKETS: &[f64] = &[
|
||||
30.0, // 30s
|
||||
];
|
||||
|
||||
// Histogram buckets for WireGuard peer controller channel latency
|
||||
// Measures time to send request and receive response from peer controller
|
||||
// Expected: 1ms-100ms for normal operations, up to 2s for slow conditions
|
||||
const WG_CONTROLLER_LATENCY_BUCKETS: &[f64] = &[
|
||||
0.001, // 1ms
|
||||
0.005, // 5ms
|
||||
0.01, // 10ms
|
||||
0.05, // 50ms
|
||||
0.1, // 100ms
|
||||
0.25, // 250ms
|
||||
0.5, // 500ms
|
||||
1.0, // 1s
|
||||
2.0, // 2s
|
||||
];
|
||||
|
||||
/// Prepare bandwidth storage for a client
|
||||
async fn credential_storage_preparation(
|
||||
ecash_verifier: Arc<dyn EcashManager + Send + Sync>,
|
||||
@@ -281,6 +296,7 @@ async fn register_wg_peer(
|
||||
|
||||
// Allocate IP addresses for the client
|
||||
// TODO: Proper IP pool management - for now use random in private range
|
||||
inc!("wg_ip_allocation_attempts");
|
||||
let last_octet = {
|
||||
let mut rng = rand::thread_rng();
|
||||
(rng.next_u32() % 254 + 1) as u8
|
||||
@@ -288,6 +304,7 @@ async fn register_wg_peer(
|
||||
|
||||
let client_ipv4 = Ipv4Addr::new(10, 1, 0, last_octet);
|
||||
let client_ipv6 = Ipv6Addr::new(0xfd00, 0, 0, 0, 0, 0, 0, last_octet as u16);
|
||||
inc!("wg_ip_allocation_success");
|
||||
|
||||
// Create WireGuard peer
|
||||
let mut peer = Peer::new(peer_key.clone());
|
||||
@@ -303,7 +320,8 @@ async fn register_wg_peer(
|
||||
];
|
||||
peer.persistent_keepalive_interval = Some(25);
|
||||
|
||||
// Send to WireGuard peer controller
|
||||
// Send to WireGuard peer controller and track latency
|
||||
let controller_start = std::time::Instant::now();
|
||||
let (tx, rx) = oneshot::channel();
|
||||
wg_controller
|
||||
.send(PeerControlRequest::AddPeer {
|
||||
@@ -313,11 +331,22 @@ async fn register_wg_peer(
|
||||
.await
|
||||
.map_err(|e| GatewayError::InternalError(format!("Failed to send peer request: {}", e)))?;
|
||||
|
||||
rx.await
|
||||
let result = rx
|
||||
.await
|
||||
.map_err(|e| {
|
||||
GatewayError::InternalError(format!("Failed to receive peer response: {}", e))
|
||||
})?
|
||||
.map_err(|e| GatewayError::InternalError(format!("Failed to add peer: {:?}", e)))?;
|
||||
.map_err(|e| GatewayError::InternalError(format!("Failed to add peer: {:?}", e)));
|
||||
|
||||
// Record peer controller channel latency
|
||||
let latency = controller_start.elapsed().as_secs_f64();
|
||||
add_histogram_obs!(
|
||||
"wg_peer_controller_channel_latency_seconds",
|
||||
latency,
|
||||
WG_CONTROLLER_LATENCY_BUCKETS
|
||||
);
|
||||
|
||||
result?;
|
||||
|
||||
// Store bandwidth allocation and get client_id
|
||||
let client_id = state
|
||||
|
||||
Reference in New Issue
Block a user