chore(logging): remove DD_CALL_BASIC_CONFIG

ddtrace/_logger.py

@@ -5,6 +5,11 @@
 from ddtrace.internal.utils.formats import asbool
 
 
+DD_LOG_FORMAT = "%(asctime)s %(levelname)s [%(name)s] [%(filename)s:%(lineno)d] {}- %(message)s".format(
+    "[dd.service=%(dd.service)s dd.env=%(dd.env)s dd.version=%(dd.version)s"
+    " dd.trace_id=%(dd.trace_id)s dd.span_id=%(dd.span_id)s] "
+)
+
 DEFAULT_FILE_SIZE_BYTES = 15 << 20  # 15 MB
 
 
@@ -32,14 +37,18 @@ def configure_ddtrace_logger():
 
     """
     ddtrace_logger = logging.getLogger("ddtrace")
-
     _configure_ddtrace_debug_logger(ddtrace_logger)
     _configure_ddtrace_file_logger(ddtrace_logger)
 
 
 def _configure_ddtrace_debug_logger(logger):
     debug_enabled = asbool(os.environ.get("DD_TRACE_DEBUG", "false"))
-    if debug_enabled:
+    logs_injection_enabled = asbool(os.environ.get("DD_LOGS_INJECTION", "false"))
+
+    # Logs injection enabled requires a handler present on ddtrace
+    if debug_enabled or logs_injection_enabled:
+        if not os.environ.get("DD_TRACE_LOG_FILE"):
+            logger.addHandler(logging.StreamHandler())
         logger.setLevel(logging.DEBUG)
         logger.debug("debug mode has been enabled for the ddtrace logger")
 
@@ -62,11 +71,21 @@ def _configure_ddtrace_file_logger(logger):
         ddtrace_file_handler = RotatingFileHandler(
             filename=log_path, mode="a", maxBytes=max_file_bytes, backupCount=num_backup
         )
-
         log_format = "%(asctime)s %(levelname)s [%(name)s] [%(filename)s:%(lineno)d] - %(message)s"
         log_formatter = logging.Formatter(log_format)
-
         ddtrace_file_handler.setLevel(file_log_level_value)
         ddtrace_file_handler.setFormatter(log_formatter)
         logger.addHandler(ddtrace_file_handler)
         logger.debug("ddtrace logs will be routed to %s", log_path)
+
+
+def _configure_log_injection():
+    """
+    Ensures that logging is patched before we inject trace information into logs.
+    """
+    from ddtrace import patch
+
+    patch(logging=True)
+    ddtrace_logger = logging.getLogger("ddtrace")
+    if ddtrace_logger.hasHandlers():
+        ddtrace_logger.handlers[0].setFormatter(logging.Formatter(DD_LOG_FORMAT))

ddtrace/bootstrap/sitecustomize.py

@@ -10,6 +10,7 @@
 import warnings  # noqa
 
 from ddtrace import config  # noqa
+from ddtrace._logger import _configure_log_injection
 from ddtrace.debugging._config import di_config  # noqa
 from ddtrace.debugging._config import ed_config  # noqa
 from ddtrace.internal.compat import PY2  # noqa
@@ -19,32 +20,12 @@
 from ddtrace.internal.runtime.runtime_metrics import RuntimeWorker  # noqa
 from ddtrace.internal.utils.formats import asbool  # noqa
 from ddtrace.internal.utils.formats import parse_tags_str  # noqa
-from ddtrace.tracer import DD_LOG_FORMAT  # noqa
-from ddtrace.vendor.debtcollector import deprecate  # noqa
 
 
-if config.logs_injection:
-    # immediately patch logging if trace id injected
-    from ddtrace import patch
+# Debug mode from the tracer will do the same here, so only need to do this otherwise.
+if not config._debug_mode and config.logs_injection:
+    _configure_log_injection()
 
-    patch(logging=True)
-
-
-# DEV: Once basicConfig is called here, future calls to it cannot be used to
-# change the formatter since it applies the formatter to the root handler only
-# upon initializing it the first time.
-# See https://github.com/python/cpython/blob/112e4afd582515fcdcc0cde5012a4866e5cfda12/Lib/logging/__init__.py#L1550
-# Debug mode from the tracer will do a basicConfig so only need to do this otherwise
-if not config._debug_mode and config._call_basic_config:
-    deprecate(
-        "ddtrace.tracer.logging.basicConfig",
-        message="`logging.basicConfig()` should be called in a user's application.",
-        removal_version="2.0.0",
-    )
-    if config.logs_injection:
-        logging.basicConfig(format=DD_LOG_FORMAT)
-    else:
-        logging.basicConfig()
 
 log = get_logger(__name__)
 

ddtrace/internal/telemetry/constants.py

@@ -20,7 +20,6 @@
 
 TELEMETRY_TRACE_DEBUG = "DD_TRACE_DEBUG"
 TELEMETRY_ANALYTICS_ENABLED = "DD_TRACE_ANALYTICS_ENABLED"
-TELEMETRY_CALL_BASIC_CONFIG = "DD_CALL_BASIC_CONFIG"
 TELEMETRY_CLIENT_IP_ENABLED = "DD_TRACE_CLIENT_IP_ENABLED"
 TELEMETRY_LOGS_INJECTION_ENABLED = "DD_LOGS_INJECTION"
 TELEMETRY_128_BIT_TRACEID_GENERATION_ENABLED = "DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED"

ddtrace/internal/telemetry/writer.py

@@ -34,7 +34,6 @@
 from .constants import TELEMETRY_128_BIT_TRACEID_LOGGING_ENABLED
 from .constants import TELEMETRY_ANALYTICS_ENABLED
 from .constants import TELEMETRY_ASM_ENABLED
-from .constants import TELEMETRY_CALL_BASIC_CONFIG
 from .constants import TELEMETRY_CLIENT_IP_ENABLED
 from .constants import TELEMETRY_DSM_ENABLED
 from .constants import TELEMETRY_DYNAMIC_INSTRUMENTATION_ENABLED
@@ -283,7 +282,6 @@ def _app_started_event(self):
         self.add_configurations(
             [
                 (TELEMETRY_TRACING_ENABLED, config._tracing_enabled, "unknown"),
-                (TELEMETRY_CALL_BASIC_CONFIG, config._call_basic_config, "unknown"),
                 (TELEMETRY_DSM_ENABLED, config._data_streams_enabled, "unknown"),
                 (TELEMETRY_ASM_ENABLED, config._appsec_enabled, "unknown"),
                 (TELEMETRY_PROFILING_ENABLED, profiling_config.enabled, "unknown"),

ddtrace/settings/config.py

@@ -184,7 +184,6 @@ def __init__(self):
         self._config = {}
 
         self._debug_mode = asbool(os.getenv("DD_TRACE_DEBUG", default=False))
-        self._call_basic_config = asbool(os.environ.get("DD_CALL_BASIC_CONFIG", "false"))
 
         header_tags = parse_tags_str(os.getenv("DD_TRACE_HEADER_TAGS", ""))
         self.http = HttpConfig(header_tags=header_tags)

ddtrace/tracer.py

@@ -15,10 +15,9 @@
 from ddtrace.internal.sampling import SpanSamplingRule
 from ddtrace.internal.sampling import get_span_sampling_rules
 from ddtrace.settings.peer_service import PeerServiceConfig
-from ddtrace.vendor import debtcollector
 
 from . import _hooks
-from ._monkey import patch
+from ._logger import _configure_log_injection
 from .constants import AUTO_KEEP
 from .constants import AUTO_REJECT
 from .constants import ENV_KEY
@@ -81,22 +80,9 @@
 log = get_logger(__name__)
 
 
-DD_LOG_FORMAT = "%(asctime)s %(levelname)s [%(name)s] [%(filename)s:%(lineno)d] {}- %(message)s".format(
-    "[dd.service=%(dd.service)s dd.env=%(dd.env)s dd.version=%(dd.version)s"
-    " dd.trace_id=%(dd.trace_id)s dd.span_id=%(dd.span_id)s] "
-)
-if config._debug_mode and not hasHandlers(log) and config._call_basic_config:
-    debtcollector.deprecate(
-        "ddtrace.tracer.logging.basicConfig",
-        message="`logging.basicConfig()` should be called in a user's application.",
-        removal_version="2.0.0",
-    )
-    if config.logs_injection:
-        # We need to ensure logging is patched in case the tracer logs during initialization
-        patch(logging=True)
-        logging.basicConfig(level=logging.DEBUG, format=DD_LOG_FORMAT)
-    else:
-        logging.basicConfig(level=logging.DEBUG)
+if config._debug_mode and config.logs_injection:
+    # We need to ensure logging is patched in case the tracer logs during initialization
+    _configure_log_injection()
 
 
 _INTERNAL_APPLICATION_SPAN_TYPES = {"custom", "template", "web", "worker"}

docs/configuration.rst

@@ -87,7 +87,7 @@ The following environment variables for the tracer are supported:
      type: Boolean
      default: False
      description: |
-         Enables debug logging in the tracer. Setting this flag will cause the library to create a root logging handler if one does not already exist.
+         Enables debug logging in the tracer.
 
          Can be used with `DD_TRACE_LOG_FILE` to route logs to a file.
      version_added:
@@ -136,11 +136,6 @@ The following environment variables for the tracer are supported:
      default: False
      description: Enables :ref:`Logs Injection`.
 
-   DD_CALL_BASIC_CONFIG:
-     type: Boolean
-     default: False
-     description: Controls whether ``logging.basicConfig`` is called in ``ddtrace-run`` or when debug mode is enabled.
-
    DD_AGENT_HOST:
      type: String
      default: |

lib-injection/docker-compose.yml

@@ -45,6 +45,5 @@ services:
       - PYTHONPATH=/datadog-lib
       - DD_TRACE_AGENT_URL=http://testagent:8126
       - DD_TRACE_DEBUG=1
-      - DD_CALL_BASIC_CONFIG=1
     volumes:
       - ${TEMP_DIR:-/tmp/ddtrace_test}:/datadog-lib

releasenotes/notes/remove-deprecated-items-2.0-89eac06472c59554.yaml

@@ -89,4 +89,22 @@ upgrade:
     ``ddtrace.filters.TraceCiVisibilityFilter`` is removed.
 
 
+    "
+  - ".. _remove-dd-log-format:
+
+
+    ``ddtrace.tracer.DD_LOG_FORMAT`` is removed.
+    As an alternative, please follow the log injection formatting as provided in the
+    `log injection docs <https://ddtrace.readthedocs.io/en/stable/advanced_usage.html#update-log-format>`_.
+
+
+    "
+  - ".. _remove-basic-config:
+
+
+    ``DD_CALL_BASIC_CONFIG`` is removed.
+    There is no special configuration necessary to replace ``DD_CALL_BASIC_CONFIG``.
+    The ddtrace logger will log to standard out by default or to a file specified by ``DD_TRACE_LOG_FILE``.
+
+
     "

tests/commands/ddtrace_run_logs_injection.py

@@ -3,14 +3,15 @@
 
 if __name__ == "__main__":
     # Ensure if module is patched then default log formatter is set up for logs
+    ddtrace_logger = logging.getLogger("ddtrace")
     if getattr(logging, "_datadog_patch"):
         assert (
             "[dd.service=%(dd.service)s dd.env=%(dd.env)s dd.version=%(dd.version)s"
-            " dd.trace_id=%(dd.trace_id)s dd.span_id=%(dd.span_id)s]" in logging.root.handlers[0].formatter._fmt
+            " dd.trace_id=%(dd.trace_id)s dd.span_id=%(dd.span_id)s]" in ddtrace_logger.handlers[0].formatter._fmt
         )
     else:
         assert (
             "[dd.service=%(dd.service)s dd.env=%(dd.env)s dd.version=%(dd.version)s"
-            " dd.trace_id=%(dd.trace_id)s dd.span_id=%(dd.span_id)s]" not in logging.root.handlers[0].formatter._fmt
+            " dd.trace_id=%(dd.trace_id)s dd.span_id=%(dd.span_id)s]" not in ddtrace_logger.handlers[0].formatter._fmt
         )
     print("Test success")

tests/commands/test_runner.py

@@ -74,7 +74,7 @@ def test_debug_enabling(self):
             assert b"Test success" in out
             assert b"DATADOG TRACER CONFIGURATION" not in out
 
-        with self.override_env(dict(DD_TRACE_DEBUG="true", DD_CALL_BASIC_CONFIG="true")):
+        with self.override_env(dict(DD_TRACE_DEBUG="true")):
             out = subprocess.check_output(
                 ["ddtrace-run", "python", "tests/commands/ddtrace_run_debug.py"],
                 stderr=subprocess.STDOUT,
@@ -223,22 +223,21 @@ def test_global_trace_tags(self):
 
     def test_logs_injection(self):
         """Ensure logs injection works"""
-        with self.override_env(dict(DD_LOGS_INJECTION="true", DD_CALL_BASIC_CONFIG="true")):
+        with self.override_env(dict(DD_LOGS_INJECTION="true")):
             out = subprocess.check_output(["ddtrace-run", "python", "tests/commands/ddtrace_run_logs_injection.py"])
             assert out.startswith(b"Test success"), out.decode()
 
     def test_debug_mode(self):
-        with self.override_env(dict(DD_CALL_BASIC_CONFIG="true")):
-            p = subprocess.Popen(
-                ["ddtrace-run", "--debug", "python", "-c", "''"],
-                stdout=subprocess.PIPE,
-                stderr=subprocess.PIPE,
-            )
+        p = subprocess.Popen(
+            ["ddtrace-run", "--debug", "python", "-c", "''"],
+            stdout=subprocess.PIPE,
+            stderr=subprocess.PIPE,
+        )
 
-            p.wait()
-            assert p.returncode == 0
-            assert p.stdout.read() == six.b("")
-            assert six.b("ddtrace.sampler") in p.stderr.read()
+        p.wait()
+        assert p.returncode == 0
+        assert p.stdout.read() == six.b("")
+        assert six.b("debug mode has been enabled for the ddtrace logger") in p.stderr.read()
 
 
 @pytest.mark.skipif(sys.version_info >= (3, 11, 0), reason="Profiler not yet compatible with Python 3.11")

tests/contrib/logging/test_tracer_logging.py

@@ -295,7 +295,6 @@ def test_debug_logs_streamhandler_default(
 ddtrace_logger = logging.getLogger('ddtrace')
 
 assert ddtrace_logger.getEffectiveLevel() == logging.DEBUG
-assert len(ddtrace_logger.handlers) == 0
 
 ddtrace_logger.warning('warning log')
 ddtrace_logger.debug('debug log')
@@ -315,7 +314,6 @@ def test_debug_logs_streamhandler_default(
 ddtrace_logger = logging.getLogger('ddtrace')
 
 assert ddtrace_logger.getEffectiveLevel() == logging.DEBUG
-assert len(ddtrace_logger.handlers) == 0
 
 ddtrace_logger.warning('warning log')
 ddtrace_logger.debug('debug log')

tests/integration/test_debug.py

@@ -366,9 +366,7 @@ def test_startup_logs_sampling_rules():
 def test_error_output_ddtracerun_debug_mode():
     p = subprocess.Popen(
         ["ddtrace-run", "python", "tests/integration/hello.py"],
-        env=dict(
-            DD_TRACE_AGENT_URL="http://localhost:8126", DD_TRACE_DEBUG="true", DD_CALL_BASIC_CONFIG="true", **os.environ
-        ),
+        env=dict(DD_TRACE_AGENT_URL="http://localhost:8126", DD_TRACE_DEBUG="true", **os.environ),
         stdout=subprocess.PIPE,
         stderr=subprocess.PIPE,
     )
@@ -380,9 +378,7 @@ def test_error_output_ddtracerun_debug_mode():
     # No connection to agent, debug mode enabled
     p = subprocess.Popen(
         ["ddtrace-run", "python", "tests/integration/hello.py"],
-        env=dict(
-            DD_TRACE_AGENT_URL="http://localhost:4321", DD_TRACE_DEBUG="true", DD_CALL_BASIC_CONFIG="true", **os.environ
-        ),
+        env=dict(DD_TRACE_AGENT_URL="http://localhost:4321", DD_TRACE_DEBUG="true", **os.environ),
         stdout=subprocess.PIPE,
         stderr=subprocess.PIPE,
     )
@@ -424,9 +420,7 @@ def test_error_output_ddtracerun():
 def test_debug_span_log():
     p = subprocess.Popen(
         ["python", "-c", 'import os; print(os.environ);import ddtrace; ddtrace.tracer.trace("span").finish()'],
-        env=dict(
-            DD_TRACE_AGENT_URL="http://localhost:8126", DD_TRACE_DEBUG="true", DD_CALL_BASIC_CONFIG="true", **os.environ
-        ),
+        env=dict(DD_TRACE_AGENT_URL="http://localhost:8126", DD_TRACE_DEBUG="true", **os.environ),
         stdout=subprocess.PIPE,
         stderr=subprocess.PIPE,
     )