From 8789442c47d6be2a1a6837bbdbd5964c8f951d4c Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Mon, 2 Jun 2025 15:48:01 +0100 Subject: [PATCH 1/3] chore: configurable logger levels We introduce private enviornment variables that allow configuring the log level of the ddtrace loggers. This allows for fine-grained control over the logger levels, making debugging easier by reducing the noise of logs. --- ddtrace/internal/logger.py | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/ddtrace/internal/logger.py b/ddtrace/internal/logger.py index 74f4b5321a6..654909025a0 100644 --- a/ddtrace/internal/logger.py +++ b/ddtrace/internal/logger.py @@ -56,6 +56,18 @@ def get_logger(name: str) -> logging.Logger: logger = logging.getLogger(name) # addFilter will only add the filter if it is not already present logger.addFilter(log_filter) + + # Set the log level from the environment variable of the closest parent + # logger. + if name.startswith("ddtrace."): # for the whole of ddtrace we have DD_TRACE_DEBUG + (hierarchy := name.split(".")).pop(0) # remove "ddtrace" + while hierarchy: + if (level_name := os.getenv("_DD_" + "_".join(hierarchy).upper() + "_LOG_LEVEL", None)) is not None: + if (level := getattr(logging, level_name, None)) is not None: + logger.setLevel(level) + break + hierarchy.pop() + return logger From 2a3cb3ec237d779e8a787fd84e7560317eca84a7 Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Thu, 12 Jun 2025 16:14:15 +0100 Subject: [PATCH 2/3] add test --- tests/tracer/test_logger.py | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/tests/tracer/test_logger.py b/tests/tracer/test_logger.py index c067ca47174..7534f3aa63c 100644 --- a/tests/tracer/test_logger.py +++ b/tests/tracer/test_logger.py @@ -335,3 +335,17 @@ def test_logger_does_not_add_handler_when_configured(): ddtrace_logger = logging.getLogger("ddtrace") assert len(ddtrace_logger.handlers) == 0 assert ddtrace_logger.handlers == [] + + +def test_logger_log_level_from_env(monkeypatch): + monkeypatch.setenv("_DD_TESTING_DEBUG_LOG_LEVEL", "DEBUG") + monkeypatch.setenv("_DD_TESTING_WARNING_LOG_LEVEL", "WARNING") + + assert get_logger("ddtrace.testing.debug.foo.bar").level == logging.DEBUG + assert get_logger("ddtrace.testing.debug.foo").level == logging.DEBUG + assert get_logger("ddtrace.testing.debug").level == logging.DEBUG + assert get_logger("ddtrace.testing").level < logging.DEBUG + + assert get_logger("ddtrace.testing.warning.foo.bar").level == logging.WARNING + assert get_logger("ddtrace.testing.warning.foo").level == logging.WARNING + assert get_logger("ddtrace.testing.warning").level == logging.WARNING From e9ae14d3fd775d5788c82ce28a682ec8f5ced202 Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Thu, 12 Jun 2025 17:11:30 +0100 Subject: [PATCH 3/3] implement a trie for faster lookups --- ddtrace/internal/logger.py | 58 ++++++++++++++++++++++++++++++++----- tests/tracer/test_logger.py | 26 ++++++++++++----- 2 files changed, 70 insertions(+), 14 deletions(-) diff --git a/ddtrace/internal/logger.py b/ddtrace/internal/logger.py index 654909025a0..b5a5057a0b2 100644 --- a/ddtrace/internal/logger.py +++ b/ddtrace/internal/logger.py @@ -31,11 +31,15 @@ """ import collections +from dataclasses import dataclass +from dataclasses import field import logging import os import time import traceback from typing import DefaultDict +from typing import Dict +from typing import Optional from typing import Tuple from typing import Union @@ -46,6 +50,51 @@ DAY = 24 * HOUR +@dataclass +class LoggerPrefix: + prefix: str + level: Optional[int] = None + children: Dict[str, "LoggerPrefix"] = field(default_factory=dict) + + def lookup(self, name: str) -> Optional[int]: + """ + Lookup the log level for a given logger name in the trie. + + The name is split by '.' and each part is used to traverse the trie. + If a part is not found, it returns the level of the closest parent node. + """ + parts = name.replace("_", ".").lower().split(".") + parts.pop(0) # remove the ddtrace prefix + current = self + while parts: + if (part := parts.pop(0)) not in current.children: + return current.level + current = current.children[part] + + return current.level + + @classmethod + def build_trie(cls): + trie = cls(prefix="ddtrace", level=None, children={}) + + for logger_name, level in ( + (k, v) for k, v in os.environ.items() if k.startswith("_DD_") and k.endswith("_LOG_LEVEL") + ): + # Remove the _DD_ prefix and _LOG_LEVEL suffix + logger_name = logger_name[4:-10] + parts = logger_name.lower().split("_") + current = trie.children + while parts: + if (part := parts.pop(0)) not in current: + current[part] = cls(prefix=part, level=getattr(logging, level, None) if not parts else None) + current = current[part].children + + return trie + + +LOG_LEVEL_TRIE = LoggerPrefix.build_trie() + + def get_logger(name: str) -> logging.Logger: """ Retrieve or create a ``Logger`` instance with consistent behavior for internal use. @@ -60,13 +109,8 @@ def get_logger(name: str) -> logging.Logger: # Set the log level from the environment variable of the closest parent # logger. if name.startswith("ddtrace."): # for the whole of ddtrace we have DD_TRACE_DEBUG - (hierarchy := name.split(".")).pop(0) # remove "ddtrace" - while hierarchy: - if (level_name := os.getenv("_DD_" + "_".join(hierarchy).upper() + "_LOG_LEVEL", None)) is not None: - if (level := getattr(logging, level_name, None)) is not None: - logger.setLevel(level) - break - hierarchy.pop() + if (level := LOG_LEVEL_TRIE.lookup(name)) is not None: + logger.setLevel(level) return logger diff --git a/tests/tracer/test_logger.py b/tests/tracer/test_logger.py index 7534f3aa63c..dd1aeca9963 100644 --- a/tests/tracer/test_logger.py +++ b/tests/tracer/test_logger.py @@ -340,12 +340,24 @@ def test_logger_does_not_add_handler_when_configured(): def test_logger_log_level_from_env(monkeypatch): monkeypatch.setenv("_DD_TESTING_DEBUG_LOG_LEVEL", "DEBUG") monkeypatch.setenv("_DD_TESTING_WARNING_LOG_LEVEL", "WARNING") + monkeypatch.setenv("_DD_PACKAGE_WITH_UNDERSCORE_SUBMODULE_LOG_LEVEL", "ERROR") - assert get_logger("ddtrace.testing.debug.foo.bar").level == logging.DEBUG - assert get_logger("ddtrace.testing.debug.foo").level == logging.DEBUG - assert get_logger("ddtrace.testing.debug").level == logging.DEBUG - assert get_logger("ddtrace.testing").level < logging.DEBUG + import ddtrace.internal.logger as dd_logger - assert get_logger("ddtrace.testing.warning.foo.bar").level == logging.WARNING - assert get_logger("ddtrace.testing.warning.foo").level == logging.WARNING - assert get_logger("ddtrace.testing.warning").level == logging.WARNING + original_trie = dd_logger.LOG_LEVEL_TRIE + dd_logger.LOG_LEVEL_TRIE = dd_logger.LoggerPrefix.build_trie() + print(dd_logger.LOG_LEVEL_TRIE) + + try: + assert get_logger("ddtrace.testing.debug.foo.bar").level == logging.DEBUG + assert get_logger("ddtrace.testing.debug.foo").level == logging.DEBUG + assert get_logger("ddtrace.testing.debug").level == logging.DEBUG + assert get_logger("ddtrace.testing").level < logging.DEBUG + + assert get_logger("ddtrace.testing.warning.foo.bar").level == logging.WARNING + assert get_logger("ddtrace.testing.warning.foo").level == logging.WARNING + assert get_logger("ddtrace.testing.warning").level == logging.WARNING + + assert get_logger("ddtrace.package_with_underscore.submodule").level == logging.ERROR + finally: + dd_logger.LOG_LEVEL_TRIE = original_trie