Skip to content

Commit

Permalink
perf: also shrink LabelValue
Browse files Browse the repository at this point in the history
  • Loading branch information
@morrisonlevi
morrisonlevi committed Dec 19, 2024
1 parent a68d3e7 commit b7b6eae
Show file tree
Hide file tree
Showing 6 changed files with 211 additions and 65 deletions.
72 changes: 38 additions & 34 deletions profiling/src/profiling/mod.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,7 @@ use datadog_profiling::api::UpscalingInfo;
use crate::exception::EXCEPTION_PROFILING_INTERVAL;
#[cfg(feature = "timeline")]
use crate::timeline::IncludeType;
use crate::timeline::State;

const UPLOAD_PERIOD: Duration = Duration::from_secs(67);

Expand Down Expand Up @@ -105,7 +106,7 @@ impl WallTime {

#[derive(Debug, Clone)]
pub enum LabelValue {
Str(Cow<'static, str>),
Str(ThinString),
Num(i64, Option<&'static str>),
}

Expand Down Expand Up @@ -902,15 +903,18 @@ impl Profiler {
}

#[cfg(feature = "timeline")]
const TIMELINE_COMPILE_FILE_LABELS: &'static [Label] = &[Label {
key: "event",
value: LabelValue::Str(Cow::Borrowed("compilation")),
}];
pub fn timeline_compile_file_labels(extra_labels: usize) -> Vec<Label> {
let mut labels = Profiler::common_labels(extra_labels + 1);
labels.push(Label {
key: "event",
value: LabelValue::Str(WellKnown::Compilation.into()),
});
labels
}

#[cfg(feature = "timeline")]
pub fn collect_compile_string(&self, now: i64, duration: i64, filename: ThinString, line: u32) {
let mut labels = Profiler::common_labels(Self::TIMELINE_COMPILE_FILE_LABELS.len());
labels.extend_from_slice(Self::TIMELINE_COMPILE_FILE_LABELS);
let labels = Self::timeline_compile_file_labels(0);
let n_labels = labels.len();

match self.prepare_and_send_message(
Expand Down Expand Up @@ -942,25 +946,20 @@ impl Profiler {
&self,
now: i64,
duration: i64,
filename: String,
filename: ThinString,
include_type: IncludeType,
) {
let mut labels = Profiler::common_labels(Self::TIMELINE_COMPILE_FILE_LABELS.len() + 1);
labels.extend_from_slice(Self::TIMELINE_COMPILE_FILE_LABELS);
let mut labels = Self::timeline_compile_file_labels(1);
labels.push(Label {
key: "filename",
value: LabelValue::Str(Cow::from(filename)),
value: LabelValue::Str(filename),
});

let n_labels = labels.len();

match self.prepare_and_send_message(
vec![ZendFrame {
function: match include_type {
IncludeType::Include => WellKnown::BracketedInclude.into(),
IncludeType::Require => WellKnown::BracketedRequire.into(),
IncludeType::Unknown => WellKnown::BracketedUnknownIncludeType.into(),
},
function: include_type.to_bracketed_thin_string(),
file: None,
line: 0,
}],
Expand All @@ -984,19 +983,18 @@ impl Profiler {

/// This function will collect a thread start or stop timeline event
#[cfg(all(feature = "timeline", php_zts))]
pub fn collect_thread_start_end(&self, now: i64, event: &'static str) {
let mut labels = Profiler::common_labels(1);

pub fn collect_thread_start_end(&self, now: i64, state: State) {
let mut labels = Self::timeline_compile_file_labels(1);
labels.push(Label {
key: "event",
value: LabelValue::Str(Cow::Borrowed(event)),
value: LabelValue::Str(state.to_thin_string()),
});

let n_labels = labels.len();

match self.prepare_and_send_message(
vec![ZendFrame {
function: format!("[{event}]").into(),
function: state.to_bracketed_thin_string(),
file: None,
line: 0,
}],
Expand All @@ -1018,16 +1016,16 @@ impl Profiler {

/// This function can be called to collect any fatal errors
#[cfg(feature = "timeline")]
pub fn collect_fatal(&self, now: i64, file: ThinString, line: u32, message: String) {
pub fn collect_fatal(&self, now: i64, file: ThinString, line: u32, message: ThinString) {
let mut labels = Profiler::common_labels(2);

labels.push(Label {
key: "event",
value: LabelValue::Str("fatal".into()),
value: LabelValue::Str(WellKnown::Fatal.into()),
});
labels.push(Label {
key: "message",
value: LabelValue::Str(message.into()),
value: LabelValue::Str(message),
});

let n_labels = labels.len();
Expand Down Expand Up @@ -1069,7 +1067,7 @@ impl Profiler {

labels.push(Label {
key: "event",
value: LabelValue::Str("opcache_restart".into()),
value: LabelValue::Str(WellKnown::OpcacheRestart.into()),
});
labels.push(Label {
key: "reason",
Expand Down Expand Up @@ -1102,12 +1100,12 @@ impl Profiler {

/// This function can be called to collect any kind of inactivity that is happening
#[cfg(feature = "timeline")]
pub fn collect_idle(&self, now: i64, duration: i64, reason: &'static str) {
pub fn collect_idle(&self, now: i64, duration: i64, state: State) {
let mut labels = Profiler::common_labels(1);

labels.push(Label {
key: "event",
value: LabelValue::Str(reason.into()),
value: LabelValue::Str(state.to_thin_string()),
});

let n_labels = labels.len();
Expand Down Expand Up @@ -1141,20 +1139,20 @@ impl Profiler {
&self,
now: i64,
duration: i64,
reason: &'static str,
reason: WellKnown,
collected: i64,
#[cfg(php_gc_status)] runs: i64,
) {
let mut labels = Profiler::common_labels(4);

labels.push(Label {
key: "event",
value: LabelValue::Str(Cow::Borrowed("gc")),
value: LabelValue::Str(WellKnown::BracketedGc.into()),
});

labels.push(Label {
key: "gc reason",
value: LabelValue::Str(Cow::from(reason)),
value: LabelValue::Str(reason.into()),
});

#[cfg(php_gc_status)]
Expand Down Expand Up @@ -1182,10 +1180,16 @@ impl Profiler {
now,
) {
Ok(_) => {
trace!("Sent event 'gc' with {n_labels} labels and reason {reason} to profiler.")
trace!(
"Sent event 'gc' with {n_labels} labels and reason {} to profiler.",
ThinString::from(reason).as_ref(),
)
}
Err(err) => {
warn!("Failed to send event 'gc' with {n_labels} and reason {reason} labels to profiler: {err}")
warn!(
"Failed to send event 'gc' with {n_labels} and reason {} labels to profiler: {err}",
ThinString::from(reason).as_ref(),
)
}
}
}
Expand All @@ -1198,7 +1202,7 @@ impl Profiler {
let mut labels = Vec::with_capacity(5 + n_extra_labels);
labels.push(Label {
key: "thread id",
value: LabelValue::Num(unsafe { libc::pthread_self() as i64 }, "id".into()),
value: LabelValue::Num(unsafe { libc::pthread_self() as i64 }, Some("id")),
});

labels.push(Label {
Expand Down Expand Up @@ -1238,7 +1242,7 @@ impl Profiler {
if let Some(functionname) = extract_function_name(func) {
labels.push(Label {
key: "fiber",
value: LabelValue::Str(Cow::from(functionname)),
value: LabelValue::Str(functionname),
});
}
}
Expand Down
94 changes: 64 additions & 30 deletions profiling/src/timeline.rs
View file
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
use crate::profiling::Profiler;
use crate::well_known::WellKnown;
use crate::zend::{
self, zai_str_from_zstr, zend_execute_data, zend_get_executed_filename_ex, zval,
InternalFunctionHandler,
Expand All @@ -12,6 +13,7 @@ use log::{error, trace};
#[cfg(php_zts)]
use std::cell::Cell;
use std::cell::RefCell;
use std::ops::Deref;
use std::time::{Instant, SystemTime, UNIX_EPOCH};
use std::{fmt, ptr};

Expand All @@ -22,6 +24,24 @@ pub enum IncludeType {
Unknown,
}

impl IncludeType {
pub fn to_thin_string(self) -> ThinString {
match self {
IncludeType::Include => WellKnown::Include.into(),
IncludeType::Require => WellKnown::Require.into(),
IncludeType::Unknown => WellKnown::Unknown.into(),
}
}

pub fn to_bracketed_thin_string(self) -> ThinString {
match self {
IncludeType::Include => WellKnown::BracketedInclude.into(),
IncludeType::Require => WellKnown::BracketedRequire.into(),
IncludeType::Unknown => WellKnown::BracketedUnknownIncludeType.into(),
}
}
}

impl From<u32> for IncludeType {
fn from(value: u32) -> Self {
match value {
Expand All @@ -32,19 +52,9 @@ impl From<u32> for IncludeType {
}
}

impl AsRef<str> for IncludeType {
fn as_ref(&self) -> &str {
match self {
IncludeType::Include => "include",
IncludeType::Require => "require",
IncludeType::Unknown => "unknown",
}
}
}

impl fmt::Display for IncludeType {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
write!(f, "{}", self.as_ref())
write!(f, "{}", self.to_thin_string().deref())
}
}

Expand All @@ -69,7 +79,8 @@ thread_local! {
static IS_NEW_THREAD: Cell<bool> = const { Cell::new(false) };
}

enum State {
#[derive(Copy, Clone)]
pub enum State {
Idle,
Sleeping,
Select,
Expand All @@ -80,15 +91,29 @@ enum State {
}

impl State {
fn as_str(&self) -> &'static str {
pub fn to_thin_string(self) -> ThinString {
match self {
State::Idle => "idle",
State::Sleeping => "sleeping",
State::Select => "select",
State::Idle => WellKnown::Idle.into(),
State::Sleeping => WellKnown::Sleeping.into(),
State::Select => WellKnown::Select.into(),

#[cfg(php_zts)]
State::ThreadStart => "thread start",
State::ThreadStart => WellKnown::ThreadStart.into(),
#[cfg(php_zts)]
State::ThreadStop => "thread stop",
State::ThreadStop => WellKnown::ThreadStop.into(),
}
}

pub fn to_bracketed_thin_string(self) -> ThinString {
match self {
State::Idle => WellKnown::BracketedIdle.into(),
State::Sleeping => WellKnown::BracketedSleeping.into(),
State::Select => WellKnown::BracketedSelect.into(),

#[cfg(php_zts)]
State::ThreadStart => WellKnown::BracketedThreadStart.into(),
#[cfg(php_zts)]
State::ThreadStop => WellKnown::BracketedThreadStop.into(),
}
}
}
Expand Down Expand Up @@ -132,7 +157,7 @@ fn sleeping_fn(
// Safety: `unwrap` can be unchecked, as we checked for `is_err()`
let now = unsafe { now.unwrap_unchecked().as_nanos() } as i64;
let duration = duration.as_nanos() as i64;
profiler.collect_idle(now, duration, state.as_str());
profiler.collect_idle(now, duration, state);
}
}

Expand Down Expand Up @@ -247,7 +272,11 @@ unsafe extern "C" fn ddog_php_prof_zend_error_observer(
if let Some(profiler) = Profiler::get() {
let now = now.as_nanos() as i64;
profiler.collect_fatal(now, filename, line, unsafe {
zai_str_from_zstr(message.as_mut()).into_string()
ThinString::from(
zai_str_from_zstr(message.as_mut())
.into_string_lossy()
.as_ref(),
)
});
}
}
Expand Down Expand Up @@ -448,7 +477,7 @@ pub unsafe fn timeline_rinit() {
.unwrap()
.as_nanos() as i64,
idle_since.elapsed().as_nanos() as i64,
State::Idle.as_str(),
State::Idle,
);
}
});
Expand Down Expand Up @@ -536,7 +565,7 @@ pub(crate) unsafe fn timeline_mshutdown() {
.unwrap()
.as_nanos() as i64,
idle_since.elapsed().as_nanos() as i64,
"idle",
State::Idle,
);
}
});
Expand Down Expand Up @@ -679,18 +708,22 @@ unsafe extern "C" fn ddog_php_prof_compile_file(
}

let include_type = IncludeType::from(r#type as u32);
let include_str = include_type.as_ref();

// Extract the filename from the returned op_array.
// We could also extract from the handle, but those filenames might be different from
// the one in the `op_array`: In the handle we get what `include()` was called with,
// for example "/var/www/html/../vendor/foo/bar.php" while during stack walking we get
// "/var/html/vendor/foo/bar.php". This makes sure it is the exact same string we'd
// collect in stack walking and therefore we are fully utilizing the pprof string table
let filename = zai_str_from_zstr((*op_array).filename.as_mut()).into_string();
// collect in stack walking, and therefore we are fully utilizing the pprof string table.
let filename = ThinString::from(
zai_str_from_zstr((*op_array).filename.as_mut())
.to_string_lossy()
.as_ref(),
);

trace!(
"Compile file \"{filename}\" with include type \"{include_str}\" took {} nanoseconds",
"Compile file \"{filename}\" with include type \"{}\" took {} nanoseconds",
include_type.to_thin_string().deref(),
duration.as_nanos(),
);

Expand All @@ -713,12 +746,12 @@ unsafe extern "C" fn ddog_php_prof_compile_file(
/// a `gc_collect_cycles` function at the top of the call stack, it is because
/// of a userland call to `gc_collect_cycles()`, otherwise the engine decided
/// to run it.
unsafe fn gc_reason() -> &'static str {
unsafe fn gc_reason() -> WellKnown {
let execute_data = zend::ddog_php_prof_get_current_execute_data();
let fname = || execute_data.as_ref()?.func.as_ref()?.name();
match fname() {
Some(name) if name == b"gc_collect_cycles" => "induced",
_ => "engine",
Some(name) if name == b"gc_collect_cycles" => WellKnown::Induced,
_ => WellKnown::Engine,
}
}

Expand Down Expand Up @@ -760,7 +793,8 @@ unsafe extern "C" fn ddog_php_prof_gc_collect_cycles() -> i32 {
let status = status.assume_init();

trace!(
"Garbage collection with reason \"{reason}\" took {} nanoseconds",
"Garbage collection with reason \"{}\" took {} nanoseconds",
ThinString::from(reason).deref(),
duration.as_nanos()
);

Expand Down
Loading

0 comments on commit b7b6eae

Please sign in to comment.