From 264b2dd48076fa19af59aa2980e31a020b28c748 Mon Sep 17 00:00:00 2001 From: houseme Date: Sat, 11 Jul 2026 23:27:15 +0800 Subject: [PATCH] perf(metrics): drop needless per-emission work on hot metric paths (#4743) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * perf(metrics): drop needless per-emission work on hot metric paths Audit of the metrics hot paths surfaced four low-risk wins where emission did work it did not need to: - `record_file_cache_reclaim_success/error` (disk/local.rs) called `.to_string()` on `kind` (already `&'static str`) and on the `"ok"`/`"err"` literals, heap- allocating up to four `String`s per page-cache reclaim window — which runs per read-stream reclaim. The `metrics` macros accept `&'static str` label values directly, so pass them as-is. - `record_read_repair_dedup` (set_disk/core/io_primitives.rs) likewise `.to_string()`-ed an already-`&'static str` `reason`. - `SetDisks::get_object_reader` (set_disk/ops/object.rs) captured `Instant::now()` and emitted the `rustfs.lock.acquire.*` counter and histogram unconditionally on every GET, right beside an already-gated stage timer. Gate them behind `get_stage_metrics_enabled()` too, so an inactive observability config pays no per-GET clock read or recorder lookups. - The per-response-body-chunk counter in server/http.rs re-ran the `counter!` registry lookup on every chunk (a streamed GET emits many). Resolve the label-less handle once into a `LazyLock`; the global recorder is installed at startup before any response streams, so the cached handle binds to the final recorder. No metric names or label values change. The only behavior change is that the `rustfs.lock.acquire.*` GET-path metrics now follow the GET stage-metrics flag, consistent with the neighbouring stage timings. Co-Authored-By: heihutu * perf(metrics): gate page-cache reclaim metrics behind metrics_enabled() `record_file_cache_reclaim_success/error` run per read-stream reclaim window on large-object reads and emitted unconditionally. When general metrics are disabled the `counter!`/`histogram!` macros still construct three metric keys per call for nothing. Skip the emission behind `rustfs_io_metrics::metrics_enabled()`, matching how the io-metrics free functions self-gate. The serial reclaim-metrics test now enables the flag (save/restore) alongside the existing stage gate. Left ungated deliberately: `record_read_repair_dedup` (rare read-repair path, and its non-serial test would need a global-flag toggle), and the HTTP body-chunk counter (its cached handle already makes the disabled case a no-op increment). Co-Authored-By: heihutu --------- Co-authored-by: heihutu --- crates/ecstore/src/disk/local.rs | 23 +++++++++++++++---- .../src/set_disk/core/io_primitives.rs | 4 +++- crates/ecstore/src/set_disk/ops/object.rs | 12 ++++++---- rustfs/src/server/http.rs | 11 +++++++-- 4 files changed, 38 insertions(+), 12 deletions(-) diff --git a/crates/ecstore/src/disk/local.rs b/crates/ecstore/src/disk/local.rs index cc4494e3b..03d1853f7 100644 --- a/crates/ecstore/src/disk/local.rs +++ b/crates/ecstore/src/disk/local.rs @@ -1696,14 +1696,24 @@ impl AsyncRead for StallTimeoutReader { } fn record_file_cache_reclaim_success(kind: &'static str, reclaim_len: usize, started: std::time::Instant) { - counter!("rustfs_page_cache_reclaim_requests_total", "kind" => kind.to_string(), "result" => "ok".to_string()).increment(1); - counter!("rustfs_page_cache_reclaim_bytes_total", "kind" => kind.to_string()).increment(reclaim_len as u64); - metrics::histogram!("rustfs_page_cache_reclaim_duration_seconds", "kind" => kind.to_string()) - .record(started.elapsed().as_secs_f64()); + // Runs per read-stream page-cache reclaim window; skip the whole emission + // (three metric-key constructions) when general metrics are disabled. + if !rustfs_io_metrics::metrics_enabled() { + return; + } + // `kind`, "ok" and "err" are all `&'static str`; the `metrics` macros take + // static label values directly, so pass them as-is instead of allocating a + // `String` per reclaim. + counter!("rustfs_page_cache_reclaim_requests_total", "kind" => kind, "result" => "ok").increment(1); + counter!("rustfs_page_cache_reclaim_bytes_total", "kind" => kind).increment(reclaim_len as u64); + metrics::histogram!("rustfs_page_cache_reclaim_duration_seconds", "kind" => kind).record(started.elapsed().as_secs_f64()); } fn record_file_cache_reclaim_error(kind: &'static str) { - counter!("rustfs_page_cache_reclaim_requests_total", "kind" => kind.to_string(), "result" => "err".to_string()).increment(1); + if !rustfs_io_metrics::metrics_enabled() { + return; + } + counter!("rustfs_page_cache_reclaim_requests_total", "kind" => kind, "result" => "err").increment(1); } cached_read_env! { @@ -12919,7 +12929,9 @@ mod test { let recorder = crate::test_metrics::CapturingRecorder::default(); let previous_gate = rustfs_io_metrics::get_stage_metrics_enabled(); + let previous_metrics_gate = rustfs_io_metrics::metrics_enabled(); rustfs_io_metrics::set_get_stage_metrics_enabled(true); + rustfs_io_metrics::set_metrics_enabled(true); metrics::with_local_recorder(&recorder, || { record_mmap_copy_stage(metrics(), "mmap_copy", None); record_mmap_copy_stage(metrics(), "mmap_copy", Some(std::time::Instant::now())); @@ -12935,6 +12947,7 @@ mod test { } }); rustfs_io_metrics::set_get_stage_metrics_enabled(previous_gate); + rustfs_io_metrics::set_metrics_enabled(previous_metrics_gate); assert_eq!( recorder.histogram_sample_count("rustfs_io_get_object_stage_duration_seconds"), diff --git a/crates/ecstore/src/set_disk/core/io_primitives.rs b/crates/ecstore/src/set_disk/core/io_primitives.rs index 1b31ad22c..602acc31f 100644 --- a/crates/ecstore/src/set_disk/core/io_primitives.rs +++ b/crates/ecstore/src/set_disk/core/io_primitives.rs @@ -775,7 +775,9 @@ pub(in crate::set_disk) async fn release_read_repair_heal_reservation(key: &Read } pub(in crate::set_disk) fn record_read_repair_dedup(reason: &'static str) { - counter!("rustfs_heal_read_repair_dedup_total", "reason" => reason.to_string()).increment(1); + // `reason` is already `&'static str`; the macro takes it directly, so no + // per-call `String` allocation. + counter!("rustfs_heal_read_repair_dedup_total", "reason" => reason).increment(1); } pub(in crate::set_disk) enum ReadRepairAdmissionOutcome { diff --git a/crates/ecstore/src/set_disk/ops/object.rs b/crates/ecstore/src/set_disk/ops/object.rs index 0fca28cb2..d2f0333b9 100644 --- a/crates/ecstore/src/set_disk/ops/object.rs +++ b/crates/ecstore/src/set_disk/ops/object.rs @@ -98,7 +98,7 @@ impl crate::storage_api_contracts::object::ObjectIO for SetDisks { // Acquire a shared read-lock early to protect read consistency let mut read_lock_guard = if !opts.no_lock { - let acquire_start = Instant::now(); + let acquire_start = stage_metrics_enabled.then(Instant::now); let lock_stage_start = get_stage_timer_if_enabled(stage_metrics_enabled); // Record lock wait for deadlock detection @@ -116,9 +116,13 @@ impl crate::storage_api_contracts::object::ObjectIO for SetDisks { // Record lock acquisition for deadlock detection let _lock_id = record_lock_acquire(bucket, object, "read"); - // Record lock statistics - metrics::counter!("rustfs.lock.acquire.total", "type" => "read").increment(1); - metrics::histogram!("rustfs.lock.acquire.duration.seconds").record(acquire_start.elapsed().as_secs_f64()); + // Record lock statistics only when GET stage metrics are enabled, + // matching the adjacent stage timer. Avoids a per-GET clock read and + // two global-recorder lookups when observability/stage metrics are off. + if let Some(acquire_start) = acquire_start { + metrics::counter!("rustfs.lock.acquire.total", "type" => "read").increment(1); + metrics::histogram!("rustfs.lock.acquire.duration.seconds").record(acquire_start.elapsed().as_secs_f64()); + } record_get_stage_duration_if_enabled(GET_OBJECT_PATH_SET_DISK, GET_STAGE_LOCK_ACQUIRE, lock_stage_start); Some(guard) diff --git a/rustfs/src/server/http.rs b/rustfs/src/server/http.rs index 2987467b9..84871073f 100644 --- a/rustfs/src/server/http.rs +++ b/rustfs/src/server/http.rs @@ -90,6 +90,13 @@ const METRIC_HTTP_SERVER_REQUEST_BODY_BYTES_TOTAL: &str = "rustfs_http_server_re 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"; + +/// Cached handle for the per-response-body-chunk byte counter. A streamed GET +/// emits many chunks, so resolving the `counter!` registry entry once — the +/// global recorder is installed at startup before any response streams — avoids +/// a registry lookup on every chunk. +static RESP_BODY_BYTES_COUNTER: std::sync::LazyLock = + std::sync::LazyLock::new(|| counter!(METRIC_HTTP_SERVER_RESPONSE_BODY_BYTES_TOTAL)); const LOG_COMPONENT_SERVER: &str = "server"; const LOG_SUBSYSTEM_HTTP: &str = "http"; const LOG_SUBSYSTEM_TRANSPORT: &str = "transport"; @@ -1320,7 +1327,7 @@ fn process_connection( }) .on_response(trace_on_response) .on_body_chunk(|chunk: &Bytes, latency: Duration, span: &Span| { - counter!(METRIC_HTTP_SERVER_RESPONSE_BODY_BYTES_TOTAL).increment(chunk.len() as u64); + RESP_BODY_BYTES_COUNTER.increment(chunk.len() as u64); #[cfg(feature = "tracing-chunk-debug")] { let _enter = span.enter(); @@ -1480,7 +1487,7 @@ fn process_connection( }) .on_response(trace_on_response) .on_body_chunk(|chunk: &Bytes, latency: Duration, span: &Span| { - counter!(METRIC_HTTP_SERVER_RESPONSE_BODY_BYTES_TOTAL).increment(chunk.len() as u64); + RESP_BODY_BYTES_COUNTER.increment(chunk.len() as u64); #[cfg(feature = "tracing-chunk-debug")] { let _enter = span.enter();