From 4995ba6bf9bba83d682c061f107f6516a1c02e1e Mon Sep 17 00:00:00 2001 From: Florian Engelhardt Date: Wed, 4 Feb 2026 09:53:01 +0100 Subject: [PATCH 1/3] feat(profiling): move CPU time capture to include serialization for `ddprof_upload` for current profile exported Co-Authored-By: Claude Opus 4.5 --- profiling/src/profiling/uploader.rs | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/profiling/src/profiling/uploader.rs b/profiling/src/profiling/uploader.rs index 8dcc82b146..ee8437e482 100644 --- a/profiling/src/profiling/uploader.rs +++ b/profiling/src/profiling/uploader.rs @@ -89,7 +89,11 @@ impl Uploader { Some(metadata) } - fn upload(&self, message: Box) -> anyhow::Result { + fn upload( + &self, + message: Box, + last_cpu: &mut Option, + ) -> anyhow::Result { let index = message.index; let profile = message.profile; @@ -110,6 +114,11 @@ impl Uploader { let serialized = profile.serialize_into_compressed_pprof(Some(message.end_time), message.duration)?; exporter.set_timeout(10000); // 10 seconds in milliseconds + + // Capture CPU time up to this point. Note: metadata generation, exporter + // building, and HTTP request time will be attributed to the next profile. + update_background_cpu_time(last_cpu); + let request = exporter.build( serialized, &[], @@ -147,7 +156,6 @@ impl Uploader { }, Ok(UploadMessage::Upload(request)) => { - update_background_cpu_time(&mut last_cpu); match pprof_filename { Some(filename) => { let filename_prefix = filename.as_ref(); @@ -157,7 +165,7 @@ impl Uploader { std::fs::write(&name, r.buffer).expect("write to succeed"); info!("Successfully wrote profile to {name}"); }, - None => match self.upload(request) { + None => match self.upload(request, &mut last_cpu) { Ok(status) => { if status >= 400 { warn!("Unexpected HTTP status when sending profile (HTTP {status}).") From 6e3a026b55c4782d6729fb3ad17c1f1d536727a1 Mon Sep 17 00:00:00 2001 From: Florian Engelhardt Date: Wed, 4 Feb 2026 09:53:57 +0100 Subject: [PATCH 2/3] feat(profiling): add CPU time tracking for `ddprof_time` thread Co-Authored-By: Claude Opus 4.5 --- profiling/src/profiling/mod.rs | 3 +++ 1 file changed, 3 insertions(+) diff --git a/profiling/src/profiling/mod.rs b/profiling/src/profiling/mod.rs index fe07fa40c9..ea5091f6a0 100644 --- a/profiling/src/profiling/mod.rs +++ b/profiling/src/profiling/mod.rs @@ -595,6 +595,7 @@ impl TimeCollector { let upload_tick = crossbeam_channel::tick(self.upload_period); let never = crossbeam_channel::never(); let mut running = true; + let mut last_cpu = ThreadTime::try_now().ok(); while running { // The crossbeam_channel::select! doesn't have the ability to @@ -620,6 +621,7 @@ impl TimeCollector { Self::handle_resource_message(message, &mut profiles), ProfilerMessage::Cancel => { // flush what we have before exiting + update_background_cpu_time(&mut last_cpu); last_wall_export = self.handle_timeout(&mut profiles, &last_wall_export); running = false; }, @@ -657,6 +659,7 @@ impl TimeCollector { recv(upload_tick) -> message => { if message.is_ok() { + update_background_cpu_time(&mut last_cpu); last_wall_export = self.handle_timeout(&mut profiles, &last_wall_export); } }, From b33c01e4bbc5d962f2fbaea0a840f615e76fa50e Mon Sep 17 00:00:00 2001 From: Florian Engelhardt Date: Wed, 4 Feb 2026 10:10:41 +0100 Subject: [PATCH 3/3] feat(profiling): separate CPU time tracking per background thread Co-authored-by: Claude Opus 4.5 --- profiling/src/profiling/mod.rs | 11 ++++++----- profiling/src/profiling/uploader.rs | 27 +++++++++++++++++++-------- 2 files changed, 25 insertions(+), 13 deletions(-) diff --git a/profiling/src/profiling/mod.rs b/profiling/src/profiling/mod.rs index ea5091f6a0..a7470c3888 100644 --- a/profiling/src/profiling/mod.rs +++ b/profiling/src/profiling/mod.rs @@ -64,7 +64,8 @@ static mut PROFILER: OnceLock = OnceLock::new(); pub static STACK_WALK_COUNT: AtomicU64 = AtomicU64::new(0); pub static STACK_WALK_CPU_TIME_NS: AtomicU64 = AtomicU64::new(0); -pub static BACKGROUND_THREAD_CPU_TIME_NS: AtomicU64 = AtomicU64::new(0); +pub static DDPROF_TIME_CPU_TIME_NS: AtomicU64 = AtomicU64::new(0); +pub static DDPROF_UPLOAD_CPU_TIME_NS: AtomicU64 = AtomicU64::new(0); fn cpu_time_delta_ns(now: ThreadTime, prev: ThreadTime) -> u64 { match now.as_duration().checked_sub(prev.as_duration()) { @@ -73,14 +74,14 @@ fn cpu_time_delta_ns(now: ThreadTime, prev: ThreadTime) -> u64 { } } -pub(crate) fn update_background_cpu_time(last: &mut Option) { +pub(crate) fn update_cpu_time_counter(last: &mut Option, counter: &AtomicU64) { let Some(prev) = last.take() else { *last = ThreadTime::try_now().ok(); return; }; if let Ok(now) = ThreadTime::try_now() { let elapsed_ns = cpu_time_delta_ns(now, prev); - BACKGROUND_THREAD_CPU_TIME_NS.fetch_add(elapsed_ns, Ordering::Relaxed); + counter.fetch_add(elapsed_ns, Ordering::Relaxed); *last = Some(now); } else { *last = Some(prev); @@ -621,7 +622,7 @@ impl TimeCollector { Self::handle_resource_message(message, &mut profiles), ProfilerMessage::Cancel => { // flush what we have before exiting - update_background_cpu_time(&mut last_cpu); + update_cpu_time_counter(&mut last_cpu, &DDPROF_TIME_CPU_TIME_NS); last_wall_export = self.handle_timeout(&mut profiles, &last_wall_export); running = false; }, @@ -659,7 +660,7 @@ impl TimeCollector { recv(upload_tick) -> message => { if message.is_ok() { - update_background_cpu_time(&mut last_cpu); + update_cpu_time_counter(&mut last_cpu, &DDPROF_TIME_CPU_TIME_NS); last_wall_export = self.handle_timeout(&mut profiles, &last_wall_export); } }, diff --git a/profiling/src/profiling/uploader.rs b/profiling/src/profiling/uploader.rs index ee8437e482..7a0848a257 100644 --- a/profiling/src/profiling/uploader.rs +++ b/profiling/src/profiling/uploader.rs @@ -1,7 +1,7 @@ use crate::config::AgentEndpoint; use crate::profiling::{ - update_background_cpu_time, UploadMessage, UploadRequest, BACKGROUND_THREAD_CPU_TIME_NS, - STACK_WALK_COUNT, STACK_WALK_CPU_TIME_NS, + update_cpu_time_counter, UploadMessage, UploadRequest, DDPROF_TIME_CPU_TIME_NS, + DDPROF_UPLOAD_CPU_TIME_NS, STACK_WALK_COUNT, STACK_WALK_CPU_TIME_NS, }; use crate::{PROFILER_NAME_STR, PROFILER_VERSION_STR}; use chrono::{DateTime, Utc}; @@ -48,7 +48,7 @@ impl Uploader { /// This function will not only create the internal metadata JSON representation, but is also /// in charge to reset all those counters back to 0. fn create_internal_metadata() -> Option { - let capacity = 3 + cfg!(feature = "debug_stats") as usize * 3; + let capacity = 4 + cfg!(feature = "debug_stats") as usize * 3; let mut metadata = serde_json::Map::with_capacity(capacity); metadata.insert( "stack_walk_count".to_string(), @@ -59,8 +59,12 @@ impl Uploader { json!(STACK_WALK_CPU_TIME_NS.swap(0, Ordering::Relaxed)), ); metadata.insert( - "background_threads_cpu_time_ns".to_string(), - json!(BACKGROUND_THREAD_CPU_TIME_NS.swap(0, Ordering::Relaxed)), + "ddprof_time_cpu_time_ns".to_string(), + json!(DDPROF_TIME_CPU_TIME_NS.swap(0, Ordering::Relaxed)), + ); + metadata.insert( + "ddprof_upload_cpu_time_ns".to_string(), + json!(DDPROF_UPLOAD_CPU_TIME_NS.swap(0, Ordering::Relaxed)), ); #[cfg(feature = "debug_stats")] { @@ -117,7 +121,7 @@ impl Uploader { // Capture CPU time up to this point. Note: metadata generation, exporter // building, and HTTP request time will be attributed to the next profile. - update_background_cpu_time(last_cpu); + update_cpu_time_counter(last_cpu, &DDPROF_UPLOAD_CPU_TIME_NS); let request = exporter.build( serialized, @@ -204,7 +208,8 @@ mod tests { // Set up all counters with known values STACK_WALK_COUNT.store(7, Ordering::Relaxed); STACK_WALK_CPU_TIME_NS.store(9000, Ordering::Relaxed); - BACKGROUND_THREAD_CPU_TIME_NS.store(1234, Ordering::Relaxed); + DDPROF_TIME_CPU_TIME_NS.store(1234, Ordering::Relaxed); + DDPROF_UPLOAD_CPU_TIME_NS.store(5678, Ordering::Relaxed); EXCEPTION_PROFILING_EXCEPTION_COUNT.store(42, Ordering::Relaxed); ALLOCATION_PROFILING_COUNT.store(100, Ordering::Relaxed); ALLOCATION_PROFILING_SIZE.store(1024, Ordering::Relaxed); @@ -229,10 +234,16 @@ mod tests { ); assert_eq!( metadata - .get("background_threads_cpu_time_ns") + .get("ddprof_time_cpu_time_ns") .and_then(|v| v.as_u64()), Some(1234) ); + assert_eq!( + metadata + .get("ddprof_upload_cpu_time_ns") + .and_then(|v| v.as_u64()), + Some(5678) + ); assert_eq!( metadata.get("exceptions_count").and_then(|v| v.as_u64()),