diff --git a/ddtrace/_logger.py b/ddtrace/_logger.py index 5bde0c11da2..631e9d97e4a 100644 --- a/ddtrace/_logger.py +++ b/ddtrace/_logger.py @@ -110,14 +110,6 @@ def _add_file_handler( return ddtrace_file_handler -def set_log_formatting(): - # type: () -> None - """Sets the log format for the ddtrace logger.""" - ddtrace_logger = logging.getLogger("ddtrace") - for handler in ddtrace_logger.handlers: - handler.setFormatter(logging.Formatter(DD_LOG_FORMAT)) - - def get_log_injection_state(raw_config: Optional[str]) -> bool: """Returns the current log injection state.""" if raw_config: diff --git a/ddtrace/contrib/internal/logging/patch.py b/ddtrace/contrib/internal/logging/patch.py index a68f0f6e4e8..c9136760c67 100644 --- a/ddtrace/contrib/internal/logging/patch.py +++ b/ddtrace/contrib/internal/logging/patch.py @@ -5,7 +5,6 @@ import ddtrace from ddtrace import config -from ddtrace._logger import set_log_formatting from ddtrace.contrib.internal.trace_utils import unwrap as _u from ddtrace.internal.constants import LOG_ATTR_ENV from ddtrace.internal.constants import LOG_ATTR_SERVICE @@ -100,13 +99,6 @@ def patch(): _w(logging.Logger, "makeRecord", _w_makeRecord) _w(logging.StrFormatStyle, "_format", _w_StrFormatStyle_format) - if config._logs_injection: - # Only set the formatter is DD_LOGS_INJECTION is set to True. We do not want to modify - # unstructured logs if a user has not enabled logs injection. - # Also, the Datadog log format must be set after the logging module has been patched, - # otherwise the formatter will raise an exception. - set_log_formatting() - def unpatch(): if getattr(logging, "_datadog_patch", False): diff --git a/releasenotes/notes/remove-set-log-formatting-a8b9c7d2e1f3g4h5.yaml b/releasenotes/notes/remove-set-log-formatting-a8b9c7d2e1f3g4h5.yaml new file mode 100644 index 00000000000..aad4e62e8c7 --- /dev/null +++ b/releasenotes/notes/remove-set-log-formatting-a8b9c7d2e1f3g4h5.yaml @@ -0,0 +1,5 @@ +--- +fixes: + - | + logging: Fixed ddtrace internal logging when trace-log correlation is disabled. + Prevents ``ValueError: Formatting field not found in record: 'dd.service'``. diff --git a/tests/commands/ddtrace_run_logs_injection.py b/tests/commands/ddtrace_run_logs_injection.py index 3a08ba3736d..82b6d4619de 100644 --- a/tests/commands/ddtrace_run_logs_injection.py +++ b/tests/commands/ddtrace_run_logs_injection.py @@ -1,17 +1,28 @@ +from io import StringIO +import json import logging +class JSONFormatter(logging.Formatter): + """Custom formatter that outputs log records as JSON.""" + + def format(self, record): + return json.dumps({k: str(v) for k, v in record.__dict__.items()}) + + if __name__ == "__main__": - # Ensure if module is patched then default log formatter is set up for logs - ddtrace_logger = logging.getLogger("ddtrace") - if 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 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 ddtrace_logger.handlers[0].formatter._fmt - ) + log_capture_string = StringIO() + handler = logging.StreamHandler(log_capture_string) + handler.setLevel(logging.INFO) + handler.setFormatter(JSONFormatter()) + + logger = logging.getLogger("ddtrace") + logger.addHandler(handler) + logger.setLevel(logging.INFO) + logger.info("Test log message") + + json_contents = json.loads(log_capture_string.getvalue().strip()) + assert json_contents.get("dd.service") == "my-service" + assert json_contents.get("dd.env") == "my-env" + assert json_contents.get("dd.version") == "my-version" print("Test success") diff --git a/tests/commands/test_runner.py b/tests/commands/test_runner.py index 967db4a7f5e..f4bc9faebd9 100644 --- a/tests/commands/test_runner.py +++ b/tests/commands/test_runner.py @@ -212,7 +212,7 @@ def test_global_trace_tags(self): def test_logs_injection(self): """Ensure logs injection works""" - with self.override_env(dict(DD_LOGS_INJECTION="true")): + with self.override_env(dict(DD_TAGS="service:my-service,env:my-env,version:my-version")): out = subprocess.check_output(["ddtrace-run", "python", "tests/commands/ddtrace_run_logs_injection.py"]) assert out.startswith(b"Test success"), out.decode() diff --git a/tests/integration/test_integration.py b/tests/integration/test_integration.py index 60aa25db059..94a8b95a77b 100644 --- a/tests/integration/test_integration.py +++ b/tests/integration/test_integration.py @@ -808,8 +808,8 @@ def test_logging_during_tracer_init_succeeds_when_debug_logging_and_logs_injecti assert out == b"", "an empty program should generate no logs under ddtrace-run" assert ( - b"[dd.service=ddtrace_subprocess_dir dd.env= dd.version= dd.trace_id=0 dd.span_id=0]" in err - ), "stderr should contain debug output when DD_TRACE_DEBUG is set" + b"[dd.service=ddtrace_subprocess_dir dd.env= dd.version= dd.trace_id=0 dd.span_id=0]" not in err + ), "stderr should not contain debug output when DD_TRACE_DEBUG is set" assert b"KeyError: 'dd.service'" not in err, "stderr should not contain any exception logs" assert ( diff --git a/tests/suitespec.yml b/tests/suitespec.yml index 977f6685e79..731a63a8d5e 100644 --- a/tests/suitespec.yml +++ b/tests/suitespec.yml @@ -55,6 +55,7 @@ components: - ddtrace/internal/gitmetadata.py - ddtrace/internal/glob_matching.py - ddtrace/internal/logger.py + - ddtrace/_logger.py - ddtrace/internal/hostname.py - ddtrace/internal/http.py - ddtrace/internal/bytecode_injection/*