diff --git a/appsec/helper-rust/src/client/metrics.rs b/appsec/helper-rust/src/client/metrics.rs index 00861270927..2063e9f0396 100644 --- a/appsec/helper-rust/src/client/metrics.rs +++ b/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, } 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); } diff --git a/appsec/helper-rust/src/telemetry.rs b/appsec/helper-rust/src/telemetry.rs index a722c52b8fd..03eca70a1ba 100644 --- a/appsec/helper-rust/src/telemetry.rs +++ b/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, diff --git a/appsec/src/extension/commands_helpers.c b/appsec/src/extension/commands_helpers.c index a7063ddcec8..b7fc49bf757 100644 --- a/appsec/src/extension/commands_helpers.c +++ b/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(); + } } } diff --git a/appsec/src/extension/ddappsec.c b/appsec/src/extension/ddappsec.c index 9e07e9b2477..0025885a55b 100644 --- a/appsec/src/extension/ddappsec.c +++ b/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); diff --git a/appsec/src/extension/php_compat.h b/appsec/src/extension/php_compat.h index 7da9d496ab2..5e70d454809 100644 --- a/appsec/src/extension/php_compat.h +++ b/appsec/src/extension/php_compat.h @@ -75,6 +75,8 @@ extern zend_string *zend_empty_string; #if PHP_VERSION_ID < 70300 extern const HashTable zend_empty_array; +# define zend_hash_find_ex(ht, key, known) zend_hash_find(ht, key) + # define GC_ADDREF(x) (++GC_REFCOUNT(x)) # define GC_DELREF(x) (--GC_REFCOUNT(x)) static zend_always_inline void _gc_try_addref(zend_refcounted_h *_rc) diff --git a/appsec/src/extension/request_lifecycle.c b/appsec/src/extension/request_lifecycle.c index 9e32129b87e..4b149729f99 100644 --- a/appsec/src/extension/request_lifecycle.c +++ b/appsec/src/extension/request_lifecycle.c @@ -39,7 +39,8 @@ 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 void _register_testing_objects(void); static bool _enabled_user_req; @@ -388,6 +389,7 @@ 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(), @@ -395,7 +397,8 @@ static void _do_request_finish_php(bool ignore_verdict) .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 +415,8 @@ 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,6 +443,7 @@ 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(), @@ -445,7 +451,8 @@ static zend_array *_do_request_finish_user_req(bool ignore_verdict, .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 +469,8 @@ 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 +1012,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 +1091,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: NULL NULL @@ -1113,9 +1127,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); } diff --git a/appsec/src/extension/telemetry.c b/appsec/src/extension/telemetry.c index 000f0cd0e5c..bafec59a055 100644 --- a/appsec/src/extension/telemetry.c +++ b/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) diff --git a/appsec/src/extension/telemetry.h b/appsec/src/extension/telemetry.h index 57eed8cc850..d827d38b6c2 100644 --- a/appsec/src/extension/telemetry.h +++ b/appsec/src/extension/telemetry.h @@ -26,6 +26,30 @@ void dd_telemetry_note_helper_string_meta(const char *nonnull key, // NOLINTNEXTLINE(bugprone-easily-swappable-parameters) void dd_telemetry_submit_duration_ext(double waf_ext_us, double rasp_ext_us); +void dd_telemetry_add_rasp_rule_skipped( + zend_string *nonnull rule_type, zend_string *nullable rule_variant); + +// The outcome of the API security decision taken for a request, as far as +// RFC-1012's api_security metrics are concerned. +typedef enum { + // the request is not a candidate for schema extraction for a reason that + // is not worth reporting (API security disabled, request blocked, trace + // dropped, ...). No metric is emitted. + DD_API_SEC_SKIP = 0, + // the request would have been a candidate, but no HTTP route (or a + // stand-in for it) could be determined: appsec.api_security.missing_route + DD_API_SEC_MISSING_ROUTE, + // the request was submitted for schema extraction: either + // appsec.api_security.request.schema or .no_schema, depending on whether + // the helper came back with a schema + DD_API_SEC_EVALUATED, +} dd_api_sec_outcome; + +// Called when the helper reports schemas (_dd.appsec.s.*) for the current +// request +void dd_telemetry_note_schema_extracted(void); +void dd_telemetry_add_api_security_request( + zend_object *nullable root_span, dd_api_sec_outcome outcome); void dd_telemetry_helper_conn_error(void); void dd_telemetry_helper_conn_success(void); diff --git a/appsec/tests/extension/api_security_telemetry_missing_route.phpt b/appsec/tests/extension/api_security_telemetry_missing_route.phpt new file mode 100644 index 00000000000..ee15a5c136a --- /dev/null +++ b/appsec/tests/extension/api_security_telemetry_missing_route.phpt @@ -0,0 +1,54 @@ +--TEST-- +appsec.api_security.missing_route is reported when no route can be determined +--INI-- +extension=ddtrace.so +datadog.appsec.log_file=/tmp/php_appsec_test_apisec_missing_route.log +datadog.appsec.log_level=debug +datadog.appsec.enabled=1 +--GET-- +key=val +--FILE-- +get_commands(); // ignore + +// no http.route, no http.endpoint and no http.url: no route can be determined +$rootSpan = root_span(); +$rootSpan->meta["http.method"] = "GET"; + +var_dump(rshutdown()); +$c = $helper->get_commands(); +echo "Sampler hash sent: ", $c[0][1][1], "\n"; + +match_log('/Telemetry metric api_security\.missing_route added with tags framework:unknown and value 1/'); +no_match_log('/api_security\.request\./'); + +?> +--EXPECT-- +bool(true) +bool(true) +Sampler hash sent: 0 +found message in log matching /Telemetry metric api_security\.missing_route added with tags framework:unknown and value 1/ +no message in log matching /api_security\.request\./ diff --git a/appsec/tests/extension/api_security_telemetry_no_route_404.phpt b/appsec/tests/extension/api_security_telemetry_no_route_404.phpt new file mode 100644 index 00000000000..14355bb9db7 --- /dev/null +++ b/appsec/tests/extension/api_security_telemetry_no_route_404.phpt @@ -0,0 +1,51 @@ +--TEST-- +No api_security metric is reported for a routeless 404 +--INI-- +extension=ddtrace.so +datadog.appsec.log_file=/tmp/php_appsec_test_apisec_404.log +datadog.appsec.log_level=debug +datadog.appsec.enabled=1 +--GET-- +key=val +--FILE-- +get_commands(); // ignore + +// an endpoint that does not exist has no route to speak of; it must not be +// counted as a missing route +$rootSpan = root_span(); +$rootSpan->meta["http.method"] = "GET"; + +var_dump(rshutdown()); +$helper->get_commands(); // ignore + +no_match_log('/api_security\./'); + +?> +--EXPECT-- +bool(true) +bool(true) +no message in log matching /api_security\./ diff --git a/appsec/tests/extension/api_security_telemetry_no_schema.phpt b/appsec/tests/extension/api_security_telemetry_no_schema.phpt new file mode 100644 index 00000000000..98538cf5f12 --- /dev/null +++ b/appsec/tests/extension/api_security_telemetry_no_schema.phpt @@ -0,0 +1,53 @@ +--TEST-- +appsec.api_security.request.no_schema is reported when no schemas come back +--INI-- +extension=ddtrace.so +datadog.appsec.log_file=/tmp/php_appsec_test_apisec_no_schema.log +datadog.appsec.log_level=debug +datadog.appsec.enabled=1 +--GET-- +key=val +--FILE-- + 'value'], + [], + ])) +]); + +http_response_code(200); + +var_dump(rinit()); +$helper->get_commands(); // ignore + +$rootSpan = root_span(); +$rootSpan->meta["http.method"] = "GET"; +$rootSpan->meta["http.route"] = "/foo/bar"; +$rootSpan->meta["component"] = "symfony"; + +var_dump(rshutdown()); +$helper->get_commands(); // ignore + +match_log('/Telemetry metric api_security\.request\.no_schema added with tags framework:symfony and value 1/'); +no_match_log('/api_security\.request\.schema/', '/api_security\.missing_route/'); + +?> +--EXPECT-- +bool(true) +bool(true) +found message in log matching /Telemetry metric api_security\.request\.no_schema added with tags framework:symfony and value 1/ +no message in log matching /api_security\.request\.schema/, /api_security\.missing_route/ diff --git a/appsec/tests/extension/api_security_telemetry_schema.phpt b/appsec/tests/extension/api_security_telemetry_schema.phpt new file mode 100644 index 00000000000..615c27dd8c9 --- /dev/null +++ b/appsec/tests/extension/api_security_telemetry_schema.phpt @@ -0,0 +1,54 @@ +--TEST-- +appsec.api_security.request.schema is reported when the helper returns schemas +--INI-- +extension=ddtrace.so +datadog.appsec.log_file=/tmp/php_appsec_test_apisec_schema.log +datadog.appsec.log_level=debug +datadog.appsec.enabled=1 +--GET-- +key=val +--FILE-- + 'W3siYSI6WzhdfV0='], + [], + ])) +]); + +http_response_code(200); + +var_dump(rinit()); +$helper->get_commands(); // ignore + +$rootSpan = root_span(); +$rootSpan->meta["http.method"] = "GET"; +$rootSpan->meta["http.route"] = "/foo/bar"; +// framework names are normalized: lowercased, spaces replaced with underscores +$rootSpan->meta["component"] = "Laravel Framework"; + +var_dump(rshutdown()); +$helper->get_commands(); // ignore + +match_log('/Telemetry metric api_security\.request\.schema added with tags framework:laravel_framework and value 1/'); +no_match_log('/api_security\.request\.no_schema/', '/api_security\.missing_route/'); + +?> +--EXPECT-- +bool(true) +bool(true) +found message in log matching /Telemetry metric api_security\.request\.schema added with tags framework:laravel_framework and value 1/ +no message in log matching /api_security\.request\.no_schema/, /api_security\.missing_route/ diff --git a/appsec/tests/extension/inc/logging.php b/appsec/tests/extension/inc/logging.php index 152ee5b7151..17b38b1de83 100644 --- a/appsec/tests/extension/inc/logging.php +++ b/appsec/tests/extension/inc/logging.php @@ -17,6 +17,16 @@ function match_log() { echo "None of " . var_export(func_get_args(), true) . " have matched\n"; echo "Log contents were:\n", log_contents(); } +function no_match_log() { + $regexes = func_get_args(); + foreach ($regexes as $r) { + if (preg_match($r, log_contents()) === 1) { + echo "unexpected message in log matching $r\n"; + return; + } + } + echo "no message in log matching " . implode(', ', $regexes) . "\n"; +} function truncate_log() { $f = fopen(get_filename(), 'c'); ftruncate($f, 0); diff --git a/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/EndpointFallbackSamplingTests.groovy b/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/EndpointFallbackSamplingTests.groovy index d9c32c1e6b8..c8c73394f3c 100644 --- a/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/EndpointFallbackSamplingTests.groovy +++ b/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/EndpointFallbackSamplingTests.groovy @@ -1,11 +1,15 @@ package com.datadog.appsec.php.integration +import com.datadog.appsec.php.TelemetryHelpers import com.datadog.appsec.php.docker.AppSecContainer import com.datadog.appsec.php.docker.PhpFpm +import org.junit.jupiter.api.Assumptions import org.junit.jupiter.api.Test import java.net.http.HttpResponse +import static com.datadog.appsec.php.integration.TestParams.getPhpVersion + trait EndpointFallbackSamplingTests extends SamplingTestsInFpm { /** @@ -106,6 +110,80 @@ trait EndpointFallbackSamplingTests extends SamplingTestsInFpm { } } + /** + * If neither http.route, nor http.endpoint, nor http.url is available, + * there is nothing to key the sampling on: the request must not be sampled + * and it must be counted as RFC-1012's appsec.api_security.missing_route. + * + * The other two API security metrics, appsec.api_security.request.schema + * and .request.no_schema, are asserted here as well, as this test can + * produce them in passing. Draining telemetry means waiting on the metric + * interval (hardcoded to 10s), so it is paid on a single PHP version; the + * behaviour under test does not depend on the version. + */ + @Test + void 'no sampling without a route, and api security telemetry metrics'() { + Assumptions.assumeTrue(phpVersion == '8.3', + 'Draining telemetry is slow; only done on one PHP version') + + // with renaming enabled, http.endpoint would be set to "/" on span close. + disableEndpointRenaming() + + try { + def trace = container.traceFromRequest('/endpoint_fallback.php?case=missing_route') { + HttpResponse resp -> + assert resp.statusCode() == 200 + } + assert trace != null + + assert trace.first().meta."http.route" == null + assert trace.first().meta."http.endpoint" == null + assert trace.first().meta."http.url" == null + assert trace.first().meta."_dd.appsec.s.res.body" == null // we did not sample + + // a route not sampled by any other test: the first request has schemas + // extracted, the second one is suppressed by the sampler + def route = '/api_security/telemetry' + 2.times { + container.traceFromRequest("/api_security.php?route=$route") { + HttpResponse resp -> + assert resp.statusCode() == 200 + } + } + + TelemetryHelpers.Metric schema + TelemetryHelpers.Metric noSchema + TelemetryHelpers.Metric missingRoute + + TelemetryHelpers.waitForMetrics(container, 30) { List messages -> + def allSeries = messages.collectMany { it.series } + schema = schema ?: allSeries.find { + it.name == 'api_security.request.schema' + } + noSchema = noSchema ?: allSeries.find { + it.name == 'api_security.request.no_schema' + } + missingRoute = missingRoute ?: allSeries.find { + it.name == 'api_security.missing_route' + } + schema && noSchema && missingRoute + } + + // counts are not exact: the requests waitForMetrics itself makes in + // order to flush the metrics are evaluated for API security too + [schema: schema, noSchema: noSchema, missingRoute: missingRoute].each { + name, metric -> + assert metric != null : "api_security metric $name not found" + assert metric.namespace == 'appsec' + assert metric.type == 'count' + assert metric.points[0][1] >= 1.0 + assert 'framework:unknown' in metric.tags + } + } finally { + resetFpm() + } + } + private AppSecContainer getContainer() { getClass().container } diff --git a/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/RoadRunnerTests.groovy b/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/RoadRunnerTests.groovy index a8a33ebac3a..40cd5c2c7ad 100644 --- a/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/RoadRunnerTests.groovy +++ b/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/RoadRunnerTests.groovy @@ -1,5 +1,6 @@ package com.datadog.appsec.php.integration +import com.datadog.appsec.php.TelemetryHelpers import com.datadog.appsec.php.docker.AppSecContainer import com.datadog.appsec.php.docker.FailOnUnmatchedTraces import com.datadog.appsec.php.docker.InspectContainerHelper @@ -57,6 +58,12 @@ class RoadRunnerTests implements WorkerStrategyTests { /** * Regression test for the AppSec helper "unexpected command RequestExec" bug: * RequestExec sent not between a request init and a request shutdown. + * + * Also covers the other half of that behaviour, RFC-1012's + * appsec.rasp.rule.skipped: a RASP evaluation that reached beyond the request must + * not merely be dropped, it must be accounted for. Asserted here rather than in a + * test of its own so that the metric is attributable to this request — any other + * test hitting this route would emit the same series. */ @Test void 'no unexpected RequestExec in outer loop after post-respond fopen'() { @@ -66,11 +73,11 @@ class RoadRunnerTests implements WorkerStrategyTests { LogFile helperLog = new LogFile(CONTAINER, 'helper.log') helperLog.markEndPos() - // PostRespondLfiHandler sets a callback that calls fopen('../etc/passwd') + // PostRespondRaspHandler sets a callback that runs RASP instrumentation // after respond() returns. By that point, request_shutdown has been sent // via the response_committed hook. If push_addresses() still reaches the // helper (socket open, active=true), it sends RequestExec into the outer loop. - CONTAINER.traceFromRequest('/post-respond-lfi') { HttpResponse resp -> + CONTAINER.traceFromRequest('/post-respond-rasp') { HttpResponse resp -> assert resp.statusCode() == 200 } @@ -88,6 +95,47 @@ class RoadRunnerTests implements WorkerStrategyTests { lines.findAll { it.contains('unexpected command') || it.contains('error in request loop') }.join('\n') + + // Draining telemetry means waiting on the metric interval (hardcoded to 10s), so + // pay it on one version only instead of on every version this class covers. The + // assertions above stay unconditional. + if (phpVersion != '8.5') { + return + } + + TelemetryHelpers.Metric lfiSkipped + TelemetryHelpers.Metric ssrfSkipped + + TelemetryHelpers.waitForMetrics(CONTAINER, 30) { List messages -> + def allSeries = messages.collectMany { it.series } + lfiSkipped = lfiSkipped ?: allSeries.find { + it.name == 'rasp.rule.skipped' && 'rule_type:lfi' in it.tags + } + ssrfSkipped = ssrfSkipped ?: allSeries.find { + it.name == 'rasp.rule.skipped' && 'rule_type:ssrf' in it.tags + } + lfiSkipped && ssrfSkipped + } + + // The handler makes exactly one push of each kind, and this is the only test + // requesting the route, so the counts are exact. + assert lfiSkipped != null : 'rasp.rule.skipped for lfi not found' + assert lfiSkipped.namespace == 'appsec' + assert lfiSkipped.type == 'count' + assert lfiSkipped.points[0][1] == 1.0 + assert 'reason:out-of-request' in lfiSkipped.tags + // LFI has no variant — tag must be absent (sidecar rejects empty tag values) + assert !lfiSkipped.tags.any { it.startsWith('rule_variant:') } + // emitted by the extension, never by the helper + assert !lfiSkipped.tags.any { it.startsWith('waf_version:') } + + assert ssrfSkipped != null : 'rasp.rule.skipped for ssrf not found' + assert ssrfSkipped.namespace == 'appsec' + assert ssrfSkipped.type == 'count' + assert ssrfSkipped.points[0][1] == 1.0 + assert 'reason:out-of-request' in ssrfSkipped.tags + assert 'rule_variant:request' in ssrfSkipped.tags + assert !ssrfSkipped.tags.any { it.startsWith('waf_version:') } } /** diff --git a/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/TelemetryTests.groovy b/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/TelemetryTests.groovy index 1f0e571b5fc..0f869ca1c18 100644 --- a/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/TelemetryTests.groovy +++ b/appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/TelemetryTests.groovy @@ -923,7 +923,9 @@ class TelemetryTests { /** * Verifies that appsec.waf.requests is tagged request_blocked:true when the WAF - * returns a block_request action and false otherwise + * returns a block_request action and false otherwise, and that block_failure:false + * is emitted alongside request_blocked:true (the PHP layer is assumed to always + * succeed at blocking, and block_failure is only emitted when a block was requested). */ @Test @Order(10) @@ -974,10 +976,14 @@ class TelemetryTests { assert wafReqBlocked.type == 'count' assert 'rule_triggered:true' in wafReqBlocked.tags assert 'request_blocked:true' in wafReqBlocked.tags + assert 'block_failure:false' in wafReqBlocked.tags : 'block_failure:false must be emitted ' + + 'alongside request_blocked:true' assert wafReqNotBlocked != null : 'waf.requests metric with request_blocked:false not found ' + '-- rust helper must emit request_blocked:false on non-blocked requests (RFC-1012)' assert 'request_blocked:false' in wafReqNotBlocked.tags + assert wafReqNotBlocked.tags.find { it.startsWith('block_failure:') } == null : + 'block_failure must not be emitted when request_blocked is false' } /** @@ -987,6 +993,9 @@ class TelemetryTests { * - rasp.duration: span metric ms × 1000 → µs must fall inside a populated bin * - rasp.duration_ext: span metric µs falls directly inside a populated bin (no conversion) * + * Also covers appsec.rasp.rule.duration, the per-libddwaf-call counterpart of + * appsec.rasp.duration, which is tagged per rule type and variant. + * * This test only applies to the Rust helper (distributions not implemented elsewhere). */ @Test @@ -1014,12 +1023,21 @@ class TelemetryTests { TelemetryHelpers.DistributionMetric raspDuration TelemetryHelpers.DistributionMetric raspDurationExt + TelemetryHelpers.DistributionMetric lfiRuleDuration + TelemetryHelpers.DistributionMetric ssrfRuleDuration TelemetryHelpers.waitForDistributions(CONTAINER, 30) { List messages -> def allSeries = messages.collectMany { it.series } raspDuration = raspDuration ?: allSeries.find { it.name == 'rasp.duration' } raspDurationExt = raspDurationExt ?: allSeries.find { it.name == 'rasp.duration_ext' } - raspDuration != null && raspDurationExt != null + lfiRuleDuration = lfiRuleDuration ?: allSeries.find { + it.name == 'rasp.rule.duration' && 'rule_type:lfi' in it.tags + } + ssrfRuleDuration = ssrfRuleDuration ?: allSeries.find { + it.name == 'rasp.rule.duration' && 'rule_type:ssrf' in it.tags + } + raspDuration != null && raspDurationExt != null && + lfiRuleDuration != null && ssrfRuleDuration != null } assert raspDuration != null : 'rasp.duration distribution metric not found' @@ -1054,6 +1072,26 @@ class TelemetryTests { assert raspDurationExt.countForBinContaining(raspDurationExtUs) != null : "span metric value ${raspDurationExtUs} µs not found in any rasp.duration_ext " + "distribution bin; distribution: ${raspDurationExt}" + + // RFC-1012 appsec.rasp.rule.duration: unlike rasp.duration, which contributes one + // cumulative observation per request, this records one observation per libddwaf call. + // /multiple_rasp.php evaluates lfi 3× and ssrf 2×, so those are the per-request minima. + assert lfiRuleDuration != null : 'rasp.rule.duration for lfi not found' + assert lfiRuleDuration.namespace == 'appsec' + assert lfiRuleDuration.tags.find { it.startsWith('waf_version:') } != null + assert lfiRuleDuration.tags.find { it.startsWith('event_rules_version:') } != null + assert lfiRuleDuration.count >= 3.0 : + "expected >= 3 lfi observations, got ${lfiRuleDuration}" + // LFI has no variant — tag must be absent (sidecar rejects empty tag values) + assert !lfiRuleDuration.tags.any { it.startsWith('rule_variant:') } + + assert ssrfRuleDuration != null : 'rasp.rule.duration for ssrf not found' + assert ssrfRuleDuration.namespace == 'appsec' + assert ssrfRuleDuration.tags.find { it.startsWith('waf_version:') } != null + assert ssrfRuleDuration.tags.find { it.startsWith('event_rules_version:') } != null + assert ssrfRuleDuration.count >= 2.0 : + "expected >= 2 ssrf observations, got ${ssrfRuleDuration}" + assert 'rule_variant:request' in ssrfRuleDuration.tags } /** diff --git a/appsec/tests/integration/src/test/www/_handlers/src/PostRespondLfiHandler.php b/appsec/tests/integration/src/test/www/_handlers/src/PostRespondLfiHandler.php deleted file mode 100644 index fd692b889f4..00000000000 --- a/appsec/tests/integration/src/test/www/_handlers/src/PostRespondLfiHandler.php +++ /dev/null @@ -1,21 +0,0 @@ - 'text/plain'], 'OK'); - } -} diff --git a/appsec/tests/integration/src/test/www/_handlers/src/PostRespondRaspHandler.php b/appsec/tests/integration/src/test/www/_handlers/src/PostRespondRaspHandler.php new file mode 100644 index 00000000000..03225d20f71 --- /dev/null +++ b/appsec/tests/integration/src/test/www/_handlers/src/PostRespondRaspHandler.php @@ -0,0 +1,29 @@ + 'text/plain'], 'OK'); + } +} diff --git a/appsec/tests/integration/src/test/www/base/public/endpoint_fallback.php b/appsec/tests/integration/src/test/www/base/public/endpoint_fallback.php index 75ab377b4b0..e6dea7b9616 100644 --- a/appsec/tests/integration/src/test/www/base/public/endpoint_fallback.php +++ b/appsec/tests/integration/src/test/www/base/public/endpoint_fallback.php @@ -68,6 +68,22 @@ ]); break; + case 'missing_route': + unset($rootSpan->meta["http.route"]); + unset($rootSpan->meta["http.endpoint"]); + unset($rootSpan->meta["http.url"]); + $rootSpan->meta["http.method"] = "GET"; + + header("Content-Type: application/json"); + http_response_code(200); + + echo json_encode([ + "status" => "ok", + "test_case" => "missing_route", + "messages" => ["test", "data"], + ]); + break; + default: header("Content-Type: application/json"); http_response_code(400); @@ -75,7 +91,7 @@ echo json_encode([ "status" => "error", "test_case" => "unknown", - "message" => "Invalid case parameter. Valid values: with_route, with_endpoint, 404, computed" + "message" => "Invalid case parameter. Valid values: with_route, with_endpoint, 404, computed, missing_route" ]); break; } diff --git a/appsec/tests/integration/src/test/www/roadrunner/worker.php b/appsec/tests/integration/src/test/www/roadrunner/worker.php index c72edadd370..2633cf48a0b 100644 --- a/appsec/tests/integration/src/test/www/roadrunner/worker.php +++ b/appsec/tests/integration/src/test/www/roadrunner/worker.php @@ -16,10 +16,12 @@ $router = new \App\Router(); $router->addRoute('/', new \App\HomePageHandler()); +// default path TelemetryHelpers uses to flush non-request-bound telemetry +$router->addRoute('/hello.php', new \App\HomePageHandler()); $router->addRoute('/json', new \App\JsonHandler()); $router->addRoute('/xml', new \App\XmlHandler()); -$router->addRoute('/post-respond-lfi', new \App\PostRespondLfiHandler()); $router->addRoute('/post-respond-track-user', new \App\PostRespondTrackUserHandler()); +$router->addRoute('/post-respond-rasp', new \App\PostRespondRaspHandler()); while ($req = $httpWorker->waitRequest()) { /** @var \Spiral\RoadRunner\Http\Request $req */