Do not use DD_TRACE_DEBUG=true by default (#3169)

conftest.py

@@ -37,6 +37,8 @@ def pytest_addoption(parser):
     )
     parser.addoption("--scenario-report", action="store_true", help="Produce a report on nodeids and their scenario")
 
+    parser.addoption("--force-dd-trace-debug", action="store_true", help="Set DD_TRACE_DEBUG to true")
+
     # Onboarding scenarios mandatory parameters
     parser.addoption("--vm-weblog", type=str, action="store", help="Set virtual machine weblog")
     parser.addoption("--vm-library", type=str, action="store", help="Set virtual machine library to test")
@@ -88,6 +90,9 @@ def pytest_addoption(parser):
 
 def pytest_configure(config):
 
+    if not config.option.force_dd_trace_debug and os.environ.get("SYSTEM_TESTS_FORCE_DD_TRACE_DEBUG") == "true":
+        config.option.force_dd_trace_debug = True
+
     # handle options that can be filled by environ
     if not config.option.report_environment and "SYSTEM_TESTS_REPORT_ENVIRONMENT" in os.environ:
         config.option.report_environment = os.environ["SYSTEM_TESTS_REPORT_ENVIRONMENT"]

docs/execute/dd-trace-debug.md

@@ -0,0 +1,19 @@
+End-to-end testing requires to have a setup as close as possible to what would be "real condition". It means that we try to not set any environment variaible that would change the library behavior if it's not what would be typically used by our customers (and if it's not what we want to tests).
+
+In consequence, DD_TRACE_DEBUG is not set. Though, it makes any debugging session hard. You can locally (or temporary in your CI) activate this by using one of those two ways :
+
+## `--force-dd-trace-debug` option
+
+By adding this option to your `./run.sh` script, you will activate debug logs in the weblog :
+
+```bash
+./run.sh <SCENARIO> --force-dd-trace-debug
+```
+
+## Using `SYSTEM_TESTS_FORCE_DD_TRACE_DEBUG` en var
+
+By setting this env var to `true`, you'll achieve the same effect. A convenient way if you want to always have this locally, is to add it to your `.env` file.
+
+```bash
+echo "SYSTEM_TESTS_FORCE_DD_TRACE_DEBUG=true" >> .env
+```

tests/appsec/test_logs.py

@@ -2,7 +2,7 @@
 # This product includes software developed at Datadog (https://www.datadoghq.com/).
 # Copyright 2021 Datadog, Inc.
 
-from utils import weblog, context, interfaces, irrelevant, missing_feature, bug, features
+from utils import weblog, context, interfaces, missing_feature, features, bug
 
 # get the default log output
 stdout = interfaces.library_stdout if context.library != "dotnet" else interfaces.library_dotnet_managed
@@ -12,69 +12,27 @@
 class Test_Standardization:
     """AppSec logs should be standardized"""
 
-    @irrelevant(library="java", reason="Cannot be implemented with cooperation from libddwaf")
-    @missing_feature(library="php")
-    def test_d01(self):
-        """Log D1: names and adresses AppSec listen to"""
-        stdout.assert_presence(r"Loaded rule:", level="DEBUG")  # TODO: should be more precise
-
-    @missing_feature(context.library < "dotnet@2.1.0")
-    @irrelevant(library="java", reason="IG doesn't push addresses in Java.")
-    def test_d02(self):
-        """Log D2: Address pushed to Instrumentation Gateway"""
-        stdout.assert_presence(r"Pushing address .* to the Instrumentation Gateway", level="DEBUG")
-
-    @missing_feature(library="dotnet", reason="APPSEC-983, being discussed")
-    @missing_feature(library="java")
-    @missing_feature(library="php", reason="Happens inside the WAF")
-    def test_d03(self):
-        """Log D3: When an address matches a rule needs"""
-        stdout.assert_presence(r"Available addresses .* match needs for rules", level="DEBUG")
-
-    @missing_feature(context.library < "dotnet@2.1.0")
-    @missing_feature(library="java")
-    def test_d04(self):
-        """Log D4: When calling the WAF, logs parameters"""
-        stdout.assert_presence(r"Executing AppSec In-App WAF with parameters:", level="DEBUG")
-
     def setup_d05(self):
         weblog.get("/waf", params={"key": "\n :"})  # rules.http_protocol_violation.crs_921_160
         weblog.get("/waf", headers={"random-key": "acunetix-user-agreement"})  # rules.security_scanner.crs_913_110
 
-    @bug(context.library == "java@0.90.0", reason="APPSEC-2190")
-    @bug(context.library == "java@0.91.0", reason="APPSEC-2190")
-    @missing_feature(context.library < "dotnet@2.1.0")
-    def test_d05(self):
-        """Log D5: WAF outputs"""
-        stdout.assert_presence(r'AppSec In-App WAF returned:.*crs-921-160"', level="DEBUG")
-        stdout.assert_presence(r'AppSec In-App WAF returned:.*crs-913-110"', level="DEBUG")
-
-    @missing_feature(library="php", reason="Would require parsing the WAF result")
-    @missing_feature(library="dotnet", reason="APPSEC-983")
-    def test_d06(self):
-        """Log D6: WAF rule detected an attack with details"""
-        stdout.assert_presence(r"Detecting an attack from rule crs-921-160:.*", level="DEBUG")
-        stdout.assert_presence(r"Detecting an attack from rule crs-913-110:.*", level="DEBUG")
-
-    @missing_feature(True, reason="not testable as now")
-    def test_d07(self):
-        """Log D7: Exception in rule"""
-        stdout.assert_presence(r"Rule .* failed. Error details: ", level="DEBUG")
-
     @missing_feature(library="php")
     @missing_feature(library="dotnet", reason="APPSEC-983, being discussed")
+    @bug(library="java", reason="APPSEC-55157")
     def test_i01(self):
         """Log I1: AppSec initial configuration"""
         stdout.assert_presence(r"AppSec initial configuration from .*, libddwaf version: \d+\.\d+\.\d+", level="INFO")
 
     @missing_feature(library="php", reason="rules are not analyzed, only converted to PWArgs")
+    @bug(library="java", reason="APPSEC-55157")
     def test_i02(self):
         """Log I2: AppSec rule source"""
         stdout.assert_presence(r"AppSec loaded \d+ rules from file .*$", level="INFO")
 
     @missing_feature(library="dotnet", reason="APPSEC-983")
     @missing_feature(context.library <= "java@0.88.0", reason="small typo")
     @missing_feature(library="php")
+    @bug(library="java", reason="APPSEC-55157")
     def test_i05(self):
         """Log I5: WAF detected an attack"""
         stdout.assert_presence(r"Detecting an attack from rule crs-921-160$", level="INFO")

utils/_context/_scenarios/__init__.py

@@ -263,7 +263,6 @@ def all_endtoend_scenarios(test_object):
         weblog_env={
             "DD_EXPERIMENTAL_API_SECURITY_ENABLED": "true",
             "DD_API_SECURITY_ENABLED": "true",
-            "DD_TRACE_DEBUG": "false",
             "DD_API_SECURITY_REQUEST_SAMPLE_RATE": "1.0",
             "DD_API_SECURITY_SAMPLE_DELAY": "0.0",
             "DD_API_SECURITY_MAX_CONCURRENT_REQUESTS": "50",
@@ -291,7 +290,6 @@ def all_endtoend_scenarios(test_object):
         weblog_env={
             "DD_EXPERIMENTAL_API_SECURITY_ENABLED": "true",
             "DD_API_SECURITY_ENABLED": "true",
-            "DD_TRACE_DEBUG": "false",
             "DD_API_SECURITY_REQUEST_SAMPLE_RATE": "1.0",
             "DD_API_SECURITY_MAX_CONCURRENT_REQUESTS": "50",
             "DD_API_SECURITY_PARSE_RESPONSE_BODY": "false",
@@ -306,11 +304,7 @@ def all_endtoend_scenarios(test_object):
     appsec_api_security_with_sampling = EndToEndScenario(
         "APPSEC_API_SECURITY_WITH_SAMPLING",
         appsec_enabled=True,
-        weblog_env={
-            "DD_EXPERIMENTAL_API_SECURITY_ENABLED": "true",
-            "DD_API_SECURITY_ENABLED": "true",
-            "DD_TRACE_DEBUG": "false",
-        },
+        weblog_env={"DD_EXPERIMENTAL_API_SECURITY_ENABLED": "true", "DD_API_SECURITY_ENABLED": "true",},
         doc="""
         Scenario for API Security feature, testing api security sampling rate.
         """,

utils/_context/_scenarios/endtoend.py

@@ -262,6 +262,9 @@ def configure(self, config):
 
         super().configure(config)
 
+        if config.option.force_dd_trace_debug:
+            self.weblog_container.environment["DD_TRACE_DEBUG"] = "true"
+
         interfaces.agent.configure(self.replay)
         interfaces.library.configure(self.replay)
         interfaces.backend.configure(self.replay)
@@ -297,7 +300,12 @@ def _get_weblog_system_info(self):
         except BaseException:
             logger.exception("can't get weblog system info")
         else:
-            logger.stdout(f"Weblog system: {message}")
+            logger.stdout(f"Weblog system: {message.strip()}")
+
+        if self.weblog_container.environment.get("DD_TRACE_DEBUG") == "true":
+            logger.stdout("\t/!\\ Debug logs are activated in weblog")
+
+        logger.stdout("")
 
     def _create_interface_folders(self):
         for interface in ("agent", "library", "backend"):

utils/_context/containers.py

@@ -715,11 +715,6 @@ def configure(self, replay):
         if self.library in ("cpp", "dotnet", "java", "python"):
             self.environment["DD_TRACE_HEADER_TAGS"] = "user-agent:http.request.headers.user-agent"
 
-            if self.library == "python":
-                # activating debug log on python causes a huge amount of logs, making the network
-                # stack fails a lot randomly
-                self.environment["DD_TRACE_DEBUG"] = "false"
-
         elif self.library in ("golang", "nodejs", "php", "ruby"):
             self.environment["DD_TRACE_HEADER_TAGS"] = "user-agent"
         else:

utils/build/docker/golang/app/internal/common/common.go

@@ -26,7 +26,7 @@ type HealtchCheck struct {
 }
 
 func init() {
-	os.Setenv("DD_TRACE_DEBUG", "true")
+	// os.Setenv("DD_TRACE_DEBUG", "true")
 }
 
 func InitDatadog() {

utils/build/docker/nodejs/nextjs.Dockerfile

@@ -24,7 +24,6 @@ ENV DD_TRACE_HEADER_TAGS=user-agent
 ENV DD_DATA_STREAMS_ENABLED=true
 ENV PORT=7777
 ENV HOSTNAME=0.0.0.0
-ENV DD_TRACE_DEBUG=true
 COPY utils/build/docker/nodejs/app.sh app.sh
 RUN printf './node_modules/.bin/next start' >> app.sh
 ENV NODE_OPTIONS="--require dd-trace/init.js"

utils/build/docker/set-system-tests-weblog-env.Dockerfile

@@ -5,7 +5,6 @@ ENV DD_SERVICE=weblog
 ENV DD_VERSION=1.0.0
 ENV DD_TAGS='key1:val1, key2 : val2 '
 ENV DD_ENV=system-tests
-ENV DD_TRACE_DEBUG=true
 ENV DD_TRACE_LOG_DIRECTORY=/var/log/system-tests
 
 ENV SOME_SECRET_ENV=leaked-env-var