Files
foxhunt/monitoring/latency_tracker.rs
jgrusewski 030a15ee05 🔧 Emergency Fix: Resolve catastrophic _i32 suffix corruption (463→0 errors)
- Fixed systematic array indexing corruption: [0_i32] → [0]
- Fixed numeric literal suffixes across 835 files
- Fixed iterator patterns on RwLockReadGuard (.iter() required)
- Fixed float type annotations (365.25_f64 for sqrt)
- Fixed missing semicolons in position manager
- Fixed reference dereferencing in data loader

Root cause: Mass refactoring incorrectly added _i32 suffixes to array indices
Impact: Complete compilation failure (463 errors)
Resolution: Automated regex + targeted fixes
Result: 100% compilation success (0 errors)

Validated: cargo check --workspace passes
Ready for: Production deployment
2025-10-10 23:05:26 +02:00

417 lines
12 KiB
Rust

#![warn(missing_docs)]
//! Comprehensive P99 latency tracking for critical HFT operations
//!
//! This module provides high-precision latency measurement and percentile tracking
//! for all critical trading operations in the Foxhunt HFT system.
use hdrhistogram::Histogram;
use std::sync::{Arc, RwLock};
use std::time::Instant;
use std::collections::HashMap;
/// High-precision latency tracker using HDR histogram for accurate percentile calculations
pub struct LatencyTracker {
histogram: RwLock<Histogram<u64>>,
operation_name: String,
}
impl LatencyTracker {
/// Create a new latency tracker for a specific operation
pub fn new(operation_name: &str) -> Self {
Self {
histogram: RwLock::new(
Histogram::new_with_bounds(1, 60_000_000_000, 3).unwrap() // 1ns to 60s
),
operation_name: operation_name.to_string(),
}
}
/// Record a latency measurement in nanoseconds
pub fn record(&self, nanos: u64) {
if let Ok(mut hist) = self.histogram.write() {
let _ = hist.record(nanos);
}
}
/// Get the 99th percentile latency in nanoseconds
pub fn get_p99(&self) -> u64 {
self.histogram
.read()
.map(|hist| hist.value_at_percentile(99.0))
.unwrap_or(0)
}
/// Get the 50th percentile (median) latency in nanoseconds
pub fn get_p50(&self) -> u64 {
self.histogram
.read()
.map(|hist| hist.value_at_percentile(50.0))
.unwrap_or(0)
}
/// Get the 95th percentile latency in nanoseconds
pub fn get_p95(&self) -> u64 {
self.histogram
.read()
.map(|hist| hist.value_at_percentile(95.0))
.unwrap_or(0)
}
/// Get the 99.9th percentile latency in nanoseconds
pub fn get_p999(&self) -> u64 {
self.histogram
.read()
.map(|hist| hist.value_at_percentile(99.9))
.unwrap_or(0)
}
/// Get the maximum recorded latency in nanoseconds
pub fn get_max(&self) -> u64 {
self.histogram
.read()
.map(|hist| hist.max())
.unwrap_or(0)
}
/// Get the minimum recorded latency in nanoseconds
pub fn get_min(&self) -> u64 {
self.histogram
.read()
.map(|hist| hist.min())
.unwrap_or(0)
}
/// Get the mean latency in nanoseconds
pub fn get_mean(&self) -> f64 {
self.histogram
.read()
.map(|hist| hist.mean())
.unwrap_or(0.0)
}
/// Get the total number of recorded samples
pub fn get_count(&self) -> u64 {
self.histogram
.read()
.map(|hist| hist.len())
.unwrap_or(0)
}
/// Reset all recorded latencies
pub fn reset(&self) {
if let Ok(mut hist) = self.histogram.write() {
hist.reset();
}
}
/// Get comprehensive latency statistics
pub fn get_stats(&self) -> LatencyStats {
if let Ok(hist) = self.histogram.read() {
LatencyStats {
operation: self.operation_name.clone(),
count: hist.len(),
min: hist.min(),
max: hist.max(),
mean: hist.mean(),
p50: hist.value_at_percentile(50.0),
p95: hist.value_at_percentile(95.0),
p99: hist.value_at_percentile(99.0),
p999: hist.value_at_percentile(99.9),
}
} else {
LatencyStats::default_for_operation(&self.operation_name)
}
}
}
/// Comprehensive latency statistics for an operation
#[derive(Debug, Clone)]
pub struct LatencyStats {
/// Operation name
pub operation: String,
/// Total number of samples
pub count: u64,
/// Minimum latency (nanoseconds)
pub min: u64,
/// Maximum latency (nanoseconds)
pub max: u64,
/// Mean latency (nanoseconds)
pub mean: f64,
/// 50th percentile latency (nanoseconds)
pub p50: u64,
/// 95th percentile latency (nanoseconds)
pub p95: u64,
/// 99th percentile latency (nanoseconds)
pub p99: u64,
/// 99.9th percentile latency (nanoseconds)
pub p999: u64,
}
impl LatencyStats {
fn default_for_operation(operation: &str) -> Self {
Self {
operation: operation.to_string(),
count: 0,
min: 0,
max: 0,
mean: 0.0,
p50: 0,
p95: 0,
p99: 0,
p999: 0,
}
}
/// Convert nanoseconds to microseconds
pub fn p99_micros(&self) -> f64 {
self.p99 as f64 / 1_000.0
}
/// Convert nanoseconds to milliseconds
pub fn p99_millis(&self) -> f64 {
self.p99 as f64 / 1_000_000.0
}
/// Check if P99 latency exceeds threshold (in nanoseconds)
pub fn exceeds_p99_threshold(&self, threshold_nanos: u64) -> bool {
self.p99 > threshold_nanos
}
/// Format latency for human-readable output
pub fn format_p99(&self) -> String {
if self.p99 < 1_000 {
format!("{}ns", self.p99)
} else if self.p99 < 1_000_000 {
format!("{:.1}μs", self.p99 as f64 / 1_000.0)
} else if self.p99 < 1_000_000_000 {
format!("{:.1}ms", self.p99 as f64 / 1_000_000.0)
} else {
format!("{:.1}s", self.p99 as f64 / 1_000_000_000.0)
}
}
}
/// Global registry for all latency trackers in the system
pub struct LatencyRegistry {
trackers: RwLock<HashMap<String, Arc<LatencyTracker>>>,
}
impl LatencyRegistry {
/// Create a new latency registry
pub fn new() -> Self {
Self {
trackers: RwLock::new(HashMap::new()),
}
}
/// Get or create a latency tracker for an operation
pub fn get_tracker(&self, operation: &str) -> Arc<LatencyTracker> {
{
let trackers = self.trackers.read().unwrap();
if let Some(tracker) = trackers.get(operation) {
return Arc::clone(tracker);
}
}
let mut trackers = self.trackers.write().unwrap();
let tracker = Arc::new(LatencyTracker::new(operation));
trackers.insert(operation.to_string(), Arc::clone(&tracker));
tracker
}
/// Get all registered tracker statistics
pub fn get_all_stats(&self) -> Vec<LatencyStats> {
let trackers = self.trackers.read().unwrap();
trackers
.values()
.map(|tracker| tracker.get_stats())
.collect()
}
/// Reset all trackers
pub fn reset_all(&self) {
let trackers = self.trackers.read().unwrap();
for tracker in trackers.values() {
tracker.reset();
}
}
}
impl Default for LatencyRegistry {
fn default() -> Self {
Self::new()
}
}
/// RAII timer for automatic latency measurement
pub struct LatencyTimer {
tracker: Arc<LatencyTracker>,
start: Instant,
}
impl LatencyTimer {
/// Start timing an operation
pub fn start(tracker: Arc<LatencyTracker>) -> Self {
Self {
tracker,
start: Instant::now(),
}
}
/// Manually record the elapsed time (useful for early recording)
pub fn record_now(&self) {
let elapsed = self.start.elapsed().as_nanos() as u64;
self.tracker.record(elapsed);
}
}
impl Drop for LatencyTimer {
fn drop(&mut self) {
let elapsed = self.start.elapsed().as_nanos() as u64;
self.tracker.record(elapsed);
}
}
/// Global latency registry instance
static GLOBAL_REGISTRY: std::sync::OnceLock<LatencyRegistry> = std::sync::OnceLock::new();
/// Get the global latency registry
pub fn global_registry() -> &'static LatencyRegistry {
GLOBAL_REGISTRY.get_or_init(|| LatencyRegistry::new())
}
/// Convenience macro for timing operations
#[macro_export]
macro_rules! time_operation {
($operation:expr, $code:block) => {{
let tracker = $crate::monitoring::latency_tracker::global_registry()
.get_tracker($operation);
let _timer = $crate::monitoring::latency_tracker::LatencyTimer::start(tracker);
$code
}};
}
/// Convenience function to record a single latency measurement
pub fn record_latency(operation: &str, nanos: u64) {
let tracker = global_registry().get_tracker(operation);
tracker.record(nanos);
}
/// Critical HFT operation names for consistent tracking
pub mod operations {
/// Order placement latency
pub const ORDER_PLACEMENT: &str = "order_placement";
/// Order cancellation latency
pub const ORDER_CANCELLATION: &str = "order_cancellation";
/// Market data processing latency
pub const MARKET_DATA_PROCESSING: &str = "market_data_processing";
/// Risk check latency
pub const RISK_CHECK: &str = "risk_check";
/// Position update latency
pub const POSITION_UPDATE: &str = "position_update";
/// Trade execution latency
pub const TRADE_EXECUTION: &str = "trade_execution";
/// Signal generation latency
pub const SIGNAL_GENERATION: &str = "signal_generation";
/// Portfolio rebalancing latency
pub const PORTFOLIO_REBALANCING: &str = "portfolio_rebalancing";
/// Database write latency
pub const DATABASE_WRITE: &str = "database_write";
/// Database read latency
pub const DATABASE_READ: &str = "database_read";
/// Message queue publish latency
pub const MESSAGE_PUBLISH: &str = "message_publish";
/// Message queue consume latency
pub const MESSAGE_CONSUME: &str = "message_consume";
/// Broker API call latency
pub const BROKER_API_CALL: &str = "broker_api_call";
/// AI model inference latency
pub const AI_MODEL_INFERENCE: &str = "ai_model_inference";
/// End-to-end trade latency
pub const END_TO_END_TRADE: &str = "end_to_end_trade";
}
#[cfg(test)]
mod tests {
use super::*;
use std::thread;
use std::time::Duration;
#[test]
fn test_latency_tracker_basic() {
let tracker = LatencyTracker::new("test_operation");
// Record some test latencies
tracker.record(1000); // 1μs
tracker.record(2000); // 2μs
tracker.record(5000); // 5μs
tracker.record(10000); // 10μs
assert_eq!(tracker.get_count(), 4);
assert!(tracker.get_p50() > 0);
assert!(tracker.get_p99() > 0);
assert!(tracker.get_max() >= 10000);
assert!(tracker.get_min() <= 1000);
}
#[test]
fn test_latency_timer() {
let tracker = Arc::new(LatencyTracker::new("timer_test"));
let tracker_clone = Arc::clone(&tracker);
{
let _timer = LatencyTimer::start(tracker_clone);
thread::sleep(Duration::from_micros(100));
}
assert_eq!(tracker.get_count(), 1);
assert!(tracker.get_p99() > 50_000); // Should be > 50μs
}
#[test]
fn test_latency_registry() {
let registry = LatencyRegistry::new();
let tracker1 = registry.get_tracker("operation1");
let tracker2 = registry.get_tracker("operation2");
let tracker1_again = registry.get_tracker("operation1");
// Should return the same tracker for the same operation
assert!(Arc::ptr_eq(&tracker1, &tracker1_again));
tracker1.record(1000);
tracker2.record(2000);
let stats = registry.get_all_stats();
assert_eq!(stats.len(), 2);
}
#[test]
fn test_latency_stats_formatting() {
let tracker = LatencyTracker::new("format_test");
tracker.record(500); // 500ns
tracker.record(1500); // 1.5μs
tracker.record(1_500_000); // 1.5ms
let stats = tracker.get_stats();
let formatted = stats.format_p99();
// Should format appropriately based on magnitude
assert!(!formatted.is_empty());
}
#[test]
fn test_time_operation_macro() {
let result = time_operation!("macro_test", {
thread::sleep(Duration::from_micros(10));
42
});
assert_eq!(result, 42);
let tracker = global_registry().get_tracker("macro_test");
assert_eq!(tracker.get_count(), 1);
}
}