Skip to content

Commit 8cb3cde

Browse files
committed
perf(profiling): use relaxed read to skip idle interrupts
This is very similar to the approach taken by Florian, which did a check for EG(vm_interrupt). Although I was able to reproduce a small speedup there, I realized that it's more nuanced than that: 1. This doesn't apply to actual VM interrupts, only to things which need to check for a pending interrupt. 2. EG(vm_interrupt) technically isn't related to the thing we care about, which is the interrupt count. So this adds ddog_php_prof_interrupt_function_unlikely which is the same as ddog_php_prof_interrupt_function at a high level, but it is optimized to assume that there isn't a pending interrupt (opposite of ddog_php_prof_interrupt_function).
1 parent 6fcfa2b commit 8cb3cde

5 files changed

Lines changed: 78 additions & 38 deletions

File tree

profiling/src/capi.rs

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -57,7 +57,9 @@ extern "C" fn ddog_php_prof_trigger_time_sample() {
5757
}
5858
}
5959

60-
pub use crate::wall_time::ddog_php_prof_interrupt_function;
60+
pub use crate::wall_time::{
61+
ddog_php_prof_interrupt_function, ddog_php_prof_interrupt_function_unlikely,
62+
};
6163

6264
#[cfg(test)]
6365
mod tests {

profiling/src/wall_time.rs

Lines changed: 62 additions & 33 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
//! implementation reasons, it has cpu-time code as well.
33
44
use crate::bindings::{zend_execute_data, zend_interrupt_function, VmInterruptFn};
5-
use crate::{profiling::Profiler, RefCellExt, REQUEST_LOCALS};
5+
use crate::{profiling::Profiler, RefCellExt, RequestLocals, REQUEST_LOCALS};
66
use core::ptr;
77
use log::debug;
88
use std::sync::atomic::Ordering;
@@ -79,8 +79,8 @@ mod execute_internal {
7979
unsafe { prev_execute_internal(execute_data, return_value) };
8080

8181
// See safety section of `execute_data_func_is_trampoline` docs for why
82-
// the leaf frame is used instead of the execute_data ptr.
83-
ddog_php_prof_interrupt_function(leaf_frame);
82+
// the leaf frame is used instead of the execute_data ptr.
83+
ddog_php_prof_interrupt_function_unlikely(leaf_frame);
8484
}
8585

8686
/// # Safety
@@ -109,31 +109,65 @@ static mut PREV_INTERRUPT_FUNCTION: Option<VmInterruptFn> = None;
109109
#[no_mangle]
110110
#[inline(never)]
111111
pub extern "C" fn ddog_php_prof_interrupt_function(execute_data: *mut zend_execute_data) {
112-
let result = REQUEST_LOCALS.try_with_borrow(|locals| {
113-
if !locals.system_settings().profiling_enabled {
114-
return;
115-
}
112+
if let Err(err) =
113+
REQUEST_LOCALS.try_with_borrow(|locals| interrupt_function(locals, execute_data))
114+
{
115+
debug!("ddog_php_prof_interrupt_function failed to borrow request locals: {err}");
116+
}
117+
}
118+
119+
fn interrupt_function(locals: &RequestLocals, execute_data: *mut zend_execute_data) {
120+
let profiling_disabled = !locals.system_settings().profiling_enabled;
121+
122+
/* Other extensions/modules or the engine itself may trigger an
123+
* interrupt, but given how expensive it is to gather a stack trace,
124+
* it should only be done if we triggered it ourselves. So
125+
* interrupt_count serves dual purposes:
126+
* 1. Track how many interrupts there were.
127+
* 2. Ensure we don't collect on someone else's interrupt.
128+
*/
129+
let interrupt_count = locals.interrupt_count.swap(0, Ordering::SeqCst);
130+
if profiling_disabled | (interrupt_count == 0) {
131+
return;
132+
}
133+
134+
if let Some(profiler) = Profiler::get() {
135+
// Safety: execute_data was provided by the engine, and the profiler doesn't mutate it.
136+
profiler.collect_time(execute_data, interrupt_count);
137+
}
138+
}
116139

117-
/* Other extensions/modules or the engine itself may trigger an
118-
* interrupt, but given how expensive it is to gather a stack trace,
119-
* it should only be done if we triggered it ourselves. So
120-
* interrupt_count serves dual purposes:
121-
* 1. Track how many interrupts there were.
122-
* 2. Ensure we don't collect on someone else's interrupt.
123-
*/
124-
let interrupt_count = locals.interrupt_count.swap(0, Ordering::SeqCst);
125-
if interrupt_count == 0 {
140+
/// This function is like [`ddog_php_prof_interrupt_function`] except it's
141+
/// optimized for the expectation that it's unlikely that there's actually an
142+
/// interrupt actively needing to be handled. This is because we have to insert
143+
/// this check in a variety of places, and in many of them (execute_internal,
144+
/// frameless functions) there won't be an interrupt at all.
145+
///
146+
/// # Safety
147+
/// The zend_execute_data pointer should come from the engine to ensure it and
148+
/// its sub-objects are valid.
149+
#[no_mangle]
150+
#[inline(never)]
151+
pub extern "C" fn ddog_php_prof_interrupt_function_unlikely(execute_data: *mut zend_execute_data) {
152+
let result = REQUEST_LOCALS.try_with_borrow(|locals| {
153+
// Optimize here with the expectation there isn't an interrupt, because
154+
// overwhelmingly, there will not be one. The relaxed load avoids the
155+
// more expensive atomic read-modify-write in `interrupt_function` on
156+
// the idle path. It is only a fast-path hint: `interrupt_function` does
157+
// the authoritative swap. If another consumer clears the count between
158+
// the load and swap, the swap simply observes zero; if a producer adds
159+
// an interrupt after this load observes zero, the count remains pending
160+
// and the corresponding VM interrupt will provide another opportunity
161+
// to handle it.
162+
if locals.interrupt_count.load(Ordering::Relaxed) == 0 {
126163
return;
127164
}
128165

129-
if let Some(profiler) = Profiler::get() {
130-
// Safety: execute_data was provided by the engine, and the profiler doesn't mutate it.
131-
profiler.collect_time(execute_data, interrupt_count);
132-
}
166+
interrupt_function(locals, execute_data);
133167
});
134168

135169
if let Err(err) = result {
136-
debug!("ddog_php_prof_interrupt_function failed to borrow request locals: {err}");
170+
debug!("ddog_php_prof_interrupt_function_unlikely failed to borrow request locals: {err}");
137171
}
138172
}
139173

@@ -144,7 +178,8 @@ mod frameless {
144178
use crate::bindings::{
145179
zend_flf_functions, zend_flf_handlers, zend_frameless_function_info,
146180
};
147-
use crate::{profiling::Profiler, zend, RefCellExt, REQUEST_LOCALS};
181+
use crate::wall_time::ddog_php_prof_interrupt_function;
182+
use crate::{zend, RefCellExt, REQUEST_LOCALS};
148183
use dynasmrt::{dynasm, DynasmApi, ExecutableBuffer};
149184
use log::error;
150185
use std::ffi::c_void;
@@ -271,23 +306,17 @@ mod frameless {
271306
#[inline(never)]
272307
pub extern "C" fn ddog_php_prof_icall_trampoline_target() {
273308
let interrupt_count = REQUEST_LOCALS
274-
.try_with_borrow(|locals| {
275-
if !locals.system_settings().profiling_enabled {
276-
return 0;
277-
}
278-
locals.interrupt_count.swap(0, Ordering::SeqCst)
279-
})
309+
.try_with_borrow(|locals| locals.interrupt_count.load(Ordering::Relaxed))
280310
.unwrap_or(0);
281311

282312
if interrupt_count == 0 {
283313
return;
284314
}
285315

286-
if let Some(profiler) = Profiler::get() {
287-
// SAFETY: profiler doesn't mutate execute_data
288-
let execute_data = unsafe { zend::ddog_php_prof_get_current_execute_data() };
289-
profiler.collect_time(execute_data, interrupt_count);
290-
}
316+
// Fetching the execute data is intentionally delayed until we know
317+
// that the interrupt count is greater than 0 for perf.
318+
let execute_data = unsafe { zend::ddog_php_prof_get_current_execute_data() };
319+
ddog_php_prof_interrupt_function(execute_data);
291320
}
292321
}
293322

tests/tea/profiling/profiling.cc

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@ ZEND_TLS datadog_php_stack_sample last_stack_sample;
99

1010
ZEND_API datadog_php_stack_sample tea_get_last_stack_sample(void) { return last_stack_sample; }
1111

12-
ZEND_API void ddog_php_prof_interrupt_function(zend_execute_data *execute_data) {
12+
ZEND_API void ddog_php_prof_interrupt_function_unlikely(zend_execute_data *execute_data) {
1313
datadog_php_stack_sample_ctor(&last_stack_sample);
1414

1515
/* Don't try to re-implement everything. Remember, the tracer is being
@@ -34,6 +34,10 @@ ZEND_API void ddog_php_prof_interrupt_function(zend_execute_data *execute_data)
3434
}
3535
}
3636

37+
ZEND_API void ddog_php_prof_interrupt_function(zend_execute_data *execute_data) {
38+
ddog_php_prof_interrupt_function_unlikely(execute_data);
39+
}
40+
3741
ZEND_API zend_extension_version_info extension_version_info = {
3842
ZEND_EXTENSION_API_NO,
3943
ZEND_EXTENSION_BUILD_ID,

tests/tea/profiling/profiling.h

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ BEGIN_EXTERN_C()
1010

1111
ZEND_API datadog_php_stack_sample tea_get_last_stack_sample(void);
1212
ZEND_API void ddog_php_prof_interrupt_function(zend_execute_data *execute_data);
13+
ZEND_API void ddog_php_prof_interrupt_function_unlikely(zend_execute_data *execute_data);
1314
END_EXTERN_C()
1415

1516
#endif

tracer/engine_hooks.c

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -41,10 +41,14 @@ void dd_search_for_profiling_symbols(void *arg) {
4141
if (extension->name && strcmp(extension->name, "datadog-profiling") == 0) {
4242
DL_HANDLE handle = extension->handle;
4343

44-
profiling_interrupt_function = (void(*)(zend_execute_data *))DL_FETCH_SYMBOL(handle, "ddog_php_prof_interrupt_function");
44+
profiling_interrupt_function = (void(*)(zend_execute_data *))DL_FETCH_SYMBOL(handle, "ddog_php_prof_interrupt_function_unlikely");
45+
if (!profiling_interrupt_function) {
46+
// Fall back for compatibility with profiler versions from before the
47+
// unlikely-pending fast path was exported.
48+
profiling_interrupt_function = (void(*)(zend_execute_data *))DL_FETCH_SYMBOL(handle, "ddog_php_prof_interrupt_function");
49+
}
4550
if (UNEXPECTED(!profiling_interrupt_function)) {
46-
LOG(WARN, "[Datadog Trace] Profiling was detected, but locating symbol %s failed: %s\n", "ddog_php_prof_interrupt_function",
47-
GET_DL_ERROR());
51+
LOG(WARN, "[Datadog Trace] Profiling was detected, but locating an interrupt function failed: %s\n", GET_DL_ERROR());
4852
}
4953

5054
profiling_notify_trace_finished = (profiling_notify_trace_finished_t)DL_FETCH_SYMBOL(handle, "datadog_profiling_notify_trace_finished");

0 commit comments

Comments
 (0)