Add more logging around stack generation

appsec/src/extension/backtrace.c

@@ -213,7 +213,10 @@ static PHP_FUNCTION(datadog_appsec_testing_generate_backtrace)
 
 bool dd_report_exploit_backtrace(zend_string *nullable id)
 {
+    mlog(dd_log_trace, "Generating backtrace");
     if (!get_global_DD_APPSEC_STACK_TRACE_ENABLED()) {
+        mlog(dd_log_trace, "Backtrace generation is disabled with "
+                           "DD_APPSEC_STACK_TRACE_ENABLED");
         return false;
     }
 
@@ -224,23 +227,22 @@ bool dd_report_exploit_backtrace(zend_string *nullable id)
 
     zend_object *span = dd_trace_get_active_root_span();
     if (!span) {
-        if (!get_global_DD_APPSEC_TESTING()) {
-            mlog(dd_log_warning, "Failed to retrieve root span");
-        }
+        mlog(dd_log_warning, "Failed to retrieve root span");
         return false;
     }
 
     zval *meta_struct = dd_trace_span_get_meta_struct(span);
     if (!meta_struct) {
-        if (!get_global_DD_APPSEC_TESTING()) {
-            mlog(dd_log_warning, "Failed to retrieve root span meta_struct");
-        }
+        mlog(dd_log_warning, "Failed to retrieve root span meta_struct");
         return false;
     }
 
     if (Z_TYPE_P(meta_struct) == IS_NULL) {
         array_init(meta_struct);
     } else if (Z_TYPE_P(meta_struct) != IS_ARRAY) {
+        mlog(dd_log_trace,
+            "Field 'meta_struct' is of type '%d', expected 'array'",
+            Z_TYPE_P(meta_struct));
         return false;
     }
 
@@ -253,20 +255,26 @@ bool dd_report_exploit_backtrace(zend_string *nullable id)
         exploit = zend_hash_add_new(
             Z_ARR_P(dd_stack), _exploit_key, &EG(uninitialized_zval));
         array_init(exploit);
+        mlog(dd_log_trace, "Backtrace stack created");
     } else if (Z_TYPE_P(dd_stack) != IS_ARRAY) {
+        mlog(dd_log_warning, "Field 'stack' is of type '%d', expected 'array'",
+            Z_TYPE_P(dd_stack));
         return false;
     } else {
         exploit = zend_hash_find(Z_ARR_P(dd_stack), _exploit_key);
     }
 
     if (Z_TYPE_P(exploit) != IS_ARRAY) {
+        mlog(dd_log_warning,
+            "Field 'exploit' is of type '%d', expected 'array'",
+            Z_TYPE_P(exploit));
         return false;
     }
 
     unsigned int limit = get_global_DD_APPSEC_MAX_STACK_TRACES();
     if (limit != 0 && zend_array_count(Z_ARR_P(exploit)) == limit) {
         mlog(dd_log_debug,
-            "Stacktrace not generated due to limit "
+            "Backtrace not generated due to limit "
             "DD_APPSEC_MAX_STACK_TRACES(%u) has been reached",
             limit);
         return false;
@@ -277,9 +285,13 @@ bool dd_report_exploit_backtrace(zend_string *nullable id)
 
     if (zend_hash_next_index_insert_new(Z_ARRVAL_P(exploit), &backtrace) ==
         NULL) {
+        if (!get_global_DD_APPSEC_TESTING()) {
+            mlog(dd_log_warning, "Error adding Backtrace");
+        }
         return false;
     }
 
+    mlog(dd_log_trace, "Backtrace generated");
     return true;
 }
 

appsec/src/extension/dddefs.c

@@ -14,6 +14,8 @@ const char *nonnull dd_result_to_string(dd_result result)
         return "dd_network";
     case dd_should_block:
         return "dd_should_block";
+    case dd_should_record:
+        return "dd_should_record";
     case dd_error:
         return "dd_error";
     case dd_try_later:

appsec/src/extension/ddtrace.c

@@ -448,6 +448,8 @@ void dd_trace_emit_asm_event(void)
         return;
     }
 
+    mlog(dd_log_trace, "Emitting ASM event");
+
     _ddtrace_emit_asm_event();
 }
 

appsec/src/extension/request_lifecycle.c

@@ -230,7 +230,7 @@ static zend_array *nullable _do_request_begin(
             return dd_request_abort_redirect_spec();
         }
         dd_request_abort_redirect();
-    } else if (res) {
+    } else if (res != dd_success && res != dd_should_record) {
         mlog_g(
             dd_log_info, "request init failed: %s", dd_result_to_string(res));
     }

appsec/src/helper/client.cpp

@@ -235,29 +235,43 @@ std::shared_ptr<typename T::response> client::publish(
         // NOLINTNEXTLINE(bugprone-unchecked-optional-access)
         auto res = context_->publish(std::move(command.data), rasp_rule);
         if (res) {
+            bool event_action = false;
+            bool stack_trace = false;
             for (auto &act : res->actions) {
                 dds::network::action_struct new_action;
                 switch (act.type) {
                 case dds::action_type::block:
                     new_action.verdict = network::verdict::block;
                     new_action.parameters = std::move(act.parameters);
+                    event_action = true;
                     break;
                 case dds::action_type::redirect:
                     new_action.verdict = network::verdict::redirect;
                     new_action.parameters = std::move(act.parameters);
+                    event_action = true;
                     break;
                 case dds::action_type::stack_trace:
+                    stack_trace = true;
                     new_action.verdict = network::verdict::stack_trace;
                     new_action.parameters = std::move(act.parameters);
                     break;
                 case dds::action_type::record:
                 default:
+                    event_action = true;
                     new_action.verdict = network::verdict::record;
                     new_action.parameters = {};
                     break;
                 }
                 response->actions.push_back(new_action);
             }
+            if (!event_action && stack_trace) {
+                // Stacktrace needs to send a record as well so Appsec event is
+                // generated
+                dds::network::action_struct extra_record_action;
+                extra_record_action.verdict = network::verdict::record;
+                extra_record_action.parameters = {};
+                response->actions.push_back(extra_record_action);
+            }
             response->triggers = std::move(res->events);
             response->force_keep = res->force_keep;
 

appsec/tests/helper/client_test.cpp

@@ -164,7 +164,7 @@ TEST(ClientTest, ClientInit)
     EXPECT_EQ(msg_res->metrics.size(), 2);
     // For small enough integers this comparison should work, otherwise replace
     // with EXPECT_NEAR.
-    EXPECT_EQ(msg_res->metrics[metrics::event_rules_loaded], 4.0);
+    EXPECT_EQ(msg_res->metrics[metrics::event_rules_loaded], 5.0);
     EXPECT_EQ(msg_res->metrics[metrics::event_rules_failed], 0.0);
 }
 
@@ -658,6 +658,39 @@ TEST(ClientTest, EventWithMultipleActions)
     }
 }
 
+TEST(ClientTest, StackTraceNeverComesAlone)
+{
+    auto smanager = std::make_shared<service_manager>();
+    auto broker = new mock::broker();
+
+    client c(smanager, std::unique_ptr<mock::broker>(broker));
+
+    set_extension_configuration_to(broker, c, EXTENSION_CONFIGURATION_ENABLED);
+
+    // Request Init
+    {
+        network::request_init::request msg;
+        msg.data = parameter::map();
+        msg.data.add("http.client_ip", parameter::string("192.168.1.3"sv));
+
+        network::request req(std::move(msg));
+
+        std::shared_ptr<network::base_response> res;
+        EXPECT_CALL(*broker, recv(_)).WillOnce(Return(req));
+        EXPECT_CALL(*broker,
+            send(
+                testing::An<const std::shared_ptr<network::base_response> &>()))
+            .WillOnce(DoAll(testing::SaveArg<0>(&res), Return(true)));
+
+        EXPECT_TRUE(c.run_request());
+        auto msg_res =
+            dynamic_cast<network::request_init::response *>(res.get());
+        EXPECT_EQ(msg_res->actions.size(), 2);
+        EXPECT_STREQ(msg_res->actions[0].verdict.c_str(), "stack_trace");
+        EXPECT_STREQ(msg_res->actions[1].verdict.c_str(), "record");
+    }
+}
+
 TEST(ClientTest, RequestInitUnpackError)
 {
     auto smanager = std::make_shared<service_manager>();

appsec/tests/helper/main.cpp

@@ -74,6 +74,33 @@ std::string create_sample_rules_ok()
         "extract_schema"
       ]
     },
+    {
+        "id": "blk-001-003",
+        "name": "Only stack trace",
+        "tags": {
+        "type": "block_ip",
+        "category": "security_response"
+        },
+        "conditions": [
+        {
+          "parameters": {
+            "inputs": [
+              {
+                "address": "http.client_ip"
+              }
+            ],
+            "list": [
+              "192.168.1.3"
+            ]
+          },
+          "operator": "ip_match"
+        }
+        ],
+        "transformers": [],
+        "on_match": [
+            "stack_trace"
+        ]
+    },
     {
       "id": "crs-913-110",
       "name": "Found request header associated with Acunetix security scanner",

appsec/tests/helper/service_manager_test.cpp

@@ -34,7 +34,7 @@ TEST(ServiceManagerTest, LoadRulesOK)
     auto *service_rp = service.get();
     auto metrics = service->drain_legacy_metrics();
     EXPECT_EQ(manager.get_cache().size(), 1);
-    EXPECT_EQ(metrics[metrics::event_rules_loaded], 4);
+    EXPECT_EQ(metrics[metrics::event_rules_loaded], 5);
 
     // loading again should take from the cache
     auto service2 = manager.create_service(engine_settings, {}, {});

appsec/tests/integration/src/test/groovy/com/datadog/appsec/php/integration/CommonTests.groovy

@@ -275,6 +275,39 @@ trait CommonTests {
         assert exploit.frames[2].line == 15
     }
 
+    @Test
+    void 'test stack generation without blocking'() {
+        HttpRequest req = container.buildReq('/generate_stack.php?id=stack_user_no_block').GET().build()
+        def trace = container.traceFromRequest(req, ofString()) { HttpResponse<String> re ->
+            assert re.statusCode() == 200
+        }
+
+        Span span = trace.first()
+
+        assert span.meta."appsec.event" == 'true'
+
+        InputStream stream = new ByteArrayInputStream( span.meta_struct."_dd.stack".decodeBase64() )
+        MessageUnpacker unpacker = MessagePack.newDefaultUnpacker(stream)
+        List<Object> stacks = []
+        stacks << MsgpackHelper.unpackSingle(unpacker)
+        Object exploit = stacks.first().exploit.first()
+
+        assert exploit.language == "php"
+        assert exploit.id ==~ /^[0-9a-fA-F]{8}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{12}$/
+        assert exploit.frames[0].file == "generate_stack.php"
+        assert exploit.frames[0].function == "one"
+        assert exploit.frames[0].id == 0
+        assert exploit.frames[0].line == 8
+        assert exploit.frames[1].file == "generate_stack.php"
+        assert exploit.frames[1].function == "two"
+        assert exploit.frames[1].id == 1
+        assert exploit.frames[1].line == 12
+        assert exploit.frames[2].file == "generate_stack.php"
+        assert exploit.frames[2].function == "three"
+        assert exploit.frames[2].id == 2
+        assert exploit.frames[2].line == 15
+    }
+
      static Stream<Arguments> getTestLfiData() {
             return Arrays.stream(new Arguments[]{
                     Arguments.of("file_put_contents", "/tmp/dummy", 9),

appsec/tests/integration/src/test/waf/recommended.json

@@ -55,6 +55,31 @@
         "block"
       ]
     },
+    {
+      "id": "blk-001-003",
+      "name": "Generate stack",
+      "tags": {
+        "type": "block_user",
+        "category": "security_response"
+      },
+      "conditions": [
+        {
+          "parameters": {
+            "inputs": [
+              {
+                "address": "usr.id"
+              }
+            ],
+            "data": "users_with_stack"
+          },
+          "operator": "exact_match"
+        }
+      ],
+      "transformers": [],
+      "on_match": [
+        "stack_trace"
+      ]
+    },
     {
       "id": "rasp-001-001",
       "name": "Path traversal attack",
@@ -134,7 +159,7 @@
       ]
     },
     {
-      "id": "blk-001-003",
+      "id": "blk-001-004",
       "name": "Block User Addresses",
       "tags": {
         "type": "block_user",
@@ -6952,7 +6977,16 @@
         }
       ]
     },
-
+    {
+      "id": "users_with_stack",
+      "type": "data_with_expiration",
+      "data": [
+        {
+          "value": "stack_user_no_block",
+          "expiration": 0
+        }
+      ]
+    },
     {
       "id": "redirected_users",
       "type": "data_with_expiration",