Skip to content

chore: configurable logger levels #13562

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 4 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
56 changes: 56 additions & 0 deletions ddtrace/internal/logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand All @@ -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.
Expand All @@ -56,6 +105,13 @@ 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
if (level := LOG_LEVEL_TRIE.lookup(name)) is not None:
logger.setLevel(level)

return logger


Expand Down
26 changes: 26 additions & 0 deletions tests/tracer/test_logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -335,3 +335,29 @@ 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")
monkeypatch.setenv("_DD_PACKAGE_WITH_UNDERSCORE_SUBMODULE_LOG_LEVEL", "ERROR")

import ddtrace.internal.logger as dd_logger

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
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we shouldn't have to manually set the level for all children.... right?

meaning _DD_TESTING_DEBUG_LOG_LEVEL=DEBUG should only set the level on testing.debug only, and not on .foo or .foo.bar.

You should evaluate via .isEnabledFor(logging.DEBUG) instead of .level == logging.DEBUG, since that takes into account it's parents settings as well:

>>> a = logging.getLogger("a")
>>> b = logging.getLogger("a.b")
>>> a.setLevel(logging.DEBUG)
>>> b.isEnabledFor(logging.DEBUG)
True
>>> a.setLevel(logging.ERROR)
>>> b.isEnabledFor(logging.DEBUG)
False

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah that's a good point, but what if the logger for a is never created? 🤔

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
Loading