Merge branch 'master' of github.com:DataDog/dd-trace-php into bob/log

Author: bwoebi

.circleci/continue_config.yml

@@ -1904,6 +1904,7 @@ jobs:
           DD_TRACE_AGENT_PORT: 80
           DD_TRACE_AGENT_FLUSH_INTERVAL: 1000
           INSTALL_TYPE: << parameters.install_type >>
+          RUST_BACKTRACE: 1
       - <<: *IMAGE_DOCKER_REQUEST_REPLAYER
     steps:
       - restore_cache:
@@ -1975,6 +1976,7 @@ jobs:
           VERIFY_APACHE: << parameters.verify_apache >>
           INSTALL_MODE: << parameters.install_mode >>
           INSTALL_TYPE: << parameters.install_type >>
+          RUST_BACKTRACE: 1
       - <<: *IMAGE_DOCKER_REQUEST_REPLAYER
     steps:
       - restore_cache:
@@ -2057,6 +2059,8 @@ jobs:
       - run:
           name: Run tests
           command: make -C dockerfiles/verify_packages test_installer
+          environment:
+              RUST_BACKTRACE: 1
 
   randomized_tests:
     working_directory: ~/datadog

.github/workflows/prof_asan.yml

@@ -60,5 +60,5 @@ jobs:
           switch-php nts-asan
           cd profiling/tests
           cp -v $(php-config --prefix)/lib/php/build/run-tests.php .
-          php run-tests.php --asan -d extension=datadog-profiling.so phpt
+          php run-tests.php --show-diff --asan -d extension=datadog-profiling.so phpt
 

appsec/src/extension/logging.c

@@ -377,9 +377,12 @@ static void _mlog_file(dd_log_level_t level, const char *format, va_list args,
             _dd_log_level_to_str(level), message_data, file, line, function);
 
     efree(message_data);
-    TSRM_MUTEX_LOCK(_mutex);
-    ssize_t written = write(_mlog_fd, data, data_len);
-    TSRM_MUTEX_UNLOCK(_mutex);
+    ssize_t written;
+    do {
+        TSRM_MUTEX_LOCK(_mutex);
+        written = write(_mlog_fd, data, data_len);
+        TSRM_MUTEX_UNLOCK(_mutex);
+    } while (written == -1 && errno == EINTR);
     efree(data);
 
     if (written == -1) {
@@ -451,13 +454,23 @@ void dd_log_shutdown()
 {
     mlog(dd_log_debug, "Shutting down the file logging");
 
-#ifdef ZTS
-    tsrm_mutex_free(_mutex);
-    _mutex = NULL;
-#endif
-    if (_log_strategy == log_use_file && _mlog_fd != -1 &&
-        _mlog_fd > fileno(stderr)) {
-        int ret = close(_mlog_fd);
+    if (_log_strategy == log_use_file &&
+        atomic_load_explicit(&_initialized, memory_order_acquire) &&
+        _mlog_fd != -1 && _mlog_fd > fileno(stderr)) {
+        // no need for the mutex at this point
+        // all the zts workers should have been done
+        // we're guaranteed visibility of the write to _mlog_fd by _initialized
+        int ret;
+        ret = fsync(_mlog_fd);
+        if (ret == -1) {
+            _mlog_php_varargs(dd_log_warning,
+                "Error fsyncing the log file (errno %d: %s)", errno,
+                _strerror(errno));
+        }
+        do {
+            ret = close(_mlog_fd);
+        } while (ret == -1 && errno == EINTR);
+
         if (ret == -1) {
             _mlog_php_varargs(dd_log_warning,
                 "Error closing the log file (errno %d: %s)", errno,
@@ -467,6 +480,11 @@ void dd_log_shutdown()
         closelog();
     }
 
+#ifdef ZTS
+    tsrm_mutex_free(_mutex);
+    _mutex = NULL;
+#endif
+
     _mlog_fd = -1;
     _log_strategy = log_use_nothing;
     atomic_store(&_initialized, false);

appsec/src/extension/request_abort.c

@@ -409,8 +409,8 @@ static bool _abort_prelude()
         mlog_g(dd_log_warning, "Failed clearing current headers");
     }
 
-    mlog_g(dd_log_debug, "Discarding output buffers");
     php_output_discard_all();
+    mlog_g(dd_log_debug, "Output buffers have been discarded");
     return true;
 }
 

profiling/src/allocation.rs

@@ -109,10 +109,25 @@ lazy_static! {
     static ref JIT_ENABLED: bool = unsafe { zend::ddog_php_jit_enabled() };
 }
 
+pub fn first_rinit_should_disable_due_to_jit() -> bool {
+    if NEEDS_RUN_TIME_CHECK_FOR_ENABLED_JIT
+        && allocation_profiling_needs_disabled_for_jit(unsafe { crate::PHP_VERSION_ID })
+        && *JIT_ENABLED
+    {
+        error!("Memory allocation profiling will be disabled as long as JIT is active. To enable allocation profiling disable JIT or upgrade PHP to at least version 8.1.21 or 8.2.8. See https://github.com/DataDog/dd-trace-php/pull/2088");
+        true
+    } else {
+        false
+    }
+}
+
 pub fn allocation_profiling_rinit() {
     let allocation_profiling: bool = REQUEST_LOCALS.with(|cell| {
         match cell.try_borrow() {
-            Ok(locals) => locals.profiling_allocation_enabled,
+            Ok(locals) => {
+                let system_settings = locals.system_settings();
+                system_settings.profiling_allocation_enabled
+            },
             Err(_err) => {
                 error!("Memory allocation was not initialized correctly due to a borrow error. Please report this to Datadog.");
                 false
@@ -124,18 +139,6 @@ pub fn allocation_profiling_rinit() {
         return;
     }
 
-    if NEEDS_RUN_TIME_CHECK_FOR_ENABLED_JIT
-        && allocation_profiling_needs_disabled_for_jit(unsafe { crate::PHP_VERSION_ID })
-        && *JIT_ENABLED
-    {
-        error!("Memory allocation profiling will be disabled as long as JIT is active. To enable allocation profiling disable JIT or upgrade PHP to at least version 8.1.21 or 8.2.8. See https://github.com/DataDog/dd-trace-php/pull/2088");
-        REQUEST_LOCALS.with(|cell| {
-            let mut locals = cell.borrow_mut();
-            locals.profiling_allocation_enabled = false;
-        });
-        return;
-    }
-
     unsafe {
         HEAP = Some(zend::zend_mm_get_heap());
     }
@@ -180,11 +183,9 @@ pub fn allocation_profiling_rinit() {
 
     // `is_zend_mm()` should be `false` now, as we installed our custom handlers
     if is_zend_mm() {
-        error!("Memory allocation profiling could not be enabled. Please feel free to fill an issue stating the PHP version and installed modules. Most likely the reason is your PHP binary was compiled with `ZEND_MM_CUSTOM` being disabled.");
-        REQUEST_LOCALS.with(|cell| {
-            let mut locals = cell.borrow_mut();
-            locals.profiling_allocation_enabled = false;
-        });
+        // Can't proceed with it being disabled, because that's a system-wide
+        // setting, not per-request.
+        panic!("Memory allocation profiling could not be enabled. Please feel free to fill an issue stating the PHP version and installed modules. Most likely the reason is your PHP binary was compiled with `ZEND_MM_CUSTOM` being disabled.");
     } else {
         trace!("Memory allocation profiling enabled.")
     }
@@ -193,7 +194,7 @@ pub fn allocation_profiling_rinit() {
 pub fn allocation_profiling_rshutdown() {
     let allocation_profiling = REQUEST_LOCALS.with(|cell| {
         cell.try_borrow()
-            .map(|locals| locals.profiling_allocation_enabled)
+            .map(|locals| locals.system_settings().profiling_allocation_enabled)
             .unwrap_or(false)
     });
 
@@ -310,7 +311,7 @@ unsafe extern "C" fn alloc_profiling_gc_mem_caches(
 ) {
     let allocation_profiling: bool = REQUEST_LOCALS.with(|cell| {
         cell.try_borrow()
-            .map(|locals| locals.profiling_allocation_enabled)
+            .map(|locals| locals.system_settings().profiling_allocation_enabled)
             // Not logging here to avoid potentially overwhelming logs.
             .unwrap_or(false)
     });

profiling/src/bindings/mod.rs

@@ -302,6 +302,11 @@ extern "C" {
     /// (single byte of null, len of 0).
     pub fn zai_str_from_zstr(zstr: Option<&mut zend_string>) -> zai_str;
 
+    /// Returns the configuration item for the given config id. Note that the
+    /// lifetime is roughly static, but technically it is from first rinit
+    /// until mshutdown.
+    pub(crate) fn ddog_php_prof_get_memoized_config(config_id: ConfigId) -> *mut zval;
+
     /// Registers the run_time_cache slot with the engine. Must be done in
     /// module init or extension startup.
     pub fn ddog_php_prof_function_run_time_cache_init(module_name: *const c_char);
@@ -332,6 +337,7 @@ extern "C" {
     pub fn ddog_php_prof_is_post_startup() -> bool;
 }
 
+use crate::config::ConfigId;
 pub use zend_module_dep as ModuleDep;
 
 impl ModuleDep {
@@ -468,15 +474,25 @@ impl TryFrom<&mut zval> for String {
     type Error = StringError;
 
     fn try_from(zval: &mut zval) -> Result<Self, Self::Error> {
+        Cow::try_from(zval).map(Cow::into_owned)
+    }
+}
+
+impl<'a> TryFrom<&'a mut zval> for Cow<'a, str> {
+    type Error = StringError;
+
+    fn try_from(zval: &'a mut zval) -> Result<Self, Self::Error> {
         let r#type = unsafe { zval.u1.v.type_ };
         if r#type == IS_STRING {
             // This shouldn't happen, very bad, something screwed up.
             if unsafe { zval.value.str_.is_null() } {
                 return Err(StringError::Null);
             }
+            // SAFETY: checked the pointer wasn't null above.
+            let reference: Option<&'a mut zend_string> = unsafe { zval.value.str_.as_mut() };
 
-            // Safety: checked the pointer wasn't null above.
-            let str = unsafe { zai_str_from_zstr(zval.value.str_.as_mut()) }.into_string();
+            // SAFETY: calling extern "C" with correct params.
+            let str = unsafe { zai_str_from_zstr(reference) }.into_string_lossy();
             Ok(str)
         } else {
             Err(StringError::Type(r#type))
@@ -573,6 +589,12 @@ impl<'a> ZaiStr<'a> {
     pub fn to_string_lossy(&self) -> Cow<str> {
         String::from_utf8_lossy(self.as_bytes())
     }
+
+    #[inline]
+    pub fn into_string_lossy(self) -> Cow<'a, str> {
+        let bytes = self.as_bytes();
+        String::from_utf8_lossy(bytes)
+    }
 }
 
 #[repr(C)]

profiling/src/capi.rs

@@ -41,7 +41,7 @@ extern "C" fn ddog_php_prof_trigger_time_sample() {
     use std::sync::atomic::Ordering;
     super::REQUEST_LOCALS.with(|cell| {
         if let Ok(locals) = cell.try_borrow() {
-            if locals.profiling_enabled {
+            if locals.system_settings().profiling_enabled {
                 // Safety: only vm interrupts are stored there, or possibly null (edges only).
                 if let Some(vm_interrupt) = unsafe { locals.vm_interrupt_addr.as_ref() } {
                     locals.interrupt_count.fetch_add(1, Ordering::SeqCst);