Skip to content

Commit b33c01e

Browse files
feat(profiling): separate CPU time tracking per background thread
Co-authored-by: Claude Opus 4.5 <[email protected]>
1 parent 6e3a026 commit b33c01e

2 files changed

Lines changed: 25 additions & 13 deletions

File tree

profiling/src/profiling/mod.rs

Lines changed: 6 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,8 @@ static mut PROFILER: OnceLock<Profiler> = OnceLock::new();
6464

6565
pub static STACK_WALK_COUNT: AtomicU64 = AtomicU64::new(0);
6666
pub static STACK_WALK_CPU_TIME_NS: AtomicU64 = AtomicU64::new(0);
67-
pub static BACKGROUND_THREAD_CPU_TIME_NS: AtomicU64 = AtomicU64::new(0);
67+
pub static DDPROF_TIME_CPU_TIME_NS: AtomicU64 = AtomicU64::new(0);
68+
pub static DDPROF_UPLOAD_CPU_TIME_NS: AtomicU64 = AtomicU64::new(0);
6869

6970
fn cpu_time_delta_ns(now: ThreadTime, prev: ThreadTime) -> u64 {
7071
match now.as_duration().checked_sub(prev.as_duration()) {
@@ -73,14 +74,14 @@ fn cpu_time_delta_ns(now: ThreadTime, prev: ThreadTime) -> u64 {
7374
}
7475
}
7576

76-
pub(crate) fn update_background_cpu_time(last: &mut Option<ThreadTime>) {
77+
pub(crate) fn update_cpu_time_counter(last: &mut Option<ThreadTime>, counter: &AtomicU64) {
7778
let Some(prev) = last.take() else {
7879
*last = ThreadTime::try_now().ok();
7980
return;
8081
};
8182
if let Ok(now) = ThreadTime::try_now() {
8283
let elapsed_ns = cpu_time_delta_ns(now, prev);
83-
BACKGROUND_THREAD_CPU_TIME_NS.fetch_add(elapsed_ns, Ordering::Relaxed);
84+
counter.fetch_add(elapsed_ns, Ordering::Relaxed);
8485
*last = Some(now);
8586
} else {
8687
*last = Some(prev);
@@ -621,7 +622,7 @@ impl TimeCollector {
621622
Self::handle_resource_message(message, &mut profiles),
622623
ProfilerMessage::Cancel => {
623624
// flush what we have before exiting
624-
update_background_cpu_time(&mut last_cpu);
625+
update_cpu_time_counter(&mut last_cpu, &DDPROF_TIME_CPU_TIME_NS);
625626
last_wall_export = self.handle_timeout(&mut profiles, &last_wall_export);
626627
running = false;
627628
},
@@ -659,7 +660,7 @@ impl TimeCollector {
659660

660661
recv(upload_tick) -> message => {
661662
if message.is_ok() {
662-
update_background_cpu_time(&mut last_cpu);
663+
update_cpu_time_counter(&mut last_cpu, &DDPROF_TIME_CPU_TIME_NS);
663664
last_wall_export = self.handle_timeout(&mut profiles, &last_wall_export);
664665
}
665666
},

profiling/src/profiling/uploader.rs

Lines changed: 19 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
use crate::config::AgentEndpoint;
22
use crate::profiling::{
3-
update_background_cpu_time, UploadMessage, UploadRequest, BACKGROUND_THREAD_CPU_TIME_NS,
4-
STACK_WALK_COUNT, STACK_WALK_CPU_TIME_NS,
3+
update_cpu_time_counter, UploadMessage, UploadRequest, DDPROF_TIME_CPU_TIME_NS,
4+
DDPROF_UPLOAD_CPU_TIME_NS, STACK_WALK_COUNT, STACK_WALK_CPU_TIME_NS,
55
};
66
use crate::{PROFILER_NAME_STR, PROFILER_VERSION_STR};
77
use chrono::{DateTime, Utc};
@@ -48,7 +48,7 @@ impl Uploader {
4848
/// This function will not only create the internal metadata JSON representation, but is also
4949
/// in charge to reset all those counters back to 0.
5050
fn create_internal_metadata() -> Option<serde_json::Value> {
51-
let capacity = 3 + cfg!(feature = "debug_stats") as usize * 3;
51+
let capacity = 4 + cfg!(feature = "debug_stats") as usize * 3;
5252
let mut metadata = serde_json::Map::with_capacity(capacity);
5353
metadata.insert(
5454
"stack_walk_count".to_string(),
@@ -59,8 +59,12 @@ impl Uploader {
5959
json!(STACK_WALK_CPU_TIME_NS.swap(0, Ordering::Relaxed)),
6060
);
6161
metadata.insert(
62-
"background_threads_cpu_time_ns".to_string(),
63-
json!(BACKGROUND_THREAD_CPU_TIME_NS.swap(0, Ordering::Relaxed)),
62+
"ddprof_time_cpu_time_ns".to_string(),
63+
json!(DDPROF_TIME_CPU_TIME_NS.swap(0, Ordering::Relaxed)),
64+
);
65+
metadata.insert(
66+
"ddprof_upload_cpu_time_ns".to_string(),
67+
json!(DDPROF_UPLOAD_CPU_TIME_NS.swap(0, Ordering::Relaxed)),
6468
);
6569
#[cfg(feature = "debug_stats")]
6670
{
@@ -117,7 +121,7 @@ impl Uploader {
117121

118122
// Capture CPU time up to this point. Note: metadata generation, exporter
119123
// building, and HTTP request time will be attributed to the next profile.
120-
update_background_cpu_time(last_cpu);
124+
update_cpu_time_counter(last_cpu, &DDPROF_UPLOAD_CPU_TIME_NS);
121125

122126
let request = exporter.build(
123127
serialized,
@@ -204,7 +208,8 @@ mod tests {
204208
// Set up all counters with known values
205209
STACK_WALK_COUNT.store(7, Ordering::Relaxed);
206210
STACK_WALK_CPU_TIME_NS.store(9000, Ordering::Relaxed);
207-
BACKGROUND_THREAD_CPU_TIME_NS.store(1234, Ordering::Relaxed);
211+
DDPROF_TIME_CPU_TIME_NS.store(1234, Ordering::Relaxed);
212+
DDPROF_UPLOAD_CPU_TIME_NS.store(5678, Ordering::Relaxed);
208213
EXCEPTION_PROFILING_EXCEPTION_COUNT.store(42, Ordering::Relaxed);
209214
ALLOCATION_PROFILING_COUNT.store(100, Ordering::Relaxed);
210215
ALLOCATION_PROFILING_SIZE.store(1024, Ordering::Relaxed);
@@ -229,10 +234,16 @@ mod tests {
229234
);
230235
assert_eq!(
231236
metadata
232-
.get("background_threads_cpu_time_ns")
237+
.get("ddprof_time_cpu_time_ns")
233238
.and_then(|v| v.as_u64()),
234239
Some(1234)
235240
);
241+
assert_eq!(
242+
metadata
243+
.get("ddprof_upload_cpu_time_ns")
244+
.and_then(|v| v.as_u64()),
245+
Some(5678)
246+
);
236247

237248
assert_eq!(
238249
metadata.get("exceptions_count").and_then(|v| v.as_u64()),

0 commit comments

Comments
 (0)