Skip to content

Commit ffeeba8

Browse files
authored
refactor(profiling): extract wall_time.rs file (#2467)
1 parent 5334fb5 commit ffeeba8

File tree

4 files changed

+148
-141
lines changed

4 files changed

+148
-141
lines changed

ext/engine_hooks.c

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -30,10 +30,9 @@ void dd_search_for_profiling_symbols(void *arg) {
3030
if (extension->name && strcmp(extension->name, "datadog-profiling") == 0) {
3131
DL_HANDLE handle = extension->handle;
3232

33-
profiling_interrupt_function = DL_FETCH_SYMBOL(handle, "datadog_profiling_interrupt_function");
33+
profiling_interrupt_function = DL_FETCH_SYMBOL(handle, "ddog_php_prof_interrupt_function");
3434
if (UNEXPECTED(!profiling_interrupt_function)) {
35-
LOG(Warn, "[Datadog Trace] Profiling was detected, but locating symbol %s failed: %s\n", "datadog_profiling_interrupt_function",
36-
DL_ERROR());
35+
LOG(Warn, "[Datadog Trace] Profiling was detected, but locating symbol %s failed: %s\n", "ddog_php_prof_interrupt_function", DL_ERROR());
3736
}
3837

3938
profiling_notify_trace_finished = DL_FETCH_SYMBOL(handle, "datadog_profiling_notify_trace_finished");

profiling/src/capi.rs

Lines changed: 2 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
//! Definitions for interacting with the profiler from a C API, such as the
22
//! ddtrace extension.
33
4-
use crate::bindings::{zend_execute_data, ZaiStr};
4+
use crate::bindings::ZaiStr;
55
use crate::runtime_id;
66

77
#[no_mangle]
@@ -52,18 +52,7 @@ extern "C" fn ddog_php_prof_trigger_time_sample() {
5252
})
5353
}
5454

55-
/// Gathers a time sample if the configured period has elapsed. Used by the
56-
/// tracer to handle pending profiler interrupts before calling a tracing
57-
/// closure from an internal function hook; if this isn't done then the
58-
/// closure is erroneously at the top of the stack.
59-
///
60-
/// # Safety
61-
/// The zend_execute_data pointer should come from the engine to ensure it and
62-
/// its sub-objects are valid.
63-
#[no_mangle]
64-
pub extern "C" fn datadog_profiling_interrupt_function(execute_data: *mut zend_execute_data) {
65-
crate::interrupt_function(execute_data);
66-
}
55+
pub use crate::wall_time::ddog_php_prof_interrupt_function;
6756

6857
#[cfg(test)]
6958
mod tests {

profiling/src/lib.rs

Lines changed: 2 additions & 125 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@ mod exception;
1616

1717
#[cfg(feature = "timeline")]
1818
mod timeline;
19+
mod wall_time;
1920

2021
use bindings as zend;
2122
use bindings::{ddog_php_prof_php_version_id, ZendExtension, ZendResult};
@@ -32,8 +33,6 @@ use sapi::Sapi;
3233
use std::borrow::Cow;
3334
use std::cell::RefCell;
3435
use std::ffi::CStr;
35-
use std::mem::MaybeUninit;
36-
use std::ops::Deref;
3736
use std::os::raw::c_int;
3837
use std::path::PathBuf;
3938
use std::str::FromStr;
@@ -170,19 +169,6 @@ pub extern "C" fn get_module() -> &'static mut zend::ModuleEntry {
170169
unsafe { &mut *MODULE }
171170
}
172171

173-
/// The engine's previous `zend_interrupt_function` value, if there is one.
174-
/// Note that because of things like Apache reload which call minit more than
175-
/// once per process, this cannot be made into a OnceCell nor lazy_static.
176-
static mut PREV_INTERRUPT_FUNCTION: MaybeUninit<Option<zend::VmInterruptFn>> =
177-
MaybeUninit::uninit();
178-
179-
/// The engine's previous `zend::zend_execute_internal` value, or
180-
/// `zend::execute_internal` if none. This is a highly active path, so although
181-
/// it could be made safe with Mutex, the cost is too high.
182-
static mut PREV_EXECUTE_INTERNAL: MaybeUninit<
183-
unsafe extern "C" fn(execute_data: *mut zend::zend_execute_data, return_value: *mut zend::zval),
184-
> = MaybeUninit::uninit();
185-
186172
/* Important note on the PHP lifecycle:
187173
* Based on how some SAPIs work and the documentation, one might expect that
188174
* MINIT is called once per process, but this is only sort-of true. Some SAPIs
@@ -287,18 +273,7 @@ extern "C" fn minit(_type: c_int, module_number: c_int) -> ZendResult {
287273
};
288274

289275
// Safety: during minit there shouldn't be any threads to race against these writes.
290-
unsafe {
291-
PREV_INTERRUPT_FUNCTION.write(zend::zend_interrupt_function);
292-
PREV_EXECUTE_INTERNAL.write(zend::zend_execute_internal.unwrap_or(zend::execute_internal));
293-
294-
zend::zend_interrupt_function = Some(if zend::zend_interrupt_function.is_some() {
295-
interrupt_function_wrapper
296-
} else {
297-
capi::datadog_profiling_interrupt_function
298-
});
299-
300-
zend::zend_execute_internal = Some(execute_internal);
301-
};
276+
unsafe { wall_time::minit() };
302277

303278
/* Safety: all arguments are valid for this C call.
304279
* Note that on PHP 7 this never fails, and on PHP 8 it returns void.
@@ -1000,104 +975,6 @@ fn notify_trace_finished(local_root_span_id: u64, span_type: Cow<str>, resource:
1000975
});
1001976
}
1002977

1003-
/// Gathers a time sample if the configured period has elapsed and resets the
1004-
/// interrupt_count.
1005-
fn interrupt_function(execute_data: *mut zend::zend_execute_data) {
1006-
REQUEST_LOCALS.with(|cell| {
1007-
// try to borrow and bail out if not successful
1008-
let locals = match cell.try_borrow() {
1009-
Ok(locals) => locals,
1010-
Err(_) => {
1011-
return;
1012-
}
1013-
};
1014-
1015-
if !locals.profiling_enabled {
1016-
return;
1017-
}
1018-
1019-
/* Other extensions/modules or the engine itself may trigger an
1020-
* interrupt, but given how expensive it is to gather a stack trace,
1021-
* it should only be done if we triggered it ourselves. So
1022-
* interrupt_count serves dual purposes:
1023-
* 1. Track how many interrupts there were.
1024-
* 2. Ensure we don't collect on someone else's interrupt.
1025-
*/
1026-
let interrupt_count = locals.interrupt_count.swap(0, Ordering::SeqCst);
1027-
if interrupt_count == 0 {
1028-
return;
1029-
}
1030-
1031-
if let Some(profiler) = PROFILER.lock().unwrap().as_ref() {
1032-
// Safety: execute_data was provided by the engine, and the profiler doesn't mutate it.
1033-
profiler.collect_time(execute_data, interrupt_count, locals.deref());
1034-
}
1035-
});
1036-
}
1037-
1038-
/// A wrapper for the `datadog_profiling_interrupt_function` to call the
1039-
/// previous interrupt handler, if there was one.
1040-
extern "C" fn interrupt_function_wrapper(execute_data: *mut zend::zend_execute_data) {
1041-
interrupt_function(execute_data);
1042-
1043-
// Safety: PREV_INTERRUPT_FUNCTION was written during minit, doesn't change during runtime.
1044-
unsafe {
1045-
if let Some(prev_interrupt) = *PREV_INTERRUPT_FUNCTION.as_mut_ptr() {
1046-
prev_interrupt(execute_data);
1047-
}
1048-
}
1049-
}
1050-
1051-
/// Returns true if the func tied to the execute_data is a trampoline.
1052-
/// # Safety
1053-
/// This is only safe to execute _before_ executing the trampoline, because the trampoline may
1054-
/// free the `execute_data.func` _without_ setting it to NULL:
1055-
/// https://heap.space/xref/PHP-8.2/Zend/zend_closures.c?r=af2110e6#60-63
1056-
/// So no code can inspect the func after the call has been made, which is why you would call this function: find out before you
1057-
/// call the function if indeed you need to skip certain code after it has been executed.
1058-
unsafe fn execute_data_func_is_trampoline(execute_data: *const zend::zend_execute_data) -> bool {
1059-
if execute_data.is_null() {
1060-
return false;
1061-
}
1062-
1063-
if (*execute_data).func.is_null() {
1064-
return false;
1065-
}
1066-
return ((*(*execute_data).func).common.fn_flags & zend::ZEND_ACC_CALL_VIA_TRAMPOLINE) != 0;
1067-
}
1068-
1069-
/// Overrides the engine's zend_execute_internal hook in order to process pending VM interrupts
1070-
/// while the internal function is still on top of the call stack. The VM does not process the
1071-
/// interrupt until the call returns so that it could theoretically jump to a different opcode,
1072-
/// like a fiber scheduler.
1073-
/// For our particular case this is problematic. For example, when the user does something like
1074-
/// `sleep(seconds: 10)`, the normal interrupt handling will not trigger until sleep returns, so
1075-
/// we'd then attribute all that time spent sleeping to whatever runs next. This is why we intercept
1076-
/// `zend_execute_internal` and process our own VM interrupts, but it doesn't delegate to the
1077-
/// previous VM interrupt hook, as it's not expecting to be called from this state.
1078-
extern "C" fn execute_internal(
1079-
execute_data: *mut zend::zend_execute_data,
1080-
return_value: *mut zend::zval,
1081-
) {
1082-
// SAFETY: called before executing the trampoline.
1083-
let leaf_frame = if unsafe { execute_data_func_is_trampoline(execute_data) } {
1084-
// SAFETY: if is_trampoline is set, then there must be a valid execute_data.
1085-
unsafe { *execute_data }.prev_execute_data
1086-
} else {
1087-
execute_data
1088-
};
1089-
1090-
// SAFETY: PREV_EXECUTE_INTERNAL was written during minit, doesn't change during runtime.
1091-
let prev_execute_internal = unsafe { *PREV_EXECUTE_INTERNAL.as_mut_ptr() };
1092-
1093-
// SAFETY: calling prev_execute without modification will be safe.
1094-
unsafe { prev_execute_internal(execute_data, return_value) };
1095-
1096-
// See safety section of `execute_data_func_is_trampoline` docs for why the leaf frame is used
1097-
// instead of the execute_data ptr.
1098-
interrupt_function(leaf_frame);
1099-
}
1100-
1101978
#[cfg(test)]
1102979
mod tests {
1103980
use super::*;

profiling/src/wall_time.rs

Lines changed: 142 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,142 @@
1+
//! This module has code related to generating wall-time profiles. Due to
2+
//! implementation reasons, it has cpu-time code as well.
3+
4+
use crate::bindings::{
5+
zend_execute_data, zend_execute_internal, zend_interrupt_function, zval, VmInterruptFn,
6+
ZEND_ACC_CALL_VIA_TRAMPOLINE,
7+
};
8+
use crate::{zend, PROFILER, REQUEST_LOCALS};
9+
use std::mem::MaybeUninit;
10+
use std::ops::Deref;
11+
use std::sync::atomic::Ordering;
12+
13+
/// The engine's previous [zend::zend_execute_internal] value, or
14+
/// [zend::execute_internal] if none. This is a highly active path, so although
15+
/// it could be made safe with Mutex, the cost is too high.
16+
static mut PREV_EXECUTE_INTERNAL: MaybeUninit<
17+
unsafe extern "C" fn(execute_data: *mut zend_execute_data, return_value: *mut zval),
18+
> = MaybeUninit::uninit();
19+
20+
/// The engine's previous `zend_interrupt_function` value, if there is one.
21+
/// Note that because of things like Apache reload which call minit more than
22+
/// once per process, this cannot be made into a OnceCell nor lazy_static.
23+
static mut PREV_INTERRUPT_FUNCTION: Option<VmInterruptFn> = None;
24+
25+
/// Gathers a time sample if the configured period has elapsed.
26+
///
27+
/// Exposed to the C API so the tracer can handle pending profiler interrupts
28+
/// before calling a tracing closure from an internal function hook; if this
29+
/// isn't done then the closure is erroneously at the top of the stack.
30+
///
31+
/// # Safety
32+
/// The zend_execute_data pointer should come from the engine to ensure it and
33+
/// its sub-objects are valid.
34+
#[no_mangle]
35+
#[inline(never)]
36+
pub extern "C" fn ddog_php_prof_interrupt_function(execute_data: *mut zend_execute_data) {
37+
REQUEST_LOCALS.with(|cell| {
38+
// try to borrow and bail out if not successful
39+
let locals = match cell.try_borrow() {
40+
Ok(locals) => locals,
41+
Err(_) => {
42+
return;
43+
}
44+
};
45+
46+
if !locals.profiling_enabled {
47+
return;
48+
}
49+
50+
/* Other extensions/modules or the engine itself may trigger an
51+
* interrupt, but given how expensive it is to gather a stack trace,
52+
* it should only be done if we triggered it ourselves. So
53+
* interrupt_count serves dual purposes:
54+
* 1. Track how many interrupts there were.
55+
* 2. Ensure we don't collect on someone else's interrupt.
56+
*/
57+
let interrupt_count = locals.interrupt_count.swap(0, Ordering::SeqCst);
58+
if interrupt_count == 0 {
59+
return;
60+
}
61+
62+
if let Some(profiler) = PROFILER.lock().unwrap().as_ref() {
63+
// Safety: execute_data was provided by the engine, and the profiler doesn't mutate it.
64+
profiler.collect_time(execute_data, interrupt_count, locals.deref());
65+
}
66+
});
67+
}
68+
69+
/// A wrapper for the `ddog_php_prof_interrupt_function` to call the
70+
/// previous interrupt handler, if there was one.
71+
#[no_mangle]
72+
extern "C" fn ddog_php_prof_interrupt_function_wrapper(execute_data: *mut zend_execute_data) {
73+
ddog_php_prof_interrupt_function(execute_data);
74+
75+
// SAFETY: PREV_INTERRUPT_FUNCTION was written during minit, doesn't change during runtime.
76+
if let Some(prev_interrupt) = unsafe { PREV_INTERRUPT_FUNCTION.as_ref() } {
77+
// SAFETY: calling the interrupt handler with correct args at right place.
78+
unsafe { prev_interrupt(execute_data) };
79+
}
80+
}
81+
82+
/// Returns true if the func tied to the execute_data is a trampoline.
83+
/// # Safety
84+
/// This is only safe to execute _before_ executing the trampoline, because the trampoline may
85+
/// free the `execute_data.func` _without_ setting it to NULL:
86+
/// https://heap.space/xref/PHP-8.2/Zend/zend_closures.c?r=af2110e6#60-63
87+
/// So no code can inspect the func after the call has been made, which is why you would call this function: find out before you
88+
/// call the function if indeed you need to skip certain code after it has been executed.
89+
unsafe fn execute_data_func_is_trampoline(execute_data: *const zend_execute_data) -> bool {
90+
if execute_data.is_null() {
91+
return false;
92+
}
93+
94+
if (*execute_data).func.is_null() {
95+
return false;
96+
}
97+
return ((*(*execute_data).func).common.fn_flags & ZEND_ACC_CALL_VIA_TRAMPOLINE) != 0;
98+
}
99+
100+
/// Overrides the engine's zend_execute_internal hook in order to process pending VM interrupts
101+
/// while the internal function is still on top of the call stack. The VM does not process the
102+
/// interrupt until the call returns so that it could theoretically jump to a different opcode,
103+
/// like a fiber scheduler.
104+
/// For our particular case this is problematic. For example, when the user does something like
105+
/// `sleep(seconds: 10)`, the normal interrupt handling will not trigger until sleep returns, so
106+
/// we'd then attribute all that time spent sleeping to whatever runs next. This is why we intercept
107+
/// `zend_execute_internal` and process our own VM interrupts, but it doesn't delegate to the
108+
/// previous VM interrupt hook, as it's not expecting to be called from this state.
109+
pub extern "C" fn execute_internal(execute_data: *mut zend_execute_data, return_value: *mut zval) {
110+
// SAFETY: called before executing the trampoline.
111+
let leaf_frame = if unsafe { execute_data_func_is_trampoline(execute_data) } {
112+
// SAFETY: if is_trampoline is set, then there must be a valid execute_data.
113+
unsafe { *execute_data }.prev_execute_data
114+
} else {
115+
execute_data
116+
};
117+
118+
// SAFETY: PREV_EXECUTE_INTERNAL was written during minit, doesn't change during runtime.
119+
let prev_execute_internal = unsafe { *PREV_EXECUTE_INTERNAL.as_mut_ptr() };
120+
121+
// SAFETY: calling prev_execute without modification will be safe.
122+
unsafe { prev_execute_internal(execute_data, return_value) };
123+
124+
// See safety section of `execute_data_func_is_trampoline` docs for why the leaf frame is used
125+
// instead of the execute_data ptr.
126+
ddog_php_prof_interrupt_function(leaf_frame);
127+
}
128+
129+
/// # Safety
130+
/// Only call during PHP's minit phase.
131+
pub unsafe fn minit() {
132+
PREV_INTERRUPT_FUNCTION = zend_interrupt_function;
133+
let function = if zend_interrupt_function.is_some() {
134+
ddog_php_prof_interrupt_function_wrapper
135+
} else {
136+
ddog_php_prof_interrupt_function
137+
};
138+
zend_interrupt_function = Some(function);
139+
140+
PREV_EXECUTE_INTERNAL.write(zend_execute_internal.unwrap_or(zend::execute_internal));
141+
zend_execute_internal = Some(execute_internal);
142+
}

0 commit comments

Comments
 (0)