chore(iast): django Invalid or empty source_value (#10816)

Fix telemetry log error: "ValueError: [IAST] Invalid or empty
source_value."

No release note needed, as this error occurs after this PR
#10740 that has not been
released yet

Task APPSEC-55017

## Checklist
- [x] PR author has checked that all the criteria below are met
- The PR description includes an overview of the change
- The PR description articulates the motivation for the change
- The change includes tests OR the PR description describes a testing
strategy
- The PR description notes risks associated with the change, if any
- Newly-added code is easy to change
- The change follows the [library release note
guidelines](https://ddtrace.readthedocs.io/en/stable/releasenotes.html)
- The change includes or references documentation updates if necessary
- Backport labels are set (if
[applicable](https://ddtrace.readthedocs.io/en/latest/contributing.html#backporting))

## Reviewer Checklist
- [x] Reviewer has checked that all the criteria below are met 
- Title is accurate
- All changes are related to the pull request's stated goal
- Avoids breaking
[API](https://ddtrace.readthedocs.io/en/stable/versioning.html#interfaces)
changes
- Testing strategy adequately addresses listed risks
- Newly-added code is easy to change
- Release note makes sense to a user of the library
- If necessary, author has acknowledged and discussed the performance
implications of this PR as reported in the benchmarks PR comment
- Backport labels are set in a manner that is consistent with the
[release branch maintenance
policy](https://ddtrace.readthedocs.io/en/latest/contributing.html#backporting)

.gitlab/tests/appsec.yml

@@ -15,6 +15,7 @@ appsec iast:
     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,7 +301,11 @@ 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 getattr(http_req, "_body", None) is not None and not is_pyobject_tainted(getattr(http_req, "_body", None)):
+        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,
@@ -311,7 +315,11 @@ def _on_django_func_wrapped(fn_args, fn_kwargs, first_arg_expected_type, *_):
                 )
             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 not is_pyobject_tainted(getattr(http_req, "body", None)):
+        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,

ddtrace/appsec/_iast/_metrics.py

@@ -67,7 +67,7 @@ def _set_iast_error_metric(msg: Text) -> None:
             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))
+            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)

ddtrace/appsec/_iast/_taint_tracking/__init__.py

@@ -203,16 +203,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

@@ -185,36 +185,41 @@ 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_format_key_error_and_no_log_metric raises")
+        _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_format_key_error_and_no_log_metric raises"
+        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_format_key_error_and_no_log_metric raises")
+            _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_format_key_error_and_no_log_metric raises"
+        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):

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),

tests/contrib/django/test_django_appsec_iast.py

@@ -24,17 +24,17 @@
 
 @pytest.fixture(autouse=True)
 def reset_context():
-    with override_env({"DD_IAST_ENABLED": "True"}):
+    with override_env({IAST.ENV: "True"}):
         from ddtrace.appsec._iast._taint_tracking import create_context
         from ddtrace.appsec._iast._taint_tracking import reset_context
 
+        _ = create_context()
         yield
         reset_context()
-        _ = create_context()
 
 
 @pytest.fixture(autouse=True)
-def check_native_code_exception_in_each_python_aspect_test(request, caplog):
+def check_native_code_exception_in_each_django_test(request, caplog, telemetry_writer):
     if "skip_iast_check_logs" in request.keywords:
         yield
     else:
@@ -43,7 +43,11 @@ def check_native_code_exception_in_each_python_aspect_test(request, caplog):
             yield
 
         log_messages = [record.message for record in caplog.get_records("call")]
-        assert not any("[IAST] " in message for message in log_messages), log_messages
+        for message in log_messages:
+            if "[IAST] " in message:
+                pytest.fail(message)
+        list_metrics_logs = list(telemetry_writer._logs)
+        assert len(list_metrics_logs) == 0
 
 
 def _aux_appsec_get_root_span(
@@ -77,6 +81,31 @@ def _aux_appsec_get_root_span(
     return test_spans.spans[0], response
 
 
+def _aux_appsec_get_root_span_with_exception(
+    client,
+    test_spans,
+    tracer,
+    payload=None,
+    url="/",
+    content_type="text/plain",
+    headers=None,
+    cookies=None,
+):
+    try:
+        return _aux_appsec_get_root_span(
+            client,
+            test_spans,
+            tracer,
+            payload=payload,
+            url=url,
+            content_type=content_type,
+            headers=headers,
+            cookies=cookies,
+        )
+    except Exception:
+        return False
+
+
 @pytest.mark.skipif(not python_supported_by_iast(), reason="Python version not supported by IAST")
 def test_django_weak_hash(client, test_spans, tracer):
     with override_global_config(dict(_asm_enabled=True, _iast_enabled=True, _deduplication_enabled=False)):
@@ -107,6 +136,46 @@ def test_django_tainted_user_agent_iast_enabled(client, test_spans, tracer):
         assert response.content == b"test/1.2.3"
 
 
+@pytest.mark.parametrize(
+    ("payload", "content_type"),
+    [
+        ("master", "application/json"),
+        ("master", "text/plain"),
+        ("", "plain"),
+        ('{"json": "body"}', "plain"),
+    ],
+)
+@pytest.mark.parametrize(
+    ("deduplication"),
+    [
+        True,
+        False,
+    ],
+)
+@pytest.mark.parametrize(
+    "sampling",
+    [
+        "0",
+        "100",
+        "50",
+    ],
+)
+@pytest.mark.skipif(not python_supported_by_iast(), reason="Python version not supported by IAST")
+def test_django_view_with_exception(client, test_spans, tracer, payload, content_type, deduplication, sampling):
+    with override_global_config(dict(_iast_enabled=True, _deduplication_enabled=deduplication)), override_env(
+        {"DD_IAST_REQUEST_SAMPLING": sampling}
+    ):
+        response = _aux_appsec_get_root_span_with_exception(
+            client,
+            test_spans,
+            tracer,
+            content_type=content_type,
+            url="/appsec/view_with_exception/?q=" + payload,
+        )
+
+        assert response is False
+
+
 @pytest.mark.skipif(not python_supported_by_iast(), reason="Python version not supported by IAST")
 def test_django_tainted_user_agent_iast_disabled(client, test_spans, tracer):
     with override_global_config(dict(_iast_enabled=False, _deduplication_enabled=False)):
@@ -502,6 +571,49 @@ def test_django_tainted_user_agent_iast_enabled_sqli_http_body(client, test_span
         assert response.content == b"master"
 
 
+@pytest.mark.parametrize(
+    ("payload", "content_type"),
+    [
+        ("", "application/json"),
+        ("", "text/plain"),
+        ("", "application/x-www-form-urlencoded"),
+    ],
+)
+@pytest.mark.parametrize(
+    ("deduplication"),
+    [
+        True,
+        False,
+    ],
+)
+@pytest.mark.parametrize(
+    "sampling",
+    [
+        "0",
+        "100",
+        "50",
+    ],
+)
+@pytest.mark.django_db()
+@pytest.mark.skipif(not python_supported_by_iast(), reason="Python version not supported by IAST")
+def test_django_tainted_http_body_empty(client, test_spans, tracer, payload, content_type, deduplication, sampling):
+    with override_global_config(dict(_iast_enabled=True, _deduplication_enabled=deduplication)), override_env(
+        {"DD_IAST_REQUEST_SAMPLING": sampling}
+    ):
+        root_span, response = _aux_appsec_get_root_span(
+            client,
+            test_spans,
+            tracer,
+            url="/appsec/source/body/",
+            payload=payload,
+            content_type=content_type,
+        )
+        assert root_span.get_tag(IAST.JSON) is None
+
+        assert response.status_code == 200
+        assert response.content == b""
+
+
 @pytest.mark.django_db()
 @pytest.mark.skipif(not python_supported_by_iast(), reason="Python version not supported by IAST")
 def test_django_tainted_iast_disabled_sqli_http_body(client, test_spans, tracer):

tests/contrib/fastapi/test_fastapi_appsec_iast.py

@@ -1,4 +1,5 @@
 import json
+import logging
 import sys
 import typing
 
@@ -43,6 +44,23 @@ def get_response_body(response):
     return response.text
 
 
+@pytest.fixture(autouse=True)
+def check_native_code_exception_in_each_fastapi_test(request, caplog, telemetry_writer):
+    if "skip_iast_check_logs" in request.keywords:
+        yield
+    else:
+        caplog.set_level(logging.DEBUG)
+        with override_env({IAST.ENV_DEBUG: "true"}), caplog.at_level(logging.DEBUG):
+            yield
+
+        log_messages = [record.msg for record in caplog.get_records("call")]
+        for message in log_messages:
+            if "[IAST] " in message:
+                pytest.fail(message)
+        list_metrics_logs = list(telemetry_writer._logs)
+        assert len(list_metrics_logs) == 0
+
+
 def test_query_param_source(fastapi_application, client, tracer, test_spans):
     @fastapi_application.get("/index.html")
     async def test_route(request: Request):