Skip to content

Commit 52856c5

Browse files
fix(structlog): ensures processor injection is not duplicated [backport 2.7] (#8760)
Backport 6f1ecfd from #8713 to 2.7. Fixes #8699 Note that when the user has a configuration with no processors, the instrumentation _does not_ inject any processors since there must be a rendered processor for a valid configuration ## Checklist - [x] Change(s) are motivated and described in the PR description - [x] Testing strategy is described if automated tests are not included in the PR - [x] Risks are described (performance impact, potential for breakage, maintainability) - [x] Change is maintainable (easy to change, telemetry, documentation) - [x] [Library release note guidelines](https://ddtrace.readthedocs.io/en/stable/releasenotes.html) are followed or label `changelog/no-changelog` is set - [x] Documentation is included (in-code, generated user docs, [public corp docs](https://github.com/DataDog/documentation/)) - [x] Backport labels are set (if [applicable](https://ddtrace.readthedocs.io/en/latest/contributing.html#backporting)) - [x] If this PR changes the public interface, I've notified `@DataDog/apm-tees`. - [x] If change touches code that signs or publishes builds or packages, or handles credentials of any kind, I've requested a review from `@DataDog/security-design-and-guidance`. ## Reviewer Checklist - [x] Title is accurate - [x] All changes are related to the pull request's stated goal - [x] Description motivates each change - [x] Avoids breaking [API](https://ddtrace.readthedocs.io/en/stable/versioning.html#interfaces) changes - [x] Testing strategy adequately addresses listed risks - [x] Change is maintainable (easy to change, telemetry, documentation) - [x] Release note makes sense to a user of the library - [x] Author has acknowledged and discussed the performance implications of this PR as reported in the benchmarks PR comment - [x] Backport labels are set in a manner that is consistent with the [release branch maintenance policy](https://ddtrace.readthedocs.io/en/latest/contributing.html#backporting) Co-authored-by: Zarir Hamza <[email protected]>
1 parent a8d0b73 commit 52856c5

File tree

4 files changed

+167
-1
lines changed

4 files changed

+167
-1
lines changed

ddtrace/contrib/structlog/patch.py

Lines changed: 51 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,8 @@
33
import ddtrace
44
from ddtrace import config
55

6+
from ...internal.utils import get_argument_value
7+
from ...internal.utils import set_argument_value
68
from ..logging.constants import RECORD_ATTR_ENV
79
from ..logging.constants import RECORD_ATTR_SERVICE
810
from ..logging.constants import RECORD_ATTR_SPAN_ID
@@ -50,6 +52,7 @@ def _tracer_injection(_, __, event_dict):
5052
def _w_get_logger(func, instance, args, kwargs):
5153
"""
5254
Append the tracer injection processor to the ``default_processors`` list used by the logger
55+
Ensures that the tracer injection processor is the first processor in the chain and only injected once
5356
The ``default_processors`` list has built in defaults which protects against a user configured ``None`` value.
5457
The argument to configure ``default_processors`` accepts an iterable type:
5558
- List: default use case which has been accounted for
@@ -59,10 +62,47 @@ def _w_get_logger(func, instance, args, kwargs):
5962
"""
6063

6164
dd_processor = [_tracer_injection]
62-
structlog._config._CONFIG.default_processors = dd_processor + list(structlog._config._CONFIG.default_processors)
65+
if (
66+
_tracer_injection not in list(structlog._config._CONFIG.default_processors)
67+
and structlog._config._CONFIG.default_processors
68+
):
69+
structlog._config._CONFIG.default_processors = dd_processor + list(structlog._config._CONFIG.default_processors)
70+
71+
return func(*args, **kwargs)
72+
73+
74+
def _w_configure(func, instance, args, kwargs):
75+
"""
76+
Injects the tracer injection processor to the ``processors`` list parameter when configuring a logger
77+
Ensures that the tracer injection processor is the first processor in the chain and only injected once
78+
In addition, the tracer injection processor is only injected if there is a renderer processor in the chain
79+
"""
80+
81+
dd_processor = [_tracer_injection]
82+
arg_processors = get_argument_value(args, kwargs, 0, "processors", True)
83+
if arg_processors and len(arg_processors) != 0:
84+
set_argument_value(args, kwargs, 0, "processors", dd_processor + list(arg_processors))
85+
6386
return func(*args, **kwargs)
6487

6588

89+
def _w_reset_defaults(func, instance, args, kwargs):
90+
"""
91+
Reset the default_processors list to the original defaults
92+
Ensures that the tracer injection processor is injected after to the default_processors list
93+
"""
94+
func(*args, **kwargs)
95+
96+
dd_processor = [_tracer_injection]
97+
if (
98+
_tracer_injection not in list(structlog._config._CONFIG.default_processors)
99+
and structlog._config._CONFIG.default_processors
100+
):
101+
structlog._config._CONFIG.default_processors = dd_processor + list(structlog._config._CONFIG.default_processors)
102+
103+
return
104+
105+
66106
def patch():
67107
"""
68108
Patch ``structlog`` module for injection of tracer information
@@ -79,6 +119,12 @@ def patch():
79119
if hasattr(structlog, "getLogger"):
80120
_w(structlog, "getLogger", _w_get_logger)
81121

122+
if hasattr(structlog, "configure"):
123+
_w(structlog, "configure", _w_configure)
124+
125+
if hasattr(structlog, "reset_defaults"):
126+
_w(structlog, "reset_defaults", _w_reset_defaults)
127+
82128

83129
def unpatch():
84130
if getattr(structlog, "_datadog_patch", False):
@@ -88,3 +134,7 @@ def unpatch():
88134
_u(structlog, "get_logger")
89135
if hasattr(structlog, "getLogger"):
90136
_u(structlog, "getLogger")
137+
if hasattr(structlog, "configure"):
138+
_u(structlog, "configure")
139+
if hasattr(structlog, "reset_defaults"):
140+
_u(structlog, "reset_defaults")
Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
---
2+
fixes:
3+
- |
4+
structlog: Fixes error where multiple loggers would duplicate processors. Also adds processors injection
5+
when resetting to defaults.

tests/contrib/structlog/test_structlog_logging.py

Lines changed: 105 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -345,3 +345,108 @@ def test_no_configured_processor():
345345

346346
cf.logger.calls.clear()
347347
unpatch()
348+
349+
350+
@pytest.mark.subprocess()
351+
def test_two_loggers_no_duplicates():
352+
"""
353+
Check if patching two loggers does not duplicate processors
354+
"""
355+
import structlog
356+
357+
from ddtrace.contrib.structlog import patch
358+
from ddtrace.contrib.structlog import unpatch
359+
360+
patch()
361+
362+
logger1 = structlog.getLogger()
363+
num_log1_processors = len(logger1.bind()._processors)
364+
365+
logger2 = structlog.getLogger()
366+
num_log2_processors = len(logger2.bind()._processors)
367+
368+
assert (
369+
num_log1_processors
370+
== num_log2_processors
371+
== len(logger1.bind()._processors)
372+
== len(structlog._config._BUILTIN_DEFAULT_PROCESSORS) + 1
373+
)
374+
375+
unpatch()
376+
377+
378+
@pytest.mark.subprocess()
379+
def test_configure_processor():
380+
"""
381+
Check if calling configure() after get_logger() does not duplicate/remove injected processors
382+
"""
383+
import structlog
384+
385+
from ddtrace.contrib.structlog import patch
386+
from ddtrace.contrib.structlog import unpatch
387+
388+
patch()
389+
390+
structlog.configure()
391+
logger1 = structlog.getLogger()
392+
num_log1_processors = len(logger1.bind()._processors)
393+
394+
cf = structlog.testing.CapturingLoggerFactory()
395+
structlog.configure(
396+
logger_factory=cf,
397+
)
398+
399+
assert (
400+
num_log1_processors == len(logger1.bind()._processors) == len(structlog._config._BUILTIN_DEFAULT_PROCESSORS) + 1
401+
)
402+
403+
cf.logger.calls.clear()
404+
unpatch()
405+
406+
407+
@pytest.mark.subprocess()
408+
def test_consistent_empty_config():
409+
"""
410+
Check if calling configure() with an empty processor list stays empty
411+
"""
412+
import structlog
413+
414+
from ddtrace.contrib.structlog import patch
415+
from ddtrace.contrib.structlog import unpatch
416+
417+
patch()
418+
419+
logger1 = structlog.getLogger()
420+
structlog.configure(processors=[])
421+
num_log1_processors = len(logger1.bind()._processors)
422+
423+
logger1 = structlog.getLogger()
424+
425+
assert num_log1_processors == len(logger1.bind()._processors) == 0
426+
427+
unpatch()
428+
429+
430+
@pytest.mark.subprocess()
431+
def test_reset_defaults():
432+
"""
433+
Check if injected processor still exists after resetting to default
434+
"""
435+
import structlog
436+
437+
from ddtrace.contrib.structlog import patch
438+
from ddtrace.contrib.structlog import unpatch
439+
440+
patch()
441+
442+
structlog.configure()
443+
logger1 = structlog.getLogger()
444+
num_log1_processors = len(logger1.bind()._processors)
445+
446+
structlog.reset_defaults()
447+
448+
assert (
449+
num_log1_processors == len(logger1.bind()._processors) == len(structlog._config._BUILTIN_DEFAULT_PROCESSORS) + 1
450+
)
451+
452+
unpatch()

tests/contrib/structlog/test_structlog_patch.py

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,11 +24,17 @@ class TestStructlogPatch(PatchTestCase.Base):
2424
def assert_module_patched(self, structlog):
2525
self.assert_wrapped(structlog.get_logger)
2626
self.assert_wrapped(structlog.getLogger)
27+
self.assert_wrapped(structlog.configure)
28+
self.assert_wrapped(structlog.reset_defaults)
2729

2830
def assert_not_module_patched(self, structlog):
2931
self.assert_not_wrapped(structlog.get_logger)
3032
self.assert_not_wrapped(structlog.getLogger)
33+
self.assert_not_wrapped(structlog.configure)
34+
self.assert_not_wrapped(structlog.reset_defaults)
3135

3236
def assert_not_module_double_patched(self, structlog):
3337
self.assert_not_double_wrapped(structlog.get_logger)
3438
self.assert_not_double_wrapped(structlog.getLogger)
39+
self.assert_not_double_wrapped(structlog.configure)
40+
self.assert_not_double_wrapped(structlog.reset_defaults)

0 commit comments

Comments
 (0)