[BUG]: ddtrace throws logging exception during unit test runs with pytest

[ejungcl]

Tracer Version(s)

2.19.1

Python Version(s)

Pyton 3.13.0

Pip Version(s)

uv-pip 0.4.23 (83f835b0d 2024-10-17)

Bug Report

ddtrace tries to log to a closed stream when running unit tests with pytest, and causes an exception to be thrown in the logger. The expected behavior is that ddtrace will not cause any logging exceptions.

I am not using any ddtrace imports or functions. The only thing I have done is install ddtrace using pyproject.toml.

If I change our logging configuration, so that disable_existing_loggers=True instead of False, then the exception goes away.

This seems to be a bug in ddtrace, because setting disable_existing_loggers=True will disable ddtrace logging.

Reproduction Code

conftest.py

@pytest.fixture
def dummy():
    cfg = """
    version: 1
    disable_existing_loggers: False

    formatters:
        simple:
            format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
            datefmt: '%Y-%m-%d %H:%M:%S'

    handlers:
        stdout:
            class: logging.StreamHandler
            level: DEBUG
            formatter: simple
            stream: ext://sys.stdout
    loggers:
        root:
            level: DEBUG
            handlers: [stdout]
    """

    logconfig = yaml.safe_load(cfg)
    dictConfig(logconfig)

test_hello.py

"""Model unit tests."""
import pytest

def test_delete(dummy):
    assert 1 == 2

Error Logs

uv run pytest tests/models/test_hello.py
=============================================================== test session starts ================================================================
platform darwin -- Python 3.13.0, pytest-8.3.4, pluggy-1.5.0
rootdir: /Users/xtaje/clrepo/yoma
configfile: pyproject.toml
plugins: cov-6.0.0, time-machine-2.16.0, ddtrace-2.19.1, timer-1.0.0, Faker-33.3.1
collected 1 item

tests/models/test_hello.py F                                                                                                                 [100%]

===================================================================== FAILURES =====================================================================
___________________________________________________________________ test_delete ____________________________________________________________________

dummy = None

    def test_delete(dummy):
>       assert 1 == 2
E       assert 1 == 2

tests/models/test_hello.py:6: AssertionError
=================================================================== pytest-timer ===================================================================
[fail] 100.00% tests/models/test_hello.py::test_delete: 0.0001s
============================================================= short test summary info ==============================================================
FAILED tests/models/test_hello.py::test_delete - assert 1 == 2
================================================================ 1 failed in 0.05s =================================================================
Waiting 5 seconds for tracer to finish. Hit ctrl-c to quit.
--- Logging error ---
Traceback (most recent call last):
  File "/Users/xtaje/.local/share/uv/python/cpython-3.13.0-macos-aarch64-none/lib/python3.13/logging/__init__.py", line 1153, in emit
    stream.write(msg + self.terminator)
    ~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
ValueError: I/O operation on closed file.
Call stack:
  File "/Users/xtaje/clrepo/yoma/.venv/lib/python3.13/site-packages/ddtrace/_trace/tracer.py", line 311, in _atexit
    log.debug(
  File "/Users/xtaje/.local/share/uv/python/cpython-3.13.0-macos-aarch64-none/lib/python3.13/logging/__init__.py", line 1507, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "/Users/xtaje/.local/share/uv/python/cpython-3.13.0-macos-aarch64-none/lib/python3.13/logging/__init__.py", line 1664, in _log
    self.handle(record)
  File "/Users/xtaje/clrepo/yoma/.venv/lib/python3.13/site-packages/ddtrace/internal/logger.py", line 148, in handle
    super(DDLogger, self).handle(record)
Message: 'Waiting %d seconds for tracer to finish. Hit %s to quit.'
Arguments: (5, 'ctrl-c')

Libraries in Use

alembic==1.14.1
amqp==5.3.1
aniso8601==10.0.0
annotated-types==0.7.0
astroid==3.3.8
bandit==1.8.2
beautifulsoup4==4.12.3
billiard==4.2.1
black==24.10.0
blinker==1.9.0
cachelib==0.9.0
celery==5.4.0
certifi==2024.12.14
charset-normalizer==3.4.1
click==8.1.8
click-didyoumean==0.3.1
click-plugins==1.1.1
click-repl==0.3.0
coverage==7.6.10
dill==0.3.9
environs==14.1.0
factory-boy==3.3.1
faker==33.3.1
flask==3.1.0
flask-caching==2.3.0
flask-jwt-extended==4.7.1
flask-migrate==4.1.0
flask-restful==0.3.10
flask-sqlalchemy==3.1.1
gevent==24.11.1
greenlet==3.1.1
gunicorn==23.0.0
httmock==1.4.0
idna==3.10
iniconfig==2.0.0
isort==5.13.2
itsdangerous==2.2.0
jinja2==3.1.5
kombu==5.4.2
legacy-cgi==2.6.2
mako==1.3.8
markdown-it-py==3.0.0
markupsafe==3.0.2
marshmallow==3.25.1
mccabe==0.7.0
mdurl==0.1.2
mypy-extensions==1.0.0
packaging==24.2
pathspec==0.12.1
pbr==6.1.0
pendulum==3.0.0
platformdirs==4.3.6
pluggy==1.5.0
prompt-toolkit==3.0.50
pydantic==2.10.5
pydantic-core==2.27.2
pydantic-extra-types==2.10.2
pygments==2.19.1
pyjwt==2.10.1
pylint==3.3.3
pymysql==1.1.1
pytest==8.3.4
pytest-cov==6.0.0
pytest-timer==1.0.0
python-dateutil==2.9.0.post0
python-dotenv==1.0.1
pytz==2024.2
pyyaml==6.0.2
redis==5.2.1
requests==2.32.3
rich==13.9.4
ruff==0.9.2
setuptools==75.8.0
six==1.17.0
soupsieve==2.6
sqlalchemy==2.0.37
sqlalchemy-utils==0.41.2
stevedore==5.4.0
time-machine==2.16.0
tomlkit==0.13.2
typing-extensions==4.12.2
tzdata==2025.1
urllib3==2.3.0
vine==5.1.0
waitress==3.0.2
wcwidth==0.2.13
webob==1.8.9
webtest==3.0.3
werkzeug==3.1.3
-e file:///Users/xtaje/clrepo/yoma
zope-event==5.0
zope-interface==7.2

Operating System

Darwin CL1076.local 24.0.0 Darwin Kernel Version 24.0.0: Tue Sep 24 23:37:25 PDT 2024; root:xnu-11215.1.12~1/RELEASE_ARM64_T6030 arm64

[doctornkz-intelas]

I think it's very close to this ticket #10754 and I also realised that ddtracer is patching loggers even without imports.