From 8ee22013a3039c2b58bcde40def513540f8ba20c Mon Sep 17 00:00:00 2001 From: Levi Morrison Date: Tue, 20 Jan 2026 20:54:58 -0700 Subject: [PATCH 1/4] feat(profiling): stack walks in timeline --- profiling/src/profiling/mod.rs | 54 ++++++++++++++++++++++++++++++---- 1 file changed, 48 insertions(+), 6 deletions(-) diff --git a/profiling/src/profiling/mod.rs b/profiling/src/profiling/mod.rs index 31059ef396..9670e7a544 100644 --- a/profiling/src/profiling/mod.rs +++ b/profiling/src/profiling/mod.rs @@ -652,6 +652,7 @@ pub enum UploadMessage { } const COW_EVAL: Cow = Cow::Borrowed("[eval]"); +const COW_PROFILER_STACK_WALK: Cow = Cow::Borrowed("[profiler stack walk]"); const DDPROF_TIME: &str = "ddprof_time"; const DDPROF_UPLOAD: &str = "ddprof_upload"; @@ -908,12 +909,10 @@ impl Profiler { pub fn collect_time(&self, execute_data: *mut zend_execute_data, interrupt_count: u32) { // todo: should probably exclude the wall and CPU time used by collecting the sample. let interrupt_count = interrupt_count as i64; - let result = collect_stack_sample(execute_data); + let (result, wall_time, cpu_time) = self.collect_stack_sample_with_timeline(execute_data); match result { Ok(frames) => { let depth = frames.len(); - let (wall_time, cpu_time) = CLOCKS.with_borrow_mut(Clocks::rotate_clocks); - let labels = Profiler::common_labels(0); let n_labels = labels.len(); @@ -959,7 +958,8 @@ impl Profiler { alloc_samples: i64, alloc_size: i64, ) { - let result = collect_stack_sample(execute_data); + let (result, _wall_time, _cpu_time) = + self.collect_stack_sample_with_timeline(execute_data); match result { Ok(frames) => { let depth = frames.len(); @@ -998,7 +998,8 @@ impl Profiler { exception: String, message: Option, ) { - let result = collect_stack_sample(execute_data); + let (result, _wall_time, _cpu_time) = + self.collect_stack_sample_with_timeline(execute_data); match result { Ok(frames) => { let depth = frames.len(); @@ -1405,7 +1406,8 @@ impl Profiler { where F: FnOnce(&mut SampleValues), { - let result = collect_stack_sample(execute_data); + let (result, _wall_time, _cpu_time) = + self.collect_stack_sample_with_timeline(execute_data); match result { Ok(frames) => { let depth = frames.len(); @@ -1529,6 +1531,46 @@ impl Profiler { }, } } + + fn collect_stack_sample_with_timeline( + &self, + execute_data: *mut zend_execute_data, + ) -> (Result, CollectStackSampleError>, i64, i64) { + let (wall_time, cpu_time) = CLOCKS.with_borrow_mut(Clocks::rotate_clocks); + let result = collect_stack_sample(execute_data); + let (stack_walk_wall_time, _stack_walk_cpu_time) = + CLOCKS.with_borrow_mut(Clocks::rotate_clocks); + + if self.is_timeline_enabled() { + if let Ok(now) = SystemTime::now().duration_since(UNIX_EPOCH) { + let timestamp = now.as_nanos() as i64; + let labels = Profiler::common_labels(0); + let n_labels = labels.len(); + match self.prepare_and_send_message( + vec![ZendFrame { + function: COW_PROFILER_STACK_WALK, + file: None, + line: 0, + }], + SampleValues { + timeline: stack_walk_wall_time, + ..Default::default() + }, + labels, + timestamp, + ) { + Ok(_) => { + trace!("Sent stack walk timeline event with {n_labels} labels to profiler.") + } + Err(err) => warn!( + "Failed to send stack walk timeline event with {n_labels} labels to profiler: {err}" + ), + } + } + } + + (result, wall_time, cpu_time) + } } pub struct JoinError { From cfad181e4b511ed358d33f6d7045c04dbc5d047e Mon Sep 17 00:00:00 2001 From: Levi Morrison Date: Wed, 21 Jan 2026 09:06:21 -0700 Subject: [PATCH 2/4] fix: put sample into {wall,cpu}_time instead of timeline --- profiling/src/profiling/mod.rs | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/profiling/src/profiling/mod.rs b/profiling/src/profiling/mod.rs index 9670e7a544..aa73d42fb8 100644 --- a/profiling/src/profiling/mod.rs +++ b/profiling/src/profiling/mod.rs @@ -1538,7 +1538,7 @@ impl Profiler { ) -> (Result, CollectStackSampleError>, i64, i64) { let (wall_time, cpu_time) = CLOCKS.with_borrow_mut(Clocks::rotate_clocks); let result = collect_stack_sample(execute_data); - let (stack_walk_wall_time, _stack_walk_cpu_time) = + let (stack_walk_wall_time, stack_walk_cpu_time) = CLOCKS.with_borrow_mut(Clocks::rotate_clocks); if self.is_timeline_enabled() { @@ -1553,17 +1553,18 @@ impl Profiler { line: 0, }], SampleValues { - timeline: stack_walk_wall_time, + wall_time: stack_walk_wall_time, + cpu_time: stack_walk_cpu_time, ..Default::default() }, labels, timestamp, ) { Ok(_) => { - trace!("Sent stack walk timeline event with {n_labels} labels to profiler.") + trace!("Sent stack walk sample with {n_labels} labels to profiler.") } Err(err) => warn!( - "Failed to send stack walk timeline event with {n_labels} labels to profiler: {err}" + "Failed to send stack walk sample with {n_labels} labels to profiler: {err}" ), } } From 3647506a6fbc152321e780a0304889bd807918fc Mon Sep 17 00:00:00 2001 From: Levi Morrison Date: Wed, 21 Jan 2026 15:13:21 -0700 Subject: [PATCH 3/4] reformat and remove is_timeline_enabled guard --- profiling/src/profiling/mod.rs | 57 +++++++++++++++------------------- 1 file changed, 25 insertions(+), 32 deletions(-) diff --git a/profiling/src/profiling/mod.rs b/profiling/src/profiling/mod.rs index 7d39857764..a300ff5133 100644 --- a/profiling/src/profiling/mod.rs +++ b/profiling/src/profiling/mod.rs @@ -955,8 +955,7 @@ impl Profiler { alloc_size: i64, interrupt_count: Option, ) { - let (result, _wall_time, _cpu_time) = - self.collect_stack_sample_with_timeline(execute_data); + let (result, _wall_time, _cpu_time) = self.collect_stack_sample_with_timeline(execute_data); match result { Ok(frames) => { let depth = frames.len(); @@ -1009,8 +1008,7 @@ impl Profiler { exception: String, message: Option, ) { - let (result, _wall_time, _cpu_time) = - self.collect_stack_sample_with_timeline(execute_data); + let (result, _wall_time, _cpu_time) = self.collect_stack_sample_with_timeline(execute_data); match result { Ok(frames) => { let depth = frames.len(); @@ -1410,8 +1408,7 @@ impl Profiler { where F: FnOnce(&mut SampleValues), { - let (result, _wall_time, _cpu_time) = - self.collect_stack_sample_with_timeline(execute_data); + let (result, _wall_time, _cpu_time) = self.collect_stack_sample_with_timeline(execute_data); match result { Ok(frames) => { let depth = frames.len(); @@ -1555,32 +1552,28 @@ impl Profiler { let (stack_walk_wall_time, stack_walk_cpu_time) = CLOCKS.with_borrow_mut(Clocks::rotate_clocks); - if self.is_timeline_enabled() { - if let Ok(now) = SystemTime::now().duration_since(UNIX_EPOCH) { - let timestamp = now.as_nanos() as i64; - let labels = Profiler::common_labels(0); - let n_labels = labels.len(); - match self.prepare_and_send_message( - vec![ZendFrame { - function: COW_PROFILER_STACK_WALK, - file: None, - line: 0, - }], - SampleValues { - wall_time: stack_walk_wall_time, - cpu_time: stack_walk_cpu_time, - ..Default::default() - }, - labels, - timestamp, - ) { - Ok(_) => { - trace!("Sent stack walk sample with {n_labels} labels to profiler.") - } - Err(err) => warn!( - "Failed to send stack walk sample with {n_labels} labels to profiler: {err}" - ), - } + let timestamp = self.get_timeline_timestamp(); + let labels = Profiler::common_labels(0); + let n_labels = labels.len(); + match self.prepare_and_send_message( + vec![ZendFrame { + function: COW_PROFILER_STACK_WALK, + file: None, + line: 0, + }], + SampleValues { + wall_time: stack_walk_wall_time, + cpu_time: stack_walk_cpu_time, + ..Default::default() + }, + labels, + timestamp, + ) { + Ok(_) => { + trace!("Sent stack walk sample with {n_labels} labels to profiler.") + } + Err(err) => { + warn!("Failed to send stack walk sample with {n_labels} labels to profiler: {err}") } } From dc0c9caa9876a92449b73f585128fa2f8bbe5a18 Mon Sep 17 00:00:00 2001 From: Levi Morrison Date: Mon, 26 Jan 2026 12:07:34 -0700 Subject: [PATCH 4/4] fix: don't rotate 3 times --- profiling/src/profiling/mod.rs | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/profiling/src/profiling/mod.rs b/profiling/src/profiling/mod.rs index a300ff5133..52ab137901 100644 --- a/profiling/src/profiling/mod.rs +++ b/profiling/src/profiling/mod.rs @@ -955,7 +955,7 @@ impl Profiler { alloc_size: i64, interrupt_count: Option, ) { - let (result, _wall_time, _cpu_time) = self.collect_stack_sample_with_timeline(execute_data); + let (result, wall_time, cpu_time) = self.collect_stack_sample_with_timeline(execute_data); match result { Ok(frames) => { let depth = frames.len(); @@ -963,7 +963,6 @@ impl Profiler { // Optionally collect time data when interrupt_count is provided let (interrupt_count, wall_time, cpu_time, timestamp) = if let Some(count) = interrupt_count { - let (wall_time, cpu_time) = CLOCKS.with_borrow_mut(Clocks::rotate_clocks); let timestamp = self.get_timeline_timestamp(); (count as i64, wall_time, cpu_time, timestamp) } else {