feat(obs): improve metrics coverage and dashboard performance (#2682)

This commit is contained in:
houseme
2026-04-26 02:51:29 +08:00
committed by GitHub
parent 81854762d4
commit 59f41eb86a
42 changed files with 1108 additions and 292 deletions
@@ -1282,8 +1282,8 @@ async fn build_metrics_summary(local_peer: &PeerInfo) -> SRMetricsSummary {
head_total: non_negative_u64(node.proxied.head_total),
get_failed_total: non_negative_u64(node.proxied.get_failed),
head_failed_total: non_negative_u64(node.proxied.head_failed),
put_tag_total: non_negative_u64(node.proxied.put_total),
put_tag_failed_total: non_negative_u64(node.proxied.put_failed),
put_tag_total: non_negative_u64(node.proxied.put_tag_total),
put_tag_failed_total: non_negative_u64(node.proxied.put_tag_failed),
..Default::default()
},
metrics,
+2 -2
View File
@@ -1651,8 +1651,8 @@ impl DefaultObjectUsecase {
if enable_zero_copy {
// Record zero-copy write attempt
counter!("rustfs.zero_copy.write.attempts.total").increment(1);
histogram!("rustfs.zero_copy.write.size.bytes").record(size as f64);
counter!("rustfs_zero_copy_write_attempts_total").increment(1);
histogram!("rustfs_zero_copy_write_size_bytes").record(size as f64);
debug!("Zero-copy write enabled for {} byte object (bucket={}, key={})", size, bucket, key);
}
+91 -22
View File
@@ -38,7 +38,7 @@ use hyper_util::{
server::graceful::GracefulShutdown,
service::TowerToHyperService,
};
use metrics::{counter, histogram};
use metrics::{counter, gauge, histogram};
use opentelemetry::global;
use opentelemetry::trace::TraceContextExt;
use rustfs_common::GlobalReadiness;
@@ -54,6 +54,7 @@ use socket2::{SockRef, TcpKeepalive};
use std::io::{Error, Result};
use std::net::SocketAddr;
use std::sync::Arc;
use std::sync::atomic::{AtomicU64, Ordering};
use std::time::Duration;
use tokio::net::{TcpListener, TcpStream};
use tonic::{Request, Status};
@@ -66,12 +67,18 @@ use tower_http::trace::TraceLayer;
use tracing::{Span, debug, error, info, instrument, warn};
use tracing_opentelemetry::OpenTelemetrySpanExt;
const LABEL_REQUEST_METHOD: &str = "request_method";
const METRIC_API_REQUESTS_TOTAL: &str = "rustfs_api_requests_total";
const METRIC_API_REQUESTS_FAILURE_TOTAL: &str = "rustfs_api_requests_failure_total";
const METRIC_REQUEST_BODY_BYTES_TOTAL: &str = "rustfs_request_body_bytes_total";
const METRIC_REQUEST_LATENCY_MS: &str = "rustfs_request_latency_ms";
const METRIC_REQUEST_BODY_LEN: &str = "rustfs_request_body_len";
const LABEL_HTTP_METHOD: &str = "method";
const LABEL_HTTP_STATUS_CLASS: &str = "status_class";
const METRIC_HTTP_SERVER_REQUESTS_TOTAL: &str = "rustfs_http_server_requests_total";
const METRIC_HTTP_SERVER_FAILURES_TOTAL: &str = "rustfs_http_server_failures_total";
const METRIC_HTTP_SERVER_ACTIVE_REQUESTS: &str = "rustfs_http_server_active_requests";
const METRIC_HTTP_SERVER_REQUEST_DURATION_SECONDS: &str = "rustfs_http_server_request_duration_seconds";
const METRIC_HTTP_SERVER_REQUEST_BODY_BYTES_TOTAL: &str = "rustfs_http_server_request_body_bytes_total";
const METRIC_HTTP_SERVER_REQUEST_BODY_SIZE_BYTES: &str = "rustfs_http_server_request_body_size_bytes";
const METRIC_HTTP_SERVER_RESPONSE_BODY_BYTES_TOTAL: &str = "rustfs_http_server_response_body_bytes_total";
const METRIC_HTTP_SERVER_RESPONSE_BODY_SIZE_BYTES: &str = "rustfs_http_server_response_body_size_bytes";
static ACTIVE_HTTP_REQUESTS: AtomicU64 = AtomicU64::new(0);
#[inline]
fn request_method_label(method: &Method) -> &'static str {
@@ -89,6 +96,32 @@ fn request_method_label(method: &Method) -> &'static str {
}
}
#[inline]
fn status_class_label(status: http::StatusCode) -> &'static str {
match status.as_u16() / 100 {
1 => "1xx",
2 => "2xx",
3 => "3xx",
4 => "4xx",
5 => "5xx",
_ => "unknown",
}
}
#[inline]
fn record_active_http_requests(delta: i64) {
let next = if delta >= 0 {
ACTIVE_HTTP_REQUESTS.fetch_add(delta as u64, Ordering::Relaxed) + delta as u64
} else {
let decrement = (-delta) as u64;
ACTIVE_HTTP_REQUESTS
.fetch_update(Ordering::Relaxed, Ordering::Relaxed, |current| Some(current.saturating_sub(decrement)))
.unwrap_or_else(|current| current)
.saturating_sub(decrement)
};
gauge!(METRIC_HTTP_SERVER_ACTIVE_REQUESTS).set(next as f64);
}
pub async fn start_http_server(
config: &config::Config,
readiness: Arc<GlobalReadiness>,
@@ -739,28 +772,55 @@ fn process_connection(
.on_request(|request: &HttpRequest<_>, span: &Span| {
let _enter = span.enter();
debug!("http started method: {}, url path: {}", request.method(), request.uri().path());
let method = request_method_label(request.method());
record_active_http_requests(1);
counter!(
METRIC_API_REQUESTS_TOTAL,
LABEL_REQUEST_METHOD => request_method_label(request.method())
METRIC_HTTP_SERVER_REQUESTS_TOTAL,
LABEL_HTTP_METHOD => method
)
.increment(1);
// Aggregate request body size for throughput monitoring (lightweight)
if let Some(cl) = request.headers().get("content-length")
&& let Some(len) = cl.to_str().ok().and_then(|s| s.parse::<u64>().ok())
{
counter!(METRIC_REQUEST_BODY_BYTES_TOTAL, "direction" => "request").increment(len);
counter!(METRIC_HTTP_SERVER_REQUEST_BODY_BYTES_TOTAL).increment(len);
histogram!(
METRIC_HTTP_SERVER_REQUEST_BODY_SIZE_BYTES,
LABEL_HTTP_METHOD => method
)
.record(len as f64);
}
})
.on_response(|response: &Response<_>, latency: Duration, span: &Span| {
span.record("status_code", tracing::field::display(response.status()));
let _enter = span.enter();
histogram!(METRIC_REQUEST_LATENCY_MS).record(latency.as_millis() as f64);
let status_class = status_class_label(response.status());
record_active_http_requests(-1);
histogram!(
METRIC_HTTP_SERVER_REQUEST_DURATION_SECONDS,
LABEL_HTTP_STATUS_CLASS => status_class
)
.record(latency.as_secs_f64());
if response.status().is_client_error() || response.status().is_server_error() {
counter!(
METRIC_HTTP_SERVER_FAILURES_TOTAL,
LABEL_HTTP_STATUS_CLASS => status_class
)
.increment(1);
}
if let Some(cl) = response.headers().get("content-length")
&& let Some(len) = cl.to_str().ok().and_then(|s| s.parse::<u64>().ok())
{
histogram!(
METRIC_HTTP_SERVER_RESPONSE_BODY_SIZE_BYTES,
LABEL_HTTP_STATUS_CLASS => status_class
)
.record(len as f64);
}
debug!("http response generated in {:?}", latency)
})
.on_body_chunk(|chunk: &Bytes, latency: Duration, span: &Span| {
// Always track aggregate body bytes (lightweight counter, no debug logging)
counter!(METRIC_REQUEST_BODY_BYTES_TOTAL, "direction" => "response").increment(chunk.len() as u64);
histogram!(METRIC_REQUEST_BODY_LEN, "direction" => "response").record(chunk.len() as f64);
counter!(METRIC_HTTP_SERVER_RESPONSE_BODY_BYTES_TOTAL).increment(chunk.len() as u64);
#[cfg(feature = "tracing-chunk-debug")]
{
let _enter = span.enter();
@@ -784,7 +844,12 @@ fn process_connection(
})
.on_failure(|_error, latency: Duration, span: &Span| {
let _enter = span.enter();
counter!(METRIC_API_REQUESTS_FAILURE_TOTAL).increment(1);
record_active_http_requests(-1);
counter!(
METRIC_HTTP_SERVER_FAILURES_TOTAL,
LABEL_HTTP_STATUS_CLASS => "transport"
)
.increment(1);
debug!("http request failure error: {:?} in {:?}", _error, latency)
}),
)
@@ -1115,11 +1180,14 @@ mod tests {
#[test]
fn test_http_metric_names_and_labels_use_snake_case() {
let metric_names = [
METRIC_API_REQUESTS_TOTAL,
METRIC_API_REQUESTS_FAILURE_TOTAL,
METRIC_REQUEST_BODY_BYTES_TOTAL,
METRIC_REQUEST_LATENCY_MS,
METRIC_REQUEST_BODY_LEN,
METRIC_HTTP_SERVER_REQUESTS_TOTAL,
METRIC_HTTP_SERVER_FAILURES_TOTAL,
METRIC_HTTP_SERVER_ACTIVE_REQUESTS,
METRIC_HTTP_SERVER_REQUEST_DURATION_SECONDS,
METRIC_HTTP_SERVER_REQUEST_BODY_BYTES_TOTAL,
METRIC_HTTP_SERVER_REQUEST_BODY_SIZE_BYTES,
METRIC_HTTP_SERVER_RESPONSE_BODY_BYTES_TOTAL,
METRIC_HTTP_SERVER_RESPONSE_BODY_SIZE_BYTES,
];
for metric_name in metric_names {
@@ -1127,7 +1195,8 @@ mod tests {
assert!(!metric_name.contains('.'));
}
assert_eq!(LABEL_REQUEST_METHOD, "request_method");
assert_eq!(LABEL_HTTP_METHOD, "method");
assert_eq!(LABEL_HTTP_STATUS_CLASS, "status_class");
}
#[test]
+2 -2
View File
@@ -249,7 +249,7 @@ async fn get_or_fetch_object_tag_conditions<T>(
return Ok(cached.values.clone());
}
counter!("rustfs.object_tag_conditions.fetched", "op" => action_tag_metric_label(&action)).increment(1);
counter!("rustfs_object_tag_conditions_fetched_total", "op" => action_tag_metric_label(&action)).increment(1);
let fetched = auth_fs()
.get_object_tag_conditions_for_policy(bucket, object, version_id)
.await?;
@@ -268,7 +268,7 @@ async fn maybe_merge_object_tag_conditions<T>(
needs_tag: bool,
) -> S3Result<()> {
if !needs_tag || bucket.is_empty() || object.is_empty() {
counter!("rustfs.object_tag_conditions.skipped", "op" => action_tag_metric_label(&action)).increment(1);
counter!("rustfs_object_tag_conditions_skipped_total", "op" => action_tag_metric_label(&action)).increment(1);
return Ok(());
}
+4 -4
View File
@@ -280,7 +280,7 @@ impl BackpressurePipe {
if usage >= threshold && !self.state.load(Ordering::Relaxed) {
self.state.store(true, Ordering::Relaxed);
counter!("rustfs.backpressure.events.total", "state" => "high_watermark").increment(1);
counter!("rustfs_backpressure_events_total", "state" => "high_watermark").increment(1);
warn!(
buffer_usage = usage,
@@ -300,7 +300,7 @@ impl BackpressurePipe {
if usage <= threshold && self.state.load(Ordering::Relaxed) {
self.state.store(false, Ordering::Relaxed);
counter!("rustfs.backpressure.events.total", "state" => "normal").increment(1);
counter!("rustfs_backpressure_events_total", "state" => "normal").increment(1);
debug!(
buffer_usage = usage,
@@ -406,14 +406,14 @@ impl BackpressureMonitor {
if usage >= high {
if !self.in_high_watermark.swap(true, Ordering::Relaxed) {
counter!("rustfs.backpressure.events.total", "state" => "high_watermark").increment(1);
counter!("rustfs_backpressure_events_total", "state" => "high_watermark").increment(1);
debug!(usage_percent = self.usage_percent() as u32, "Backpressure: entered high watermark");
}
BackpressureState::HighWatermark
} else if usage <= low {
if self.in_high_watermark.swap(false, Ordering::Relaxed) {
counter!("rustfs.backpressure.events.total", "state" => "normal").increment(1);
counter!("rustfs_backpressure_events_total", "state" => "normal").increment(1);
debug!(usage_percent = self.usage_percent() as u32, "Backpressure: returned to normal");
}
@@ -1277,7 +1277,7 @@ pub fn get_concurrency_aware_buffer_size(file_size: i64, base_buffer_size: usize
// Record concurrent request metrics
{
use metrics::gauge;
gauge!("rustfs.concurrent.get.requests").set(concurrent_requests as f64);
gauge!("rustfs_concurrent_get_requests").set(concurrent_requests as f64);
}
// For low concurrency, use the base buffer size for maximum throughput
+1 -1
View File
@@ -464,7 +464,7 @@ impl DeadlockDetector {
if let Some(cycle) = Self::find_cycle(&wait_graph) {
deadlocks_detected.fetch_add(1, Ordering::Relaxed);
counter!("rustfs.deadlock.detected.total").increment(1);
counter!("rustfs_deadlock_detected_total").increment(1);
// Log detailed deadlock information
error!(
+33 -10
View File
@@ -31,6 +31,7 @@ use rustfs_ecstore::{
},
metadata_sys,
object_lock::objectlock_sys::check_retention_for_modification,
replication::{GLOBAL_REPLICATION_STATS, ReplicationConfigurationExt},
tagging::{decode_tags, decode_tags_to_map, encode_tags},
utils::serialize,
versioning::VersioningApi,
@@ -72,6 +73,22 @@ impl FS {
Self {}
}
async fn replication_tagging_enabled(bucket: &str, object: &str) -> bool {
metadata_sys::get_replication_config(bucket)
.await
.map(|(cfg, _)| cfg.has_active_rules(object, true))
.unwrap_or(false)
}
async fn record_replication_tagging_metric(bucket: &str, object: &str, api: &str, is_err: bool) {
if !Self::replication_tagging_enabled(bucket, object).await {
return;
}
if let Some(stats) = GLOBAL_REPLICATION_STATS.get() {
stats.inc_proxy(bucket, api, is_err).await;
}
}
pub async fn get_object_tag_conditions_for_policy(
&self,
bucket: &str,
@@ -374,7 +391,9 @@ impl S3 for FS {
..Default::default()
};
store.delete_object_tags(&bucket, &object, &opts).await.map_err(|e| {
let delete_tags_result = store.delete_object_tags(&bucket, &object, &opts).await;
Self::record_replication_tagging_metric(&bucket, &object, "DeleteObjectTagging", delete_tags_result.is_err()).await;
delete_tags_result.map_err(|e| {
error!("Failed to delete object tags: {}", e);
ApiError::from(e)
})?;
@@ -393,7 +412,7 @@ impl S3 for FS {
}
};
counter!("rustfs.delete_object_tagging.success").increment(1);
counter!("rustfs_delete_object_tagging_success").increment(1);
let event_version_id = version_id
.as_deref()
@@ -413,7 +432,7 @@ impl S3 for FS {
let result = Ok(S3Response::new(DeleteObjectTaggingOutput { version_id }));
let _ = helper.complete(&result);
let duration = start_time.elapsed();
histogram!("rustfs.object_tagging.operation.duration.seconds", "operation" => "delete").record(duration.as_secs_f64());
histogram!("rustfs_object_tagging_operation_duration_seconds", "operation" => "delete").record(duration.as_secs_f64());
result
}
@@ -801,7 +820,9 @@ impl S3 for FS {
..Default::default()
};
let tags = store.get_object_tags(bucket, object, &opts).await.map_err(|e| {
let tags_result = store.get_object_tags(bucket, object, &opts).await;
Self::record_replication_tagging_metric(bucket, object, "GetObjectTagging", tags_result.is_err()).await;
let tags = tags_result.map_err(|e| {
if is_err_object_not_found(&e) {
error!("Object not found: {}", e);
return s3_error!(NoSuchKey);
@@ -813,9 +834,9 @@ impl S3 for FS {
let tag_set = decode_tags(tags.as_str());
debug!("Decoded tag set: {:?}", tag_set);
counter!("rustfs.get_object_tagging.success").increment(1);
counter!("rustfs_get_object_tagging_success").increment(1);
let duration = start_time.elapsed();
histogram!("rustfs.object_tagging.operation.duration.seconds", "operation" => "get").record(duration.as_secs_f64());
histogram!("rustfs_object_tagging_operation_duration_seconds", "operation" => "get").record(duration.as_secs_f64());
Ok(S3Response::new(GetObjectTaggingOutput {
tag_set,
version_id: req.input.version_id.clone(),
@@ -1363,9 +1384,11 @@ impl S3 for FS {
..Default::default()
};
store.put_object_tags(&bucket, &object, &tags, &opts).await.map_err(|e| {
let put_tags_result = store.put_object_tags(&bucket, &object, &tags, &opts).await;
Self::record_replication_tagging_metric(&bucket, &object, "PutObjectTagging", put_tags_result.is_err()).await;
put_tags_result.map_err(|e| {
error!("Failed to put object tags: {}", e);
counter!("rustfs.put_object_tagging.failure").increment(1);
counter!("rustfs_put_object_tagging_failure").increment(1);
ApiError::from(e)
})?;
@@ -1383,7 +1406,7 @@ impl S3 for FS {
}
};
counter!("rustfs.put_object_tagging.success").increment(1);
counter!("rustfs_put_object_tagging_success").increment(1);
let event_version_id = req
.input
@@ -1407,7 +1430,7 @@ impl S3 for FS {
}));
let _ = helper.complete(&result);
let duration = start_time.elapsed();
histogram!("rustfs.object_tagging.operation.duration.seconds", "operation" => "put").record(duration.as_secs_f64());
histogram!("rustfs_object_tagging_operation_duration_seconds", "operation" => "put").record(duration.as_secs_f64());
result
}
+4 -4
View File
@@ -190,12 +190,12 @@ pub(crate) fn get_buffer_size_opt_in(file_size: i64) -> usize {
// Optional performance metrics collection for monitoring and optimization
{
use metrics::histogram;
histogram!("rustfs.buffer.size.bytes").record(buffer_size as f64);
counter!("rustfs.buffer.size.selections").increment(1);
histogram!("rustfs_buffer_size_bytes").record(buffer_size as f64);
counter!("rustfs_buffer_size_selections_total").increment(1);
if file_size >= 0 {
if file_size > 0 {
let ratio = buffer_size as f64 / file_size as f64;
histogram!("rustfs.buffer.to.file.ratio").record(ratio);
histogram!("rustfs_buffer_to_file_ratio").record(ratio);
}
}
+2 -2
View File
@@ -223,7 +223,7 @@ impl<G> OptimizedLockGuard<G> {
self.stats.record_early_release(hold_time);
histogram!("rustfs.lock.hold.duration.seconds").record(hold_time.as_secs_f64());
histogram!("rustfs_lock_hold_duration_seconds").record(hold_time.as_secs_f64());
debug!(
resource = %self.resource,
@@ -247,7 +247,7 @@ impl<G> Drop for OptimizedLockGuard<G> {
self.stats.record_early_release(hold_time);
histogram!("rustfs.lock.hold.duration.seconds").record(hold_time.as_secs_f64());
histogram!("rustfs_lock_hold_duration_seconds").record(hold_time.as_secs_f64());
debug!(
resource = %self.resource,
+2 -2
View File
@@ -90,7 +90,7 @@ impl RequestContext {
pub fn fallback() -> Self {
let trace_ctx = current_trace_context_ids();
let id = build_fallback_request_id(trace_ctx.as_ref());
counter!("rustfs.log.chain.fallback_request_id.total", "source" => "request_context_fallback").increment(1);
counter!("rustfs_log_chain_fallback_request_id_total", "source" => "request_context_fallback").increment(1);
Self {
request_id: id.clone(),
x_amz_request_id: id,
@@ -138,7 +138,7 @@ pub fn extract_request_id_from_headers(headers: &HeaderMap) -> String {
.unwrap_or_else(generate_fallback_request_id);
if !headers.contains_key(REQUEST_ID_HEADER) && !headers.contains_key(AMZ_REQUEST_ID) {
counter!("rustfs.log.chain.fallback_request_id.total", "source" => "headers_missing").increment(1);
counter!("rustfs_log_chain_fallback_request_id_total", "source" => "headers_missing").increment(1);
}
request_id