refactor(logging): standardize concurrency and trusted proxy events (#3417)

* refactor(logging): standardize concurrency and proxy events

* chore(logging): extend guardrails for concurrency and proxies

* feat(skill): add rustfs logging governance skill
This commit is contained in:
houseme
2026-06-14 01:00:26 +08:00
committed by GitHub
parent 88d2c6ad5c
commit 9059a9c68d
19 changed files with 1363 additions and 120 deletions
+18 -2
View File
@@ -102,7 +102,15 @@ impl DeadlockManager {
*running = true;
drop(running);
tracing::info!("Deadlock detection started");
tracing::info!(
event = "deadlock_monitor.lifecycle",
component = "concurrency",
subsystem = "deadlock",
state = "started",
check_interval_ms = self.config.check_interval.as_millis(),
hang_threshold_ms = self.config.hang_threshold.as_millis(),
"deadlock monitor state changed"
);
}
/// Stop the deadlock detection
@@ -110,7 +118,15 @@ impl DeadlockManager {
let mut running = self.running.lock().await;
*running = false;
tracing::info!("Deadlock detection stopped");
tracing::info!(
event = "deadlock_monitor.lifecycle",
component = "concurrency",
subsystem = "deadlock",
state = "stopped",
check_interval_ms = self.config.check_interval.as_millis(),
hang_threshold_ms = self.config.hang_threshold.as_millis(),
"deadlock monitor state changed"
);
}
/// Create a request tracker
+10 -2
View File
@@ -138,9 +138,13 @@ impl<G> OptimizedLockGuard<G> {
lock_metrics::record_lock_hold_time(hold_time);
tracing::debug!(
event = "lock_guard.release",
component = "concurrency",
subsystem = "lock",
release_mode = "early",
resource = %self.resource,
hold_time_ms = hold_time.as_millis(),
"Lock released early (optimization active)"
"lock guard released"
);
}
@@ -161,9 +165,13 @@ impl<G> Drop for OptimizedLockGuard<G> {
lock_metrics::record_lock_hold_time(hold_time);
tracing::debug!(
event = "lock_guard.release",
component = "concurrency",
subsystem = "lock",
release_mode = "drop",
resource = %self.resource,
hold_time_ms = hold_time.as_millis(),
"Lock released on drop (normal release)"
"lock guard released"
);
}
}
+17 -7
View File
@@ -233,12 +233,16 @@ impl ConcurrencyManager {
}
tracing::info!(
"Concurrency manager started (timeout={}, lock={}, deadlock={}, backpressure={}, scheduler={})",
self.is_timeout_enabled(),
self.is_lock_enabled(),
self.is_deadlock_enabled(),
self.is_backpressure_enabled(),
self.is_scheduler_enabled()
event = "concurrency_manager.lifecycle",
component = "concurrency",
subsystem = "manager",
state = "started",
timeout_enabled = self.is_timeout_enabled(),
lock_enabled = self.is_lock_enabled(),
deadlock_enabled = self.is_deadlock_enabled(),
backpressure_enabled = self.is_backpressure_enabled(),
scheduler_enabled = self.is_scheduler_enabled(),
"concurrency manager state changed"
);
}
@@ -249,7 +253,13 @@ impl ConcurrencyManager {
self.deadlock.stop().await;
}
tracing::info!("Concurrency manager stopped");
tracing::info!(
event = "concurrency_manager.lifecycle",
component = "concurrency",
subsystem = "manager",
state = "stopped",
"concurrency manager state changed"
);
}
}
+50 -4
View File
@@ -16,7 +16,7 @@
use std::sync::Arc;
use tokio::sync::{Mutex, Notify};
use tracing::info;
use tracing::{debug, trace};
/// Cooperative worker-slot controller for async tasks.
pub struct Workers {
@@ -43,12 +43,30 @@ impl Workers {
pub async fn take(&self) {
loop {
let mut available = self.available.lock().await;
info!("worker take, {}", *available);
if *available == 0 {
trace!(
event = "worker_slot.acquire",
component = "concurrency",
subsystem = "workers",
state = "waiting",
available_slots = *available,
total_slots = self.limit,
"worker slot pending"
);
drop(available);
self.notify.notified().await;
} else {
*available -= 1;
trace!(
event = "worker_slot.acquire",
component = "concurrency",
subsystem = "workers",
state = "granted",
available_slots = *available,
total_slots = self.limit,
permits_in_use = self.limit.saturating_sub(*available),
"worker slot updated"
);
break;
}
}
@@ -57,8 +75,17 @@ impl Workers {
/// Release a worker slot.
pub async fn give(&self) {
let mut available = self.available.lock().await;
info!("worker give, {}", *available);
*available = (*available).saturating_add(1).min(self.limit); // avoid over-release beyond limit
trace!(
event = "worker_slot.release",
component = "concurrency",
subsystem = "workers",
state = "released",
available_slots = *available,
total_slots = self.limit,
permits_in_use = self.limit.saturating_sub(*available),
"worker slot updated"
);
self.notify.notify_one(); // Notify a waiting task
}
@@ -70,11 +97,30 @@ impl Workers {
if *available == self.limit {
break;
}
trace!(
event = "worker_slot.wait",
component = "concurrency",
subsystem = "workers",
state = "waiting",
available_slots = *available,
total_slots = self.limit,
permits_in_use = self.limit.saturating_sub(*available),
"worker drain pending"
);
}
// Wait until all slots are freed
self.notify.notified().await;
}
info!("worker wait end");
debug!(
event = "worker_slot.wait",
component = "concurrency",
subsystem = "workers",
state = "drained",
available_slots = self.limit,
total_slots = self.limit,
permits_in_use = 0,
"worker drain complete"
);
}
/// Return the current number of available worker slots.
+111 -13
View File
@@ -157,12 +157,30 @@ pub trait CloudMetadataFetcher: Send + Sync {
match self.fetch_network_cidrs().await {
Ok(cidrs) => ranges.extend(cidrs),
Err(e) => warn!("Failed to fetch network CIDRs from {}: {}", self.provider_name(), e),
Err(e) => warn!(
event = "trusted_proxies.cloud_fetch",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = self.provider_name(),
dataset = "network_cidrs",
result = "degraded",
error = %e,
"trusted proxy cloud metadata fetch degraded"
),
}
match self.fetch_public_ip_ranges().await {
Ok(public_ranges) => ranges.extend(public_ranges),
Err(e) => warn!("Failed to fetch public IP ranges from {}: {}", self.provider_name(), e),
Err(e) => warn!(
event = "trusted_proxies.cloud_fetch",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = self.provider_name(),
dataset = "public_ip_ranges",
result = "degraded",
error = %e,
"trusted proxy cloud metadata fetch degraded"
),
}
Ok(ranges)
@@ -208,7 +226,13 @@ impl CloudDetector {
/// Fetches trusted IP ranges for the detected cloud provider.
pub async fn fetch_trusted_ranges(&self) -> Result<Vec<ipnetwork::IpNetwork>, AppError> {
if !self.enabled {
debug!("Cloud metadata fetching is disabled");
debug!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
state = "disabled",
"trusted proxy cloud detection skipped"
);
return Ok(Vec::new());
}
@@ -216,36 +240,87 @@ impl CloudDetector {
match provider {
Some(CloudProvider::Aws) => {
info!("Detected AWS environment, fetching metadata");
info!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = "aws",
result = "detected",
timeout_ms = self.timeout.as_millis(),
"trusted proxy cloud provider detected"
);
let fetcher = crate::AwsMetadataFetcher::new(self.timeout);
fetcher.fetch_trusted_proxy_ranges().await
}
Some(CloudProvider::Azure) => {
info!("Detected Azure environment, fetching metadata");
info!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = "azure",
result = "detected",
timeout_ms = self.timeout.as_millis(),
"trusted proxy cloud provider detected"
);
let fetcher = crate::AzureMetadataFetcher::new(self.timeout);
fetcher.fetch_trusted_proxy_ranges().await
}
Some(CloudProvider::Gcp) => {
info!("Detected GCP environment, fetching metadata");
info!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = "gcp",
result = "detected",
timeout_ms = self.timeout.as_millis(),
"trusted proxy cloud provider detected"
);
let fetcher = crate::GcpMetadataFetcher::new(self.timeout);
fetcher.fetch_trusted_proxy_ranges().await
}
Some(CloudProvider::Cloudflare) => {
info!("Detected Cloudflare environment");
info!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = "cloudflare",
result = "detected",
"trusted proxy cloud provider detected"
);
let ranges = crate::CloudflareIpRanges::fetch().await?;
Ok(ranges)
}
Some(CloudProvider::DigitalOcean) => {
info!("Detected DigitalOcean environment");
info!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = "digitalocean",
result = "detected",
"trusted proxy cloud provider detected"
);
let ranges = crate::DigitalOceanIpRanges::fetch().await?;
Ok(ranges)
}
Some(CloudProvider::Unknown(name)) => {
warn!("Unknown cloud provider detected: {}", name);
warn!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = %name,
result = "unknown",
"trusted proxy cloud provider unresolved"
);
Ok(Vec::new())
}
None => {
debug!("No cloud provider detected");
debug!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
result = "none",
"trusted proxy cloud provider not detected"
);
Ok(Vec::new())
}
}
@@ -265,17 +340,40 @@ impl CloudDetector {
for provider in providers {
let provider_name = provider.provider_name();
debug!("Trying to fetch metadata from {}", provider_name);
debug!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = provider_name,
result = "attempt",
"trusted proxy cloud provider fetch attempted"
);
match provider.fetch_trusted_proxy_ranges().await {
Ok(ranges) => {
if !ranges.is_empty() {
info!("Fetched {} IP ranges from {}", ranges.len(), provider_name);
info!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = provider_name,
result = "loaded",
range_count = ranges.len(),
"trusted proxy cloud provider ranges loaded"
);
return Ok(ranges);
}
}
Err(e) => {
debug!("Failed to fetch metadata from {}: {}", provider_name, e);
debug!(
event = "trusted_proxies.cloud_detect",
component = "trusted_proxies",
subsystem = "cloud_detector",
provider = provider_name,
result = "failed",
error = %e,
"trusted proxy cloud provider fetch failed"
);
}
}
}
@@ -67,12 +67,30 @@ impl AwsMetadataFetcher {
.map_err(|e| AppError::cloud(format!("Failed to read IMDSv2 token: {}", e)))?;
Ok(token)
} else {
debug!("IMDSv2 token request failed with status: {}", response.status());
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "aws_metadata",
provider = "aws",
operation = "imdsv2_token",
result = "http_error",
status = %response.status(),
"trusted proxy cloud metadata request failed"
);
Err(AppError::cloud("Failed to obtain IMDSv2 token"))
}
}
Err(e) => {
debug!("IMDSv2 token request failed: {}", e);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "aws_metadata",
provider = "aws",
operation = "imdsv2_token",
result = "request_failed",
error = %e,
"trusted proxy cloud metadata request failed"
);
Err(AppError::cloud(format!("IMDSv2 request failed: {}", e)))
}
}
@@ -97,7 +115,17 @@ impl CloudMetadataFetcher for AwsMetadataFetcher {
match networks {
Ok(networks) => {
debug!("Using default AWS VPC network ranges");
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "aws_metadata",
provider = "aws",
operation = "network_cidrs",
result = "fallback",
source = "default_ranges",
range_count = networks.len(),
"trusted proxy cloud metadata fallback applied"
);
Ok(networks)
}
Err(e) => Err(AppError::cloud(format!("Failed to parse default AWS ranges: {}", e))),
@@ -137,15 +165,43 @@ impl CloudMetadataFetcher for AwsMetadataFetcher {
}
}
info!("Successfully fetched {} AWS public IP ranges", networks.len());
info!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "aws_metadata",
provider = "aws",
operation = "public_ip_ranges",
result = "loaded",
source = "api",
range_count = networks.len(),
"trusted proxy cloud metadata loaded"
);
Ok(networks)
} else {
debug!("Failed to fetch AWS IP ranges: HTTP {}", response.status());
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "aws_metadata",
provider = "aws",
operation = "public_ip_ranges",
result = "http_error",
status = %response.status(),
"trusted proxy cloud metadata request failed"
);
Ok(Vec::new())
}
}
Err(e) => {
debug!("Failed to fetch AWS IP ranges: {}", e);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "aws_metadata",
provider = "aws",
operation = "public_ip_ranges",
result = "request_failed",
error = %e,
"trusted proxy cloud metadata request failed"
);
Ok(Vec::new())
}
}
@@ -46,7 +46,15 @@ impl AzureMetadataFetcher {
async fn get_metadata(&self, path: &str) -> Result<String, AppError> {
let url = format!("{}/metadata/{}?api-version=2021-05-01", self.metadata_endpoint, path);
debug!("Fetching Azure metadata from: {}", url);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "metadata_request",
path = %path,
"trusted proxy cloud metadata request started"
);
match self.client.get(&url).header("Metadata", "true").send().await {
Ok(response) => {
@@ -57,12 +65,32 @@ impl AzureMetadataFetcher {
.map_err(|e| AppError::cloud(format!("Failed to read Azure metadata response: {}", e)))?;
Ok(text)
} else {
debug!("Azure metadata request failed with status: {}", response.status());
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "metadata_request",
path = %path,
result = "http_error",
status = %response.status(),
"trusted proxy cloud metadata request failed"
);
Err(AppError::cloud(format!("Azure metadata API returned status: {}", response.status())))
}
}
Err(e) => {
debug!("Azure metadata request failed: {}", e);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "metadata_request",
path = %path,
result = "request_failed",
error = %e,
"trusted proxy cloud metadata request failed"
);
Err(AppError::cloud(format!("Azure metadata request failed: {}", e)))
}
}
@@ -91,7 +119,15 @@ impl AzureMetadataFetcher {
address_prefixes: Vec<String>,
}
debug!("Fetching Azure IP ranges from: {}", url);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "public_ip_ranges",
source = %url,
"trusted proxy cloud metadata request started"
);
match self.client.get(url).timeout(Duration::from_secs(10)).send().await {
Ok(response) => {
@@ -114,15 +150,45 @@ impl AzureMetadataFetcher {
}
}
info!("Successfully fetched {} Azure public IP ranges", networks.len());
info!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "public_ip_ranges",
source = "api",
result = "loaded",
range_count = networks.len(),
"trusted proxy cloud metadata loaded"
);
Ok(networks)
} else {
debug!("Failed to fetch Azure IP ranges: HTTP {}", response.status());
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "public_ip_ranges",
source = %url,
result = "http_error",
status = %response.status(),
"trusted proxy cloud metadata request failed"
);
Ok(Vec::new())
}
}
Err(e) => {
debug!("Failed to fetch Azure IP ranges: {}", e);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "public_ip_ranges",
source = %url,
result = "request_failed",
error = %e,
"trusted proxy cloud metadata request failed"
);
// Fallback to hardcoded ranges if the download fails.
Self::default_azure_ranges()
}
@@ -217,7 +283,17 @@ impl AzureMetadataFetcher {
match networks {
Ok(networks) => {
debug!("Using default Azure public IP ranges");
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "public_ip_ranges",
result = "fallback",
source = "default_ranges",
range_count = networks.len(),
"trusted proxy cloud metadata fallback applied"
);
Ok(networks)
}
Err(e) => Err(AppError::cloud(format!("Failed to parse default Azure ranges: {}", e))),
@@ -265,15 +341,45 @@ impl CloudMetadataFetcher for AzureMetadataFetcher {
}
if !cidrs.is_empty() {
info!("Successfully fetched {} network CIDRs from Azure metadata", cidrs.len());
info!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "network_cidrs",
source = "metadata",
result = "loaded",
range_count = cidrs.len(),
"trusted proxy cloud metadata loaded"
);
Ok(cidrs)
} else {
debug!("No network CIDRs found in Azure metadata, falling back to defaults");
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "network_cidrs",
source = "metadata",
result = "fallback",
reason = "empty_metadata",
"trusted proxy cloud metadata fallback applied"
);
Self::default_azure_network_ranges()
}
}
Err(e) => {
warn!("Failed to fetch Azure network metadata: {}", e);
warn!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "network_cidrs",
source = "metadata",
result = "fallback",
error = %e,
"trusted proxy cloud metadata fallback applied"
);
Self::default_azure_network_ranges()
}
}
@@ -299,7 +405,17 @@ impl AzureMetadataFetcher {
match networks {
Ok(networks) => {
debug!("Using default Azure VNet network ranges");
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "azure_metadata",
provider = "azure",
operation = "network_cidrs",
result = "fallback",
source = "default_ranges",
range_count = networks.len(),
"trusted proxy cloud metadata fallback applied"
);
Ok(networks)
}
Err(e) => Err(AppError::cloud(format!("Failed to parse default Azure network ranges: {}", e))),
+150 -14
View File
@@ -46,7 +46,15 @@ impl GcpMetadataFetcher {
async fn get_metadata(&self, path: &str) -> Result<String, AppError> {
let url = format!("{}/computeMetadata/v1/{}", self.metadata_endpoint, path);
debug!("Fetching GCP metadata from: {}", url);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "metadata_request",
path = %path,
"trusted proxy cloud metadata request started"
);
match self.client.get(&url).header("Metadata-Flavor", "Google").send().await {
Ok(response) => {
@@ -57,12 +65,32 @@ impl GcpMetadataFetcher {
.map_err(|e| AppError::cloud(format!("Failed to read GCP metadata response: {}", e)))?;
Ok(text)
} else {
debug!("GCP metadata request failed with status: {}", response.status());
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "metadata_request",
path = %path,
result = "http_error",
status = %response.status(),
"trusted proxy cloud metadata request failed"
);
Err(AppError::cloud(format!("GCP metadata API returned status: {}", response.status())))
}
}
Err(e) => {
debug!("GCP metadata request failed: {}", e);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "metadata_request",
path = %path,
result = "request_failed",
error = %e,
"trusted proxy cloud metadata request failed"
);
Err(AppError::cloud(format!("GCP metadata request failed: {}", e)))
}
}
@@ -123,7 +151,17 @@ impl CloudMetadataFetcher for GcpMetadataFetcher {
.collect();
if interface_indices.is_empty() {
warn!("No network interfaces found in GCP metadata");
warn!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "network_cidrs",
source = "metadata",
result = "fallback",
reason = "no_interfaces",
"trusted proxy cloud metadata fallback applied"
);
return Self::default_gcp_network_ranges();
}
@@ -149,21 +187,61 @@ impl CloudMetadataFetcher for GcpMetadataFetcher {
}
}
Err(e) => {
debug!("Failed to get IP/mask for GCP interface {}: {}", index, e);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "network_interface",
interface_index = index,
result = "request_failed",
error = %e,
"trusted proxy cloud metadata request failed"
);
}
}
}
if cidrs.is_empty() {
warn!("Could not determine network CIDRs from GCP metadata, falling back to defaults");
warn!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "network_cidrs",
source = "metadata",
result = "fallback",
reason = "empty_metadata",
"trusted proxy cloud metadata fallback applied"
);
Self::default_gcp_network_ranges()
} else {
info!("Successfully fetched {} network CIDRs from GCP metadata", cidrs.len());
info!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "network_cidrs",
source = "metadata",
result = "loaded",
range_count = cidrs.len(),
"trusted proxy cloud metadata loaded"
);
Ok(cidrs)
}
}
Err(e) => {
warn!("Failed to fetch GCP network metadata: {}", e);
warn!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "network_cidrs",
source = "metadata",
result = "fallback",
error = %e,
"trusted proxy cloud metadata fallback applied"
);
Self::default_gcp_network_ranges()
}
}
@@ -189,7 +267,15 @@ impl GcpMetadataFetcher {
ipv4_prefix: Option<String>,
}
debug!("Fetching GCP IP ranges from: {}", url);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "public_ip_ranges",
source = %url,
"trusted proxy cloud metadata request started"
);
match self.client.get(url).timeout(Duration::from_secs(10)).send().await {
Ok(response) => {
@@ -209,15 +295,45 @@ impl GcpMetadataFetcher {
}
}
info!("Successfully fetched {} GCP public IP ranges", networks.len());
info!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "public_ip_ranges",
source = "api",
result = "loaded",
range_count = networks.len(),
"trusted proxy cloud metadata loaded"
);
Ok(networks)
} else {
debug!("Failed to fetch GCP IP ranges: HTTP {}", response.status());
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "public_ip_ranges",
source = %url,
result = "http_error",
status = %response.status(),
"trusted proxy cloud metadata request failed"
);
Self::default_gcp_ip_ranges()
}
}
Err(e) => {
debug!("Failed to fetch GCP IP ranges: {}", e);
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "public_ip_ranges",
source = %url,
result = "request_failed",
error = %e,
"trusted proxy cloud metadata request failed"
);
Self::default_gcp_ip_ranges()
}
}
@@ -280,7 +396,17 @@ impl GcpMetadataFetcher {
match networks {
Ok(networks) => {
debug!("Using default GCP public IP ranges");
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "public_ip_ranges",
result = "fallback",
source = "default_ranges",
range_count = networks.len(),
"trusted proxy cloud metadata fallback applied"
);
Ok(networks)
}
Err(e) => Err(AppError::cloud(format!("Failed to parse default GCP ranges: {}", e))),
@@ -300,7 +426,17 @@ impl GcpMetadataFetcher {
match networks {
Ok(networks) => {
debug!("Using default GCP VPC network ranges");
debug!(
event = "trusted_proxies.cloud_metadata",
component = "trusted_proxies",
subsystem = "gcp_metadata",
provider = "gcp",
operation = "network_cidrs",
result = "fallback",
source = "default_ranges",
range_count = networks.len(),
"trusted proxy cloud metadata fallback applied"
);
Ok(networks)
}
Err(e) => Err(AppError::cloud(format!("Failed to parse default GCP network ranges: {}", e))),
+100 -10
View File
@@ -60,7 +60,16 @@ impl CloudflareIpRanges {
match networks {
Ok(networks) => {
info!("Loaded {} static Cloudflare IP ranges", networks.len());
info!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "cloudflare",
source = "static",
result = "loaded",
range_count = networks.len(),
"trusted proxy cloud ranges loaded"
);
Ok(networks)
}
Err(e) => Err(AppError::cloud(format!("Failed to parse static Cloudflare IP ranges: {}", e))),
@@ -96,19 +105,55 @@ impl CloudflareIpRanges {
match ranges {
Ok(mut networks) => {
debug!("Fetched {} IP ranges from {}", networks.len(), url);
debug!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "cloudflare",
source = %url,
result = "loaded",
range_count = networks.len(),
"trusted proxy cloud ranges fetched"
);
all_ranges.append(&mut networks);
}
Err(e) => {
debug!("Failed to parse IP ranges from {}: {}", url, e);
debug!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "cloudflare",
source = %url,
result = "parse_failed",
error = %e,
"trusted proxy cloud ranges parse failed"
);
}
}
} else {
debug!("Failed to fetch IP ranges from {}: HTTP {}", url, response.status());
debug!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "cloudflare",
source = %url,
result = "http_error",
status = %response.status(),
"trusted proxy cloud ranges fetch failed"
);
}
}
Err(e) => {
debug!("Failed to fetch from {}: {}", url, e);
debug!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "cloudflare",
source = %url,
result = "request_failed",
error = %e,
"trusted proxy cloud ranges fetch failed"
);
}
}
}
@@ -117,7 +162,16 @@ impl CloudflareIpRanges {
// Fallback to static list if API requests fail.
Self::fetch().await
} else {
info!("Successfully fetched {} Cloudflare IP ranges from API", all_ranges.len());
info!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "cloudflare",
source = "api",
result = "loaded",
range_count = all_ranges.len(),
"trusted proxy cloud ranges loaded"
);
Ok(all_ranges)
}
}
@@ -151,7 +205,16 @@ impl DigitalOceanIpRanges {
match networks {
Ok(networks) => {
info!("Loaded {} static DigitalOcean IP ranges", networks.len());
info!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "digitalocean",
source = "static",
result = "loaded",
range_count = networks.len(),
"trusted proxy cloud ranges loaded"
);
Ok(networks)
}
Err(e) => Err(AppError::cloud(format!("Failed to parse static DigitalOcean IP ranges: {}", e))),
@@ -200,15 +263,42 @@ impl GoogleCloudIpRanges {
}
}
info!("Successfully fetched {} Google Cloud IP ranges from API", networks.len());
info!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "gcp",
source = "api",
result = "loaded",
range_count = networks.len(),
"trusted proxy cloud ranges loaded"
);
Ok(networks)
} else {
debug!("Failed to fetch Google IP ranges: HTTP {}", response.status());
debug!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "gcp",
source = %url,
result = "http_error",
status = %response.status(),
"trusted proxy cloud ranges fetch failed"
);
Ok(Vec::new())
}
}
Err(e) => {
debug!("Failed to fetch Google IP ranges: {}", e);
debug!(
event = "trusted_proxies.cloud_ranges",
component = "trusted_proxies",
subsystem = "cloud_ranges",
provider = "gcp",
source = %url,
result = "request_failed",
error = %e,
"trusted proxy cloud ranges fetch failed"
);
Ok(Vec::new())
}
}
+47 -14
View File
@@ -176,11 +176,26 @@ impl ConfigLoader {
pub fn from_env_or_default() -> AppConfig {
match Self::from_env() {
Ok(config) => {
info!("Configuration loaded successfully from environment variables");
info!(
event = "trusted_proxies.config",
component = "trusted_proxies",
subsystem = "config_loader",
result = "loaded",
source = "environment",
"trusted proxies configuration loaded"
);
config
}
Err(e) => {
tracing::warn!("Failed to load configuration from environment: {}. Using defaults", e);
tracing::warn!(
event = "trusted_proxies.config",
component = "trusted_proxies",
subsystem = "config_loader",
result = "fallback",
source = "defaults",
error = %e,
"trusted proxies configuration fell back to defaults"
);
Self::default_config()
}
}
@@ -214,20 +229,38 @@ impl ConfigLoader {
/// Prints a summary of the configuration to the log.
pub fn print_summary(config: &AppConfig) {
info!("=== Application Configuration ===");
info!("Server: {}", config.server_addr);
info!("Trusted Proxies: {}", config.proxy.proxies.len());
info!("Validation Mode: {:?}", config.proxy.validation_mode);
info!("Cache Capacity: {}", config.cache.capacity);
info!("Metrics Enabled: {}", config.monitoring.metrics_enabled);
info!("Cloud Metadata: {}", config.cloud.metadata_enabled);
if config.monitoring.log_failed_validations {
info!("Failed validations will be logged");
}
info!(
event = "trusted_proxies.config",
component = "trusted_proxies",
subsystem = "config_loader",
result = "summary",
server_addr = %config.server_addr,
trusted_proxy_count = config.proxy.proxies.len(),
validation_mode = config.proxy.validation_mode.as_str(),
cache_capacity = config.cache.capacity,
cache_ttl_seconds = config.cache.ttl_seconds,
cache_cleanup_interval_seconds = config.cache.cleanup_interval_seconds,
metrics_enabled = config.monitoring.metrics_enabled,
structured_logging = config.monitoring.structured_logging,
tracing_enabled = config.monitoring.tracing_enabled,
log_failed_validations = config.monitoring.log_failed_validations,
cloud_metadata_enabled = config.cloud.metadata_enabled,
cloud_metadata_timeout_seconds = config.cloud.metadata_timeout_seconds,
cloudflare_ips_enabled = config.cloud.cloudflare_ips_enabled,
forced_provider = config.cloud.forced_provider.as_deref().unwrap_or("none"),
"trusted proxies configuration summarized"
);
if !config.proxy.proxies.is_empty() {
tracing::debug!("Trusted networks: {:?}", config.proxy.get_network_strings());
tracing::debug!(
event = "trusted_proxies.config",
component = "trusted_proxies",
subsystem = "config_loader",
result = "trusted_networks",
trusted_proxy_count = config.proxy.proxies.len(),
trusted_networks = ?config.proxy.get_network_strings(),
"trusted proxies networks enumerated"
);
}
}
}
+19 -2
View File
@@ -43,7 +43,14 @@ pub fn init() {
ENABLED.get_or_init(|| enabled);
if !enabled {
tracing::info!("Trusted Proxies module is disabled via configuration");
tracing::info!(
event = "trusted_proxies.lifecycle",
component = "trusted_proxies",
subsystem = "global",
state = "disabled",
enabled,
"trusted proxies state changed"
);
return;
}
@@ -66,7 +73,17 @@ pub fn init() {
)
});
tracing::info!("Trusted Proxies module initialized");
tracing::info!(
event = "trusted_proxies.lifecycle",
component = "trusted_proxies",
subsystem = "global",
state = "initialized",
enabled,
metrics_enabled = config.monitoring.metrics_enabled,
trusted_proxy_count = config.proxy.proxies.len(),
validation_mode = config.proxy.validation_mode.as_str(),
"trusted proxies state changed"
);
ConfigLoader::print_summary(&config);
}
@@ -19,7 +19,7 @@ use http::Request;
use std::sync::Arc;
use std::task::{Context, Poll};
use tower::Service;
use tracing::debug;
use tracing::{debug, trace, warn};
/// Tower Service for the trusted proxy middleware.
#[derive(Clone)]
@@ -64,7 +64,13 @@ where
fn call(&mut self, mut req: Request<ReqBody>) -> Self::Future {
// If the middleware is disabled, pass the request through immediately.
if !self.enabled {
debug!("Trusted proxy middleware is disabled");
debug!(
event = "proxy_validation.middleware",
component = "trusted_proxies",
subsystem = "middleware",
state = "disabled",
"trusted proxy middleware bypassed"
);
return self.inner.call(req);
}
@@ -77,20 +83,65 @@ where
match self.validator.validate_request(peer_addr, req.headers()) {
Ok(client_info) => {
// Insert the verified client info into the request extensions.
req.extensions_mut().insert(client_info);
let duration = start_time.elapsed();
debug!("Proxy validation successful in {:?}", duration);
trace!(
event = "proxy_validation.middleware",
component = "trusted_proxies",
subsystem = "middleware",
result = if client_info.is_from_trusted_proxy {
"trusted_proxy"
} else {
"direct"
},
peer_ip = peer_addr
.map(|addr| addr.ip().to_string())
.unwrap_or_else(|| "0.0.0.0".to_string()),
client_ip = %client_info.real_ip,
proxy_hops = client_info.proxy_hops,
warning_count = client_info.warnings.len(),
validation_mode = client_info.validation_mode.as_str(),
duration_ms = duration.as_millis(),
"trusted proxy evaluation completed"
);
req.extensions_mut().insert(client_info);
}
Err(err) => {
// If the error is recoverable, fallback to a direct connection info.
if err.is_recoverable() {
let duration = start_time.elapsed();
warn!(
event = "proxy_validation.middleware",
component = "trusted_proxies",
subsystem = "middleware",
result = "fallback",
fallback = "socket_peer",
peer_ip = peer_addr
.map(|addr| addr.ip().to_string())
.unwrap_or_else(|| "0.0.0.0".to_string()),
error = %err,
duration_ms = duration.as_millis(),
"trusted proxy validation fell back to direct peer"
);
let client_info = ClientInfo::direct(
peer_addr.unwrap_or_else(|| std::net::SocketAddr::new(std::net::IpAddr::from([0, 0, 0, 0]), 0)),
);
req.extensions_mut().insert(client_info);
} else {
debug!("Unrecoverable proxy validation error: {}", err);
let duration = start_time.elapsed();
warn!(
event = "proxy_validation.middleware",
component = "trusted_proxies",
subsystem = "middleware",
result = "error",
fallback = "none",
peer_ip = peer_addr
.map(|addr| addr.ip().to_string())
.unwrap_or_else(|| "0.0.0.0".to_string()),
error = %err,
duration_ms = duration.as_millis(),
"trusted proxy validation failed"
);
}
}
}
+9 -1
View File
@@ -81,7 +81,15 @@ impl ProxyChainAnalyzer {
current_proxy_ip: IpAddr,
headers: &HeaderMap,
) -> Result<ChainAnalysis, ProxyError> {
trace!("Analyzing proxy chain: {:?} with current proxy: {}", proxy_chain, current_proxy_ip);
trace!(
event = "proxy_chain.analyze",
component = "trusted_proxies",
subsystem = "chain",
validation_mode = self.config.validation_mode.as_str(),
proxy_chain_len = proxy_chain.len(),
current_proxy_ip = %current_proxy_ip,
"proxy chain analysis started"
);
// Validate all IP addresses in the chain.
self.validate_ip_addresses(proxy_chain)?;
+17 -12
View File
@@ -219,21 +219,26 @@ impl ProxyMetrics {
/// Prints a summary of enabled metrics to the log.
pub fn print_summary(&self) {
if !self.enabled {
info!("Metrics collection is disabled");
info!(
event = "trusted_proxies.metrics",
component = "trusted_proxies",
subsystem = "metrics",
state = "disabled",
app = %self.app_name,
"trusted proxies metrics state changed"
);
return;
}
info!("Proxy metrics enabled for application: {}", self.app_name);
info!("Available metrics:");
info!(" - rustfs_trusted_proxy_validation_attempts_total");
info!(" - rustfs_trusted_proxy_validation_success_total");
info!(" - rustfs_trusted_proxy_validation_failure_total");
info!(" - rustfs_trusted_proxy_validation_failure_by_type_total");
info!(" - rustfs_trusted_proxy_chain_length");
info!(" - rustfs_trusted_proxy_validation_duration_seconds");
info!(" - rustfs_trusted_proxy_cache_size");
info!(" - rustfs_trusted_proxy_cache_hits_total");
info!(" - rustfs_trusted_proxy_cache_misses_total");
info!(
event = "trusted_proxies.metrics",
component = "trusted_proxies",
subsystem = "metrics",
state = "enabled",
app = %self.app_name,
metric_count = 9,
"trusted proxies metrics state changed"
);
}
}
+68 -15
View File
@@ -18,7 +18,7 @@ use axum::http::HeaderMap;
use std::net::{IpAddr, SocketAddr};
use std::sync::Arc;
use std::time::{Duration, Instant};
use tracing::{debug, warn};
use tracing::{debug, trace, warn};
use crate::{
CacheConfig, CacheStats, IpValidationCache, ProxyChainAnalyzer, ProxyError, ProxyMetrics, TrustedProxyConfig, ValidationMode,
@@ -81,14 +81,6 @@ impl ClientInfo {
warnings,
}
}
/// Returns a string representation of the client info for logging.
pub fn to_log_string(&self) -> String {
format!(
"client_ip={}, proxy={:?}, hops={}, trusted={}, mode={:?}",
self.real_ip, self.proxy_ip, self.proxy_hops, self.is_from_trusted_proxy, self.validation_mode
)
}
}
/// Core validator that processes incoming requests to verify proxy chains.
@@ -149,13 +141,28 @@ impl ProxyValidator {
/// Internal logic for request validation.
fn validate_request_internal(&self, peer_addr: Option<SocketAddr>, headers: &HeaderMap) -> Result<ClientInfo, ProxyError> {
let Some(peer_addr) = peer_addr else {
debug!("SocketAddr extension is missing; skipping trusted proxy evaluation");
debug!(
event = "proxy_validation.evaluate",
component = "trusted_proxies",
subsystem = "validator",
result = "direct",
reason = "missing_peer_addr",
"trusted proxy evaluation skipped"
);
return Ok(ClientInfo::direct(SocketAddr::new(IpAddr::from([0, 0, 0, 0]), 0)));
};
let peer_ip = peer_addr.ip();
if peer_ip.is_unspecified() {
debug!("Peer address is unspecified; skipping trusted proxy evaluation");
debug!(
event = "proxy_validation.evaluate",
component = "trusted_proxies",
subsystem = "validator",
result = "direct",
reason = "unspecified_peer_addr",
peer_ip = %peer_ip,
"trusted proxy evaluation skipped"
);
return Ok(ClientInfo::direct(peer_addr));
}
@@ -165,7 +172,15 @@ impl ProxyValidator {
// Check if the direct peer is a trusted proxy.
if is_trusted_proxy {
debug!("Request received from trusted proxy: {}", peer_ip);
trace!(
event = "proxy_validation.peer",
component = "trusted_proxies",
subsystem = "validator",
result = "trusted_proxy",
peer_ip = %peer_ip,
validation_mode = self.config.validation_mode.as_str(),
"trusted proxy peer accepted"
);
// Parse and validate headers from the trusted proxy.
self.validate_trusted_proxy_request(&peer_addr, headers)
@@ -173,8 +188,25 @@ impl ProxyValidator {
// Log a warning if the request is from a private network but not trusted.
if self.config.is_private_network(&peer_ip) {
warn!(
"Request from private network but not trusted: {}. This might indicate a configuration issue.",
peer_ip
event = "proxy_validation.peer",
component = "trusted_proxies",
subsystem = "validator",
result = "direct",
fallback = "socket_peer",
reason = "private_network_untrusted",
peer_ip = %peer_ip,
"trusted proxy validation downgraded to direct peer"
);
} else {
trace!(
event = "proxy_validation.peer",
component = "trusted_proxies",
subsystem = "validator",
result = "direct",
fallback = "socket_peer",
reason = "peer_not_trusted",
peer_ip = %peer_ip,
"trusted proxy validation resolved direct peer"
);
}
@@ -194,7 +226,14 @@ impl ProxyValidator {
}
let Ok(handle) = tokio::runtime::Handle::try_current() else {
tracing::debug!("No Tokio runtime available; trusted proxy cache maintenance is disabled");
tracing::debug!(
event = "proxy_validation.cache_maintenance",
component = "trusted_proxies",
subsystem = "validator",
state = "disabled",
reason = "missing_tokio_runtime",
"trusted proxy cache maintenance unavailable"
);
return;
};
@@ -235,6 +274,20 @@ impl ProxyValidator {
return Err(ProxyError::ChainNotContinuous);
}
trace!(
event = "proxy_validation.chain",
component = "trusted_proxies",
subsystem = "validator",
result = "accepted",
proxy_ip = %proxy_ip,
client_ip = %chain_analysis.client_ip,
proxy_hops = chain_analysis.hops,
warning_count = chain_analysis.warnings.len(),
validation_mode = chain_analysis.validation_mode.as_str(),
trusted_proxy_count = chain_analysis.trusted_chain.len(),
"trusted proxy chain accepted"
);
Ok(ClientInfo::from_trusted_proxy(
chain_analysis.client_ip,
client_info.forwarded_host,