appsec: implement more telemetry metrics/tags

appsec/helper-rust/src/client/metrics.rs

@@ -101,6 +101,11 @@ pub struct RaspRuleMetrics {
 
     /// Total number of RASP rule timeouts
     pub timeouts: u32,
+
+    /// Duration of each individual libddwaf call, for the rasp.rule.duration
+    /// distribution. Unlike rasp.duration, which is the per-request cumulative
+    /// sum, this metric records one observation per call.
+    pub durations: Vec<Duration>,
 }
 
 impl WafMetrics {
@@ -180,6 +185,7 @@ impl WafMetrics {
             .entry((rule_type.to_string(), rule_variant.to_string()))
             .or_default();
         entry.evals += 1;
+        entry.durations.push(run_output.duration());
         if run_output.has_events() {
             if run_output.is_blocking() {
                 entry.matches_blocked += 1;
@@ -234,8 +240,11 @@ impl telemetry::TelemetryMetricsGenerator for WafMetrics {
         // RFC-1012: all boolean tags must be emitted regardless of value.
         let mut tags = base_tags.clone();
         tags.add("rule_triggered", bool_tag(self.had_triggers));
-        // block_failure is not tracked: the PHP layer is assumed to always succeed at blocking.
+        // The PHP layer is assumed to always succeed at blocking.
         // Therefore request_blocked == "WAF requested a block" == "block succeeded".
+        if self.request_blocked {
+            tags.add("block_failure", "false");
+        }
         // request_excluded is not tracked: libddwaf applies exclusion filters internally and
         // does not expose whether a request was excluded in RunOutput.
         tags.add("request_blocked", bool_tag(self.request_blocked));
@@ -306,6 +315,15 @@ impl telemetry::TelemetryMetricsGenerator for WafMetrics {
                 );
             }
 
+            // rasp.rule.duration distribution: one observation per libddwaf call, in microseconds
+            for duration in &metrics.durations {
+                submitter.submit_metric(
+                    telemetry::RASP_RULE_DURATION_DIST,
+                    duration.as_micros() as f64,
+                    tags.clone(),
+                );
+            }
+
             // tests expect this to always be sent, even if 0
             submitter.submit_metric(telemetry::RASP_TIMEOUT, metrics.timeouts as f64, tags);
         }

appsec/helper-rust/src/telemetry.rs

@@ -97,6 +97,7 @@ pub const WAF_ERROR: MetricName = MetricName("waf.error");
 pub const WAF_DURATION_DIST: MetricName = MetricName("waf.duration");
 pub const RASP_DURATION_DIST: MetricName = MetricName("rasp.duration");
 pub const RASP_RULE_EVAL: MetricName = MetricName("rasp.rule.eval");
+pub const RASP_RULE_DURATION_DIST: MetricName = MetricName("rasp.rule.duration");
 pub const RASP_RULE_MATCH: MetricName = MetricName("rasp.rule.match");
 pub const RASP_TIMEOUT: MetricName = MetricName("rasp.timeout");
 pub const RASP_ERROR: MetricName = MetricName("rasp.error");
@@ -136,6 +137,10 @@ pub const KNOWN_METRICS: &[KnownMetric] = &[
         name: RASP_DURATION_DIST,
         metric_type: ddog_MetricType_DDOG_METRIC_TYPE_DISTRIBUTION,
     },
+    KnownMetric {
+        name: RASP_RULE_DURATION_DIST,
+        metric_type: ddog_MetricType_DDOG_METRIC_TYPE_DISTRIBUTION,
+    },
     KnownMetric {
         name: RASP_TIMEOUT,
         metric_type: ddog_MetricType_DDOG_METRIC_TYPE_COUNT,

appsec/src/extension/commands_helpers.c

@@ -719,8 +719,11 @@ void dd_command_process_meta(mpack_node_t root, zend_object *nonnull span)
             key_str, key_len, val_str, val_len);
     }
 
-    if (has_schemas && !get_DD_APM_TRACING_ENABLED()) {
-        dd_trace_emit_asm_event();
+    if (has_schemas) {
+        dd_telemetry_note_schema_extracted();
+        if (!get_DD_APM_TRACING_ENABLED()) {
+            dd_trace_emit_asm_event();
+        }
     }
 }
 

appsec/src/extension/ddappsec.c

@@ -573,12 +573,6 @@ PHP_FUNCTION(datadog_appsec_push_addresses)
         RETURN_FALSE;
     }
 
-    if (!dd_req_lifecycle_is_active()) {
-        mlog_g(dd_log_info,
-            "Not running inside a tracked request; skipping push_addresses");
-        RETURN_FALSE;
-    }
-
     zval *addresses;
     zend_string *rasp_rule = NULL;
     zend_string *rule_variant = NULL;
@@ -587,12 +581,22 @@ PHP_FUNCTION(datadog_appsec_push_addresses)
         RETURN_FALSE;
     }
 
-    if (rasp_rule && ZSTR_LEN(rasp_rule) > 0 &&
-        !get_global_DD_APPSEC_RASP_ENABLED()) {
+    bool is_rasp = rasp_rule != NULL && ZSTR_LEN(rasp_rule) > 0;
+
+    if (is_rasp && !get_global_DD_APPSEC_RASP_ENABLED()) {
         mlog(dd_log_debug, "RASP is not enabled; skipping push_addresses");
         RETURN_FALSE;
     }
 
+    if (!dd_req_lifecycle_is_active()) {
+        mlog_g(dd_log_info,
+            "Not running inside a tracked request; skipping push_addresses");
+        if (is_rasp) {
+            dd_telemetry_add_rasp_rule_skipped(rasp_rule, rule_variant);
+        }
+        RETURN_FALSE;
+    }
+
     dd_conn *conn = dd_helper_mgr_cur_conn();
     if (conn == NULL) {
         mlog_g(dd_log_debug, "No connection; skipping push_addresses");
@@ -606,7 +610,7 @@ PHP_FUNCTION(datadog_appsec_push_addresses)
     dd_result res =
         dd_request_exec(conn, Z_ARRVAL_P(addresses), &opts, &block_params);
 
-    if (opts.rasp_rule && ZSTR_LEN(opts.rasp_rule) > 0) {
+    if (is_rasp) {
         dd_duration_rasp_ext_account(&start);
     } else {
         dd_duration_waf_ext_account(&start);

appsec/src/extension/request_lifecycle.c

@@ -39,7 +39,9 @@ static void _set_cur_span(zend_object *nullable span);
 static void _reset_globals(void);
 const zend_array *nonnull _get_server_equiv(
     const zend_array *nonnull superglob_equiv);
-static uint64_t _calc_sampling_key(zend_object *root_span, int status_code);
+static uint64_t _calc_sampling_key(zend_object *root_span, int status_code,
+    dd_api_sec_outcome *nonnull outcome);
+static bool _shutdown_succeeded(dd_result res);
 static void _register_testing_objects(void);
 
 static bool _enabled_user_req;
@@ -388,14 +390,16 @@ static void _do_request_finish_php(bool ignore_verdict)
 
     if (conn && DDAPPSEC_G(active)) {
         const int status_code = SG(sapi_headers).http_response_code;
+        dd_api_sec_outcome api_sec_outcome;
         ctx = (struct req_shutdown_info){
             .req_info.root_span = dd_req_lifecycle_get_cur_span(),
             .req_info.client_ip = dd_req_lifecycle_get_client_ip(),
             .status_code = status_code,
             .resp_headers_fmt = RESP_HEADERS_LLIST,
             .resp_headers_llist = &SG(sapi_headers).headers,
             .entity = dd_response_body_buffered(),
-            .api_sec_samp_key = _calc_sampling_key(_cur_req_span, status_code),
+            .api_sec_samp_key = _calc_sampling_key(
+                _cur_req_span, status_code, &api_sec_outcome),
         };
 
         struct timespec shutdown_start = dd_monotime_start();
@@ -412,6 +416,9 @@ static void _do_request_finish_php(bool ignore_verdict)
             mlog_g(dd_log_info, "request shutdown failed: %s",
                 dd_result_to_string(res));
         }
+
+        dd_telemetry_add_api_security_request(
+            _cur_req_span, api_sec_outcome);
     }
 
     dd_helper_rshutdown();
@@ -438,14 +445,16 @@ static zend_array *_do_request_finish_user_req(bool ignore_verdict,
     struct req_shutdown_info ctx = {0};
 
     if (conn && DDAPPSEC_G(active)) {
+        dd_api_sec_outcome api_sec_outcome;
         ctx = (struct req_shutdown_info){
             .req_info.root_span = dd_req_lifecycle_get_cur_span(),
             .req_info.client_ip = dd_req_lifecycle_get_client_ip(),
             .status_code = status_code,
             .resp_headers_fmt = RESP_HEADERS_MAP_STRING_LIST,
             .resp_headers_arr = resp_headers ? resp_headers : &zend_empty_array,
             .entity = entity,
-            .api_sec_samp_key = _calc_sampling_key(_cur_req_span, status_code),
+            .api_sec_samp_key = _calc_sampling_key(
+                _cur_req_span, status_code, &api_sec_outcome),
         };
 
         struct timespec shutdown_start = dd_monotime_start();
@@ -462,6 +471,9 @@ static zend_array *_do_request_finish_user_req(bool ignore_verdict,
             mlog_g(dd_log_info, "request shutdown failed: %s",
                 dd_result_to_string(res));
         }
+
+        dd_telemetry_add_api_security_request(
+            _cur_req_span, api_sec_outcome);
     }
 
     dd_helper_rshutdown();
@@ -1003,8 +1015,11 @@ static inline uint64_t _hash_zend_string(
     return _hash_string(hash, ZSTR_VAL(str), ZSTR_LEN(str));
 }
 
-static uint64_t _calc_sampling_key(zend_object *root_span, int status_code)
+static uint64_t _calc_sampling_key(zend_object *root_span, int status_code,
+    dd_api_sec_outcome *nonnull outcome)
 {
+    *outcome = DD_API_SEC_SKIP;
+
     if (!get_DD_API_SECURITY_ENABLED()) {
         return 0;
     }
@@ -1079,14 +1094,16 @@ static uint64_t _calc_sampling_key(zend_object *root_span, int status_code)
     }
 
     if (!route_or_endpoint) {
-        goto error;
+        goto missing_route;
     }
 
     zval *method =
         zend_hash_str_find(Z_ARRVAL_P(meta), ZEND_STRL("http.method"));
     if (!method || Z_TYPE_P(method) != IS_STRING) {
         mlog_g(dd_log_debug, "No http.method tag; not sampling");
-        goto error;
+        // we treat the absence of http.method also as a missing route, because
+        // it also prevents schema extraction and it's sort of part of the route
+        goto missing_route;
     }
 
     // use fnv-1a hash with: <route_or_endpoint> NULL <http.method tag> NULL
@@ -1113,9 +1130,17 @@ static uint64_t _calc_sampling_key(zend_object *root_span, int status_code)
     if (free_route_or_endpoint) {
         zend_string_release(route_or_endpoint);
     }
+    *outcome = DD_API_SEC_EVALUATED;
     return hash;
 
-error:
+missing_route:
+    // Neither the route nor a stand-in for it could be determined. 404s are
+    // excluded: an endpoint that does not exist has no route to speak of, so
+    // counting it would be misleading
+    if (status_code != HTTP_NOT_FOUND) {
+        *outcome = DD_API_SEC_MISSING_ROUTE;
+    }
+
     if (free_route_or_endpoint) {
         zend_string_release(route_or_endpoint);
     }

appsec/src/extension/telemetry.c

@@ -20,11 +20,19 @@ static zend_string *_dd_helper_conn_close_zstr;
 
 static zend_string *_waf_duration_ext_tel_zstr;
 static zend_string *_rasp_duration_ext_tel_zstr;
+static zend_string *_rasp_rule_skipped_zstr;
+static zend_string *_api_sec_request_schema_zstr;
+static zend_string *_api_sec_request_no_schema_zstr;
+static zend_string *_api_sec_missing_route_zstr;
+
+static zend_string *_component_literal_zstr;
 
 static THREAD_LOCAL_ON_ZTS zend_string *nullable _cached_waf_version;
 static THREAD_LOCAL_ON_ZTS zend_string *nullable _cached_event_rules_version;
+static THREAD_LOCAL_ON_ZTS bool _schema_extracted;
 
 static zend_string *nullable _duration_ext_tags_from_cache(void);
+static zend_string *nonnull _framework_tag(zend_object *nullable root_span);
 static void _release_zstr(zend_string *nullable *nonnull slot);
 static void _cache_replace(zend_string *nullable *nonnull slot,
     const char *nonnull val, size_t val_len);
@@ -46,6 +54,16 @@ void dd_telemetry_startup(void)
         zend_string_init_interned(LSTRARG("waf.duration_ext"), 1);
     _rasp_duration_ext_tel_zstr =
         zend_string_init_interned(LSTRARG("rasp.duration_ext"), 1);
+    _rasp_rule_skipped_zstr =
+        zend_string_init_interned(LSTRARG("rasp.rule.skipped"), 1);
+    _api_sec_request_schema_zstr =
+        zend_string_init_interned(LSTRARG("api_security.request.schema"), 1);
+    _api_sec_request_no_schema_zstr =
+        zend_string_init_interned(LSTRARG("api_security.request.no_schema"), 1);
+    _api_sec_missing_route_zstr =
+        zend_string_init_interned(LSTRARG("api_security.missing_route"), 1);
+    _component_literal_zstr =
+        zend_string_init_interned(LSTRARG("component"), 1);
 }
 
 void dd_telemetry_mshutdown(void)
@@ -58,6 +76,7 @@ void dd_telemetry_rinit(void)
 {
     _release_zstr(&_cached_event_rules_version);
     _release_zstr(&_cached_waf_version);
+    _schema_extracted = false;
 }
 
 void dd_telemetry_note_helper_string_meta(const char *nonnull key,
@@ -96,6 +115,102 @@ void dd_telemetry_add_sdk_event(char *nonnull event_type, size_t event_type_len)
     free(tags);
 }
 
+void dd_telemetry_add_rasp_rule_skipped(
+    zend_string *nonnull rule_type, zend_string *nullable rule_variant)
+{
+    if (!dd_trace_loaded() || datadog_metric_register_buffer == NULL ||
+        datadog_metric_add_point == NULL) {
+        return;
+    }
+
+    char *tags = NULL;
+    size_t tags_len;
+    if (rule_variant != NULL && ZSTR_LEN(rule_variant) > 0) {
+        tags_len = spprintf(&tags, 0,
+            "rule_type:%.*s,rule_variant:%.*s,reason:out-of-request",
+            ZSTR_PRINTF(rule_type), ZSTR_PRINTF(rule_variant));
+    } else {
+        tags_len = spprintf(&tags, 0, "rule_type:%.*s,reason:out-of-request",
+            ZSTR_PRINTF(rule_type));
+    }
+
+    zend_string *tags_zstr = zend_string_init(tags, tags_len, 0);
+    dd_telemetry_add_metric(
+        _rasp_rule_skipped_zstr, 1, tags_zstr, DDTRACE_METRIC_TYPE_COUNT);
+    zend_string_release(tags_zstr);
+    efree(tags);
+}
+
+void dd_telemetry_note_schema_extracted(void) { _schema_extracted = true; }
+
+void dd_telemetry_add_api_security_request(
+    zend_object *nullable root_span, dd_api_sec_outcome outcome)
+{
+    const bool schema_extracted = _schema_extracted;
+    _schema_extracted = false;
+
+    if (outcome == DD_API_SEC_SKIP) {
+        return;
+    }
+
+    if (!dd_trace_loaded() || datadog_metric_register_buffer == NULL ||
+        datadog_metric_add_point == NULL) {
+        return;
+    }
+
+    zend_string *name_zstr;
+    if (outcome == DD_API_SEC_MISSING_ROUTE) {
+        name_zstr = _api_sec_missing_route_zstr;
+    } else if (schema_extracted) {
+        name_zstr = _api_sec_request_schema_zstr;
+    } else {
+        name_zstr = _api_sec_request_no_schema_zstr;
+    }
+
+    zend_string *tags_zstr = _framework_tag(root_span);
+    dd_telemetry_add_metric(name_zstr, 1, tags_zstr, DDTRACE_METRIC_TYPE_COUNT);
+    zend_string_release(tags_zstr);
+}
+
+#define DD_UNKNOWN_FRAMEWORK "unknown"
+// Builds the framework tag out of the root span's component tag, which is what
+// the framework integrations set (e.g. laravel, symfony, wordpress). Per
+// RFC-1012, the name is normalized by lowercasing it and replacing spaces with
+// underscores.
+static zend_string *nonnull _framework_tag(zend_object *nullable root_span)
+{
+    const char *framework = DD_UNKNOWN_FRAMEWORK;
+    size_t framework_len = LSTRLEN(DD_UNKNOWN_FRAMEWORK);
+
+    zval *nullable meta = root_span ? dd_trace_span_get_meta(root_span) : NULL;
+    if (meta != NULL && Z_TYPE_P(meta) == IS_ARRAY) {
+        zval *nullable component =
+            zend_hash_find_ex(Z_ARRVAL_P(meta), _component_literal_zstr, true);
+        if (component != NULL && Z_TYPE_P(component) == IS_STRING &&
+            Z_STRLEN_P(component) > 0) {
+            framework = Z_STRVAL_P(component);
+            framework_len = Z_STRLEN_P(component);
+        }
+    }
+
+    zend_string *tags_zstr =
+        zend_string_alloc(LSTRLEN("framework:") + framework_len, 0);
+    memcpy(ZSTR_VAL(tags_zstr), LSTRARG("framework:"));
+    char *dest = ZSTR_VAL(tags_zstr) + LSTRLEN("framework:");
+    for (size_t i = 0; i < framework_len; i++) {
+        char c = framework[i];
+        if (c == ' ') {
+            c = '_';
+        } else if (c >= 'A' && c <= 'Z') {
+            c = (char)(c - 'A' + 'a');
+        }
+        dest[i] = c;
+    }
+    ZSTR_VAL(tags_zstr)[ZSTR_LEN(tags_zstr)] = '\0';
+
+    return tags_zstr;
+}
+
 static void _add_user_auth_metric(zend_string *nonnull name_zstr,
     const char *nonnull event_type, size_t event_type_len,
     const char *nonnull framework, size_t framework_len)