appsec: fix duration_ext metric

It had three problems:
* Value in ns instead of microseconds
* It would effectively be the time of the first rasp call only
* Did not fetch the span properly where to store the tags

Author: cataphract

appsec/src/extension/ddappsec.c

@@ -35,6 +35,7 @@
 #include "network.h"
 #include "php_compat.h"
 #include "php_objects.h"
+#include "rasp.h"
 #include "request_abort.h"
 #include "request_lifecycle.h"
 #include "tags.h"
@@ -219,6 +220,7 @@ static PHP_MINIT_FUNCTION(ddappsec)
     dd_user_tracking_startup();
     dd_request_abort_startup();
     dd_tags_startup();
+    dd_rasp_startup();
     dd_ip_extraction_startup();
     dd_entity_body_startup();
     dd_backtrace_startup();
@@ -237,6 +239,7 @@ static PHP_MSHUTDOWN_FUNCTION(ddappsec)
     // no other thread is running now. reset config to global config only.
     runtime_config_first_init = false;
 
+    dd_rasp_shutdown();
     dd_tags_shutdown();
     dd_request_abort_shutdown();
     dd_user_tracking_shutdown();
@@ -485,9 +488,7 @@ static PHP_FUNCTION(datadog_appsec_testing_request_exec)
 static PHP_FUNCTION(datadog_appsec_push_addresses)
 {
     struct timespec start;
-    struct timespec end;
     clock_gettime(CLOCK_MONOTONIC_RAW, &start);
-    long elapsed = 0;
     UNUSED(return_value);
     if (!DDAPPSEC_G(active)) {
         mlog(dd_log_debug, "Trying to access to push_addresses "
@@ -520,16 +521,15 @@ static PHP_FUNCTION(datadog_appsec_push_addresses)
     dd_result res = dd_request_exec(conn, addresses, rasp_rule);
 
     if (rasp_rule && ZSTR_LEN(rasp_rule) > 0) {
+        struct timespec end;
         clock_gettime(CLOCK_MONOTONIC_RAW, &end);
-        elapsed =
-            ((int64_t)end.tv_sec - (int64_t)start.tv_sec) *
+        double elapsed_us =
+            ((double)(end.tv_sec - start.tv_sec) *
+                    // NOLINTNEXTLINE(cppcoreguidelines-avoid-magic-numbers,readability-magic-numbers)
+                    (int64_t)1000000 +
                 // NOLINTNEXTLINE(cppcoreguidelines-avoid-magic-numbers,readability-magic-numbers)
-                (int64_t)1000000000 +
-            ((int64_t)end.tv_nsec - (int64_t)start.tv_nsec);
-        zend_object *span = dd_trace_get_active_root_span();
-        if (span) {
-            dd_tags_add_rasp_duration_ext(span, elapsed);
-        }
+                (double)(end.tv_nsec - start.tv_nsec) / 1000.0);
+        dd_rasp_account_duration_us(elapsed_us);
     }
 
     if (dd_req_is_user_req()) {

appsec/src/extension/rasp.c

@@ -0,0 +1,65 @@
+
+#include "rasp.h"
+
+#include "ddappsec.h"
+#include "ddtrace.h"
+#include "logging.h"
+#include "php_helpers.h"
+#include "request_lifecycle.h"
+#include "string_helpers.h"
+
+#define DD_EVENTS_RASP_DURATION_EXT "_dd.appsec.rasp.duration_ext"
+
+static zend_string *_dd_rasp_duration_ext;
+static THREAD_LOCAL_ON_ZTS double _duration_ext_us;
+
+static void _add_rasp_duration_ext_to_metrics(
+    zend_object *nonnull span, double duration);
+
+void dd_rasp_startup(void)
+{
+    _dd_rasp_duration_ext =
+        zend_string_init_interned(LSTRARG(DD_EVENTS_RASP_DURATION_EXT), 1);
+}
+void dd_rasp_shutdown(void)
+{
+    zend_string_release(_dd_rasp_duration_ext);
+    _dd_rasp_duration_ext = NULL;
+}
+void dd_rasp_reset_globals(void) { _duration_ext_us = 0.0; }
+void dd_rasp_req_finish(void)
+{
+    if (_duration_ext_us <= 0.0) {
+        return;
+    }
+    zend_object *span = dd_req_lifecycle_get_cur_span();
+    if (!span) {
+        return;
+    }
+    _add_rasp_duration_ext_to_metrics(span, _duration_ext_us);
+    _duration_ext_us = 0.0;
+}
+
+void dd_rasp_account_duration_us(double duration_us)
+{
+    _duration_ext_us += duration_us;
+}
+
+static void _add_rasp_duration_ext_to_metrics(
+    zend_object *nonnull span, double duration)
+{
+    zval *metrics_zv = dd_trace_span_get_metrics(span);
+    if (!metrics_zv) {
+        return;
+    }
+
+    zval zv;
+    ZVAL_DOUBLE(&zv, duration);
+    zval *nullable res =
+        zend_hash_add(Z_ARRVAL_P(metrics_zv), _dd_rasp_duration_ext, &zv);
+    if (res == NULL) {
+        mlog(dd_log_warning, "Failed to add metric %.*s",
+            (int)ZSTR_LEN(_dd_rasp_duration_ext),
+            ZSTR_VAL(_dd_rasp_duration_ext));
+    }
+}

appsec/src/extension/rasp.h

@@ -0,0 +1,7 @@
+#pragma once
+
+void dd_rasp_startup(void);
+void dd_rasp_shutdown(void);
+void dd_rasp_account_duration_us(double duration_us);
+void dd_rasp_reset_globals(void); // call on rinit/user req begin
+void dd_rasp_req_finish(void); // call on rshutdown/user req shutdown

appsec/src/extension/request_lifecycle.c

@@ -14,6 +14,7 @@
 #include "php_compat.h"
 #include "php_helpers.h"
 #include "php_objects.h"
+#include "rasp.h"
 #include "request_abort.h"
 #include "string_helpers.h"
 #include "tags.h"
@@ -352,6 +353,7 @@ static void _do_request_finish_php(bool ignore_verdict)
         dd_tags_add_tags(_cur_req_span, NULL);
     }
     dd_tags_rshutdown();
+    dd_rasp_req_finish();
 
     _reset_globals();
 
@@ -402,6 +404,7 @@ static zend_array *_do_request_finish_user_req(bool ignore_verdict,
     if (DDAPPSEC_G(active) && _cur_req_span) {
         dd_tags_add_tags(_cur_req_span, superglob_equiv);
     }
+    dd_rasp_req_finish();
 
     if (verdict == dd_should_block) {
         const zend_array *nonnull sv = _get_server_equiv(superglob_equiv);
@@ -439,6 +442,7 @@ static void _reset_globals(void)
 
     _shutdown_done_on_commit = false;
     dd_tags_rshutdown();
+    dd_rasp_reset_globals();
 }
 
 static zend_string *nullable _extract_ip_from_autoglobal(void)

appsec/src/extension/tags.c

@@ -76,7 +76,6 @@
     "_dd.appsec.events.users.login.success.sdk"
 #define DD_EVENTS_USER_LOGIN_FAILURE_SDK                                       \
     "_dd.appsec.events.users.login.failure.sdk"
-#define DD_EVENTS_RASP_DURATION_EXT "_dd.appsec.rasp.duration_ext"
 #define DD_SERVER_BUSINESS_LOGIC_USERS_SIGNUP                                  \
     "server.business_logic.users.signup"
 #define DD_SERVER_BUSINESS_LOGIC_USERS_LOGIN_SUCCESS                           \
@@ -104,7 +103,6 @@ static zend_string *_dd_tag_rh_content_language; // response
 static zend_string *_dd_tag_user;
 static zend_string *_dd_tag_user_id;
 static zend_string *_dd_metric_enabled;
-static zend_string *_dd_rasp_duration_ext;
 static zend_string *_dd_business_logic_users_signup;
 static zend_string *_dd_business_logic_users_login_success;
 static zend_string *_dd_business_logic_users_login_failure;
@@ -217,9 +215,6 @@ void dd_tags_startup(void)
     _key_remote_addr_zstr =
         zend_string_init_interned(LSTRARG("REMOTE_ADDR"), 1);
 
-    _dd_rasp_duration_ext =
-        zend_string_init_interned(LSTRARG(DD_EVENTS_RASP_DURATION_EXT), 1);
-
     // Event related strings
     _track_zstr =
         zend_string_init_interned(LSTRARG("track"), 1 /* permanent */);
@@ -370,18 +365,6 @@ void dd_tags_set_event_user_id(zend_string *nonnull zstr)
     _event_user_id = zend_string_copy(zstr);
 }
 
-void dd_tags_add_rasp_duration_ext(
-    zend_object *nonnull span, zend_long duration)
-{
-    zval *metrics_zv = dd_trace_span_get_metrics(span);
-    if (!metrics_zv) {
-        return;
-    }
-    zval zv;
-    ZVAL_LONG(&zv, duration);
-    zend_hash_add(Z_ARRVAL_P(metrics_zv), _dd_rasp_duration_ext, &zv);
-}
-
 void dd_tags_rshutdown(void)
 {
     zend_llist_clean(&_appsec_json_frags);

appsec/src/extension/tags.h

@@ -26,6 +26,3 @@ void dd_tags_set_event_user_id(zend_string *nonnull zstr);
 
 // does not increase the refcount on zstr
 void dd_tags_add_appsec_json_frag(zend_string *nonnull zstr);
-
-void dd_tags_add_rasp_duration_ext(
-    zend_object *nonnull span, zend_long duration);

appsec/tests/extension/push_params_ok_04.phpt

@@ -30,8 +30,8 @@ bool(true)
 Array
 (
     [process_id] => %d
-    [_dd.appsec.rasp.duration_ext] => %d
     [_dd.appsec.enabled] => %d
+    [_dd.appsec.rasp.duration_ext] => %f
 )
 array(2) {
   [0]=>

appsec/tests/extension/rasp_duration_ext_user_requests.phpt

@@ -0,0 +1,93 @@
+--TEST--
+RASP duration_ext metric accumulates across multiple calls in user requests
+--INI--
+extension=ddtrace.so
+datadog.appsec.enabled=true
+datadog.appsec.cli_start_on_rinit=false
+--ENV--
+DD_TRACE_GENERATE_ROOT_SPAN=0
+--FILE--
+<?php
+
+use function DDTrace\UserRequest\{notify_start,notify_commit};
+use function DDTrace\{start_span,close_span,active_span};
+use function datadog\appsec\push_addresses;
+
+include __DIR__ . '/inc/mock_helper.php';
+
+define('NUM_CALLS', 20);
+
+$resps = array_merge(
+    array(response_list(response_request_init([[['ok', []]], [], []]))),
+    array_fill(0, NUM_CALLS,
+    response_list(response_request_exec([[['ok', []]], [], [], [], false]))),
+    array(
+        response_list(response_request_shutdown([[['ok', []]], [], []])),
+
+        // Second user request
+        response_list(response_request_init([[['ok', []]], [], []])),
+        response_list(response_request_exec([[['ok', []]], [], [], [], false])),
+        response_list(response_request_shutdown([[['ok', []]], [], []])),
+    )
+);
+
+$helper = Helper::createinitedRun($resps);
+
+echo "=== First user request ===\n";
+$span1 = start_span();
+notify_start($span1, array());
+
+for ($i = 0; $i < NUM_CALLS; $i++) {
+    push_addresses(["server.request.path_params" => "test1"], "lfi");
+}
+
+notify_commit($span1, 200, array());
+
+// Get metrics for first request
+$metrics1 = $span1->metrics ?? [];
+echo "First request has duration_ext: " . (isset($metrics1['_dd.appsec.rasp.duration_ext']) ? "yes" : "no") . "\n";
+if (isset($metrics1['_dd.appsec.rasp.duration_ext'])) {
+    $duration1 = $metrics1['_dd.appsec.rasp.duration_ext'];
+    echo "First request duration_ext is positive: " . ($duration1 > 0 ? "yes" : "no") . "\n";
+}
+
+close_span(100.0);
+
+echo "\n=== Second user request ===\n";
+$span2 = start_span();
+notify_start($span2, array());
+
+push_addresses(["server.request.body" => "test3"], "lfi");
+
+notify_commit($span2, 200, array());
+
+// Get metrics for second request
+$metrics2 = $span2->metrics ?? [];
+echo "Second request has duration_ext: " . (isset($metrics2['_dd.appsec.rasp.duration_ext']) ? "yes" : "no") . "\n";
+if (isset($metrics2['_dd.appsec.rasp.duration_ext'])) {
+    $duration2 = $metrics2['_dd.appsec.rasp.duration_ext'];
+    echo "Second request duration_ext is positive: " . ($duration2 > 0 ? "yes" : "no") . "\n";
+}
+
+close_span(100.0);
+
+if (isset($duration1) && isset($duration2)) {
+    echo "\nBoth requests have duration_ext metrics: yes\n";
+    if ($duration1 > $duration2) {
+        echo "First request has a larger duration_ext: yes\n";
+    }
+}
+
+
+?>
+--EXPECTF--
+=== First user request ===
+First request has duration_ext: yes
+First request duration_ext is positive: yes
+
+=== Second user request ===
+Second request has duration_ext: yes
+Second request duration_ext is positive: yes
+
+Both requests have duration_ext metrics: yes
+First request has a larger duration_ext: yes