chore(iast): django Invalid or empty source_value [backport 2.13]

.gitlab/tests/appsec.yml

@@ -18,6 +18,8 @@ appsec iast:
   variables:
     SUITE_NAME: "appsec_iast$"
     TEST_POSTGRES_HOST: "postgres"
+  retry: 2
+  timeout: 25m
 
 appsec iast tdd_propagation:
   extends: .test_base_riot_snapshot

ddtrace/appsec/_handlers.py

@@ -301,13 +301,35 @@ def _on_django_func_wrapped(fn_args, fn_kwargs, first_arg_expected_type, *_):
         http_req.COOKIES = taint_structure(http_req.COOKIES, OriginType.COOKIE_NAME, OriginType.COOKIE)
         http_req.GET = taint_structure(http_req.GET, OriginType.PARAMETER_NAME, OriginType.PARAMETER)
         http_req.POST = taint_structure(http_req.POST, OriginType.BODY, OriginType.BODY)
-        if not is_pyobject_tainted(getattr(http_req, "_body", None)):
-            http_req._body = taint_pyobject(
-                http_req.body,
-                source_name=origin_to_str(OriginType.BODY),
-                source_value=http_req.body,
-                source_origin=OriginType.BODY,
-            )
+
+        if (
+            getattr(http_req, "_body", None) is not None
+            and len(getattr(http_req, "_body", None)) > 0
+            and not is_pyobject_tainted(getattr(http_req, "_body", None))
+        ):
+            try:
+                http_req._body = taint_pyobject(
+                    http_req._body,
+                    source_name=origin_to_str(OriginType.BODY),
+                    source_value=http_req._body,
+                    source_origin=OriginType.BODY,
+                )
+            except AttributeError:
+                log.debug("IAST can't set attribute http_req._body", exc_info=True)
+        elif (
+            getattr(http_req, "body", None) is not None
+            and len(getattr(http_req, "body", None)) > 0
+            and not is_pyobject_tainted(getattr(http_req, "body", None))
+        ):
+            try:
+                http_req.body = taint_pyobject(
+                    http_req.body,
+                    source_name=origin_to_str(OriginType.BODY),
+                    source_value=http_req.body,
+                    source_origin=OriginType.BODY,
+                )
+            except AttributeError:
+                log.debug("IAST can't set attribute http_req.body", exc_info=True)
 
         http_req.headers = taint_structure(http_req.headers, OriginType.HEADER_NAME, OriginType.HEADER)
         http_req.path = taint_pyobject(

ddtrace/appsec/_iast/_metrics.py

@@ -7,6 +7,7 @@
 from ddtrace.appsec._constants import IAST
 from ddtrace.appsec._constants import IAST_SPAN_TAGS
 from ddtrace.appsec._deduplications import deduplication
+from ddtrace.appsec._iast._utils import _is_iast_debug_enabled
 from ddtrace.internal import telemetry
 from ddtrace.internal.logger import get_logger
 from ddtrace.internal.telemetry.constants import TELEMETRY_LOG_LEVEL
@@ -61,16 +62,18 @@ def wrapper(f):
 def _set_iast_error_metric(msg: Text) -> None:
     # Due to format_exc and format_exception returns the error and the last frame
     try:
-        exception_type, exception_instance, _traceback_list = sys.exc_info()
-        res = []
-        # first 10 frames are this function, the exception in aspects and the error line
-        res.extend(traceback.format_stack(limit=10))
+        stack_trace = ""
+        if _is_iast_debug_enabled():
+            exception_type, exception_instance, _traceback_list = sys.exc_info()
+            res = []
+            # first 10 frames are this function, the exception in aspects and the error line
+            res.extend(traceback.format_stack(limit=20))
+
+            # get the frame with the error and the error message
+            result = traceback.format_exception(exception_type, exception_instance, _traceback_list)
+            res.extend(result[1:])
+            stack_trace = "".join(res)
 
-        # get the frame with the error and the error message
-        result = traceback.format_exception(exception_type, exception_instance, _traceback_list)
-        res.extend(result[1:])
-
-        stack_trace = "".join(res)
         tags = {
             "lib_language": "python",
         }

ddtrace/appsec/_iast/_taint_tracking/__init__.py

@@ -206,16 +206,18 @@ def trace_calls_and_returns(frame, event, arg):
             return
         if event == "call":
             f_locals = frame.f_locals
-            if any([is_pyobject_tainted(f_locals[arg]) for arg in f_locals]):
-                TAINTED_FRAMES.append(frame)
-                log.debug("Call to %s on line %s of %s, args: %s", func_name, line_no, filename, frame.f_locals)
-                log.debug("Tainted arguments:")
-                for arg in f_locals:
-                    if is_pyobject_tainted(f_locals[arg]):
-                        log.debug("\t%s: %s", arg, f_locals[arg])
-                log.debug("-----")
-
-            return trace_calls_and_returns
+            try:
+                if any([is_pyobject_tainted(f_locals[arg]) for arg in f_locals]):
+                    TAINTED_FRAMES.append(frame)
+                    log.debug("Call to %s on line %s of %s, args: %s", func_name, line_no, filename, frame.f_locals)
+                    log.debug("Tainted arguments:")
+                    for arg in f_locals:
+                        if is_pyobject_tainted(f_locals[arg]):
+                            log.debug("\t%s: %s", arg, f_locals[arg])
+                    log.debug("-----")
+                return trace_calls_and_returns
+            except AttributeError:
+                pass
         elif event == "return":
             if frame in TAINTED_FRAMES:
                 TAINTED_FRAMES.remove(frame)

tests/appsec/iast/conftest.py

@@ -182,3 +182,6 @@ def check_native_code_exception_in_each_python_aspect_test(request, caplog):
 
         log_messages = [record.message for record in caplog.get_records("call")]
         assert not any("[IAST] " in message for message in log_messages), log_messages
+        # TODO(avara1986): iast tests throw a timeout in gitlab
+        #   list_metrics_logs = list(telemetry_writer._logs)
+        #   assert len(list_metrics_logs) == 0

tests/appsec/iast/test_processor.py

@@ -26,7 +26,12 @@ def traced_function(tracer):
     return span
 
 
+@pytest.mark.skip_iast_check_logs
 def test_appsec_iast_processor():
+    """
+    test_appsec_iast_processor.
+    This test throws  'finished span not connected to a trace' log error
+    """
     with override_global_config(dict(_iast_enabled=True)):
         patch_iast()
 
@@ -42,8 +47,13 @@ def test_appsec_iast_processor():
         assert len(json.loads(result)["vulnerabilities"]) == 1
 
 
+@pytest.mark.skip_iast_check_logs
 @pytest.mark.parametrize("sampling_rate", ["0.0", "0.5", "1.0"])
 def test_appsec_iast_processor_ensure_span_is_manual_keep(sampling_rate):
+    """
+    test_appsec_iast_processor_ensure_span_is_manual_keep.
+    This test throws  'finished span not connected to a trace' log error
+    """
     with override_env(dict(DD_TRACE_SAMPLE_RATE=sampling_rate)), override_global_config(dict(_iast_enabled=True)):
         patch_iast()
 

tests/appsec/iast/test_telemetry.py

@@ -3,6 +3,7 @@
 from ddtrace.appsec import _asm_request_context
 from ddtrace.appsec._common_module_patches import patch_common_modules
 from ddtrace.appsec._common_module_patches import unpatch_common_modules
+from ddtrace.appsec._constants import IAST
 from ddtrace.appsec._constants import IAST_SPAN_TAGS
 from ddtrace.appsec._handlers import _on_django_patch
 from ddtrace.appsec._iast._metrics import TELEMETRY_DEBUG_VERBOSITY
@@ -184,15 +185,52 @@ def test_metric_request_tainted(no_request_sampling, telemetry_writer):
     assert span.get_metric(IAST_SPAN_TAGS.TELEMETRY_REQUEST_TAINTED) > 0
 
 
+@pytest.mark.skip_iast_check_logs
 def test_log_metric(telemetry_writer):
-    _set_iast_error_metric("test_format_key_error_and_no_log_metric raises")
+    with override_env({IAST.ENV_DEBUG: "true"}):
+        _set_iast_error_metric("test_format_key_error_and_no_log_metric raises")
 
     list_metrics_logs = list(telemetry_writer._logs)
     assert len(list_metrics_logs) == 1
     assert list_metrics_logs[0]["message"] == "test_format_key_error_and_no_log_metric raises"
     assert str(list_metrics_logs[0]["stack_trace"]).startswith('  File "/')
 
 
+@pytest.mark.skip_iast_check_logs
+def test_log_metric_debug_disabled(telemetry_writer):
+    with override_env({IAST.ENV_DEBUG: "false"}):
+        _set_iast_error_metric("test_log_metric_debug_disabled raises")
+
+        list_metrics_logs = list(telemetry_writer._logs)
+        assert len(list_metrics_logs) == 1
+        assert list_metrics_logs[0]["message"] == "test_log_metric_debug_disabled raises"
+        assert "stack_trace" not in list_metrics_logs[0].keys()
+
+
+@pytest.mark.skip_iast_check_logs
+def test_log_metric_debug_disabled_deduplication(telemetry_writer):
+    with override_env({IAST.ENV_DEBUG: "false"}):
+        for i in range(10):
+            _set_iast_error_metric("test_log_metric_debug_disabled_deduplication raises")
+
+        list_metrics_logs = list(telemetry_writer._logs)
+        assert len(list_metrics_logs) == 1
+        assert list_metrics_logs[0]["message"] == "test_log_metric_debug_disabled_deduplication raises"
+        assert "stack_trace" not in list_metrics_logs[0].keys()
+
+
+@pytest.mark.skip_iast_check_logs
+def test_log_metric_debug_disabled_deduplication_different_messages(telemetry_writer):
+    with override_env({IAST.ENV_DEBUG: "false"}):
+        for i in range(10):
+            _set_iast_error_metric(f"test_format_key_error_and_no_log_metric raises {i}")
+
+        list_metrics_logs = list(telemetry_writer._logs)
+        assert len(list_metrics_logs) == 10
+        assert list_metrics_logs[0]["message"].startswith("test_format_key_error_and_no_log_metric raises")
+        assert "stack_trace" not in list_metrics_logs[0].keys()
+
+
 def test_django_instrumented_metrics(telemetry_writer):
     with override_global_config(dict(_iast_enabled=True)):
         _on_django_patch()

tests/contrib/django/django_app/appsec_urls.py

@@ -210,6 +210,24 @@ def sqli_http_request_body(request):
     return HttpResponse(value, status=200)
 
 
+def source_body_view(request):
+    value = decode_aspect(bytes.decode, 1, request.body)
+    with connection.cursor() as cursor:
+        # label source_body_view
+        cursor.execute(add_aspect("SELECT 1 FROM sqlite_master WHERE type='1'", value))
+    return HttpResponse(value, status=200)
+
+
+def view_with_exception(request):
+    value = request.GET["q"]
+    from time import sleep_not_exists  # noqa:F401
+
+    with connection.cursor() as cursor:
+        # label value
+        cursor.execute(value)
+    return HttpResponse(value, status=200)
+
+
 def view_insecure_cookies_insecure(request):
     res = HttpResponse("OK")
     res.set_cookie("insecure", "cookie", secure=False, httponly=True, samesite="Strict")
@@ -272,6 +290,7 @@ def validate_querydict(request):
 urlpatterns = [
     handler("response-header/$", magic_header_key, name="response-header"),
     handler("body/$", body_view, name="body_view"),
+    handler("view_with_exception/$", view_with_exception, name="view_with_exception"),
     handler("weak-hash/$", weak_hash_view, name="weak_hash"),
     handler("block/$", block_callable_view, name="block"),
     handler("command-injection/$", command_injection, name="command_injection"),
@@ -284,6 +303,7 @@ def validate_querydict(request):
     handler("sqli_http_request_cookie_name/$", sqli_http_request_cookie_name, name="sqli_http_request_cookie_name"),
     handler("sqli_http_request_cookie_value/$", sqli_http_request_cookie_value, name="sqli_http_request_cookie_value"),
     handler("sqli_http_request_body/$", sqli_http_request_body, name="sqli_http_request_body"),
+    handler("source/body/$", source_body_view, name="source_body"),
     handler("insecure-cookie/test_insecure_2_1/$", view_insecure_cookies_two_insecure_one_secure),
     handler("insecure-cookie/test_insecure_special/$", view_insecure_cookies_insecure_special_chars),
     handler("insecure-cookie/test_insecure/$", view_insecure_cookies_insecure),