gevent could not work with ddtrace in pytest

DataDog / dd-trace-py

Datadog Python APM Client

https://ddtrace.readthedocs.io/

Other

550 stars 412 forks source link

gevent could not work with ddtrace in pytest #8281

Closed zdyj3170101136 closed 5 months ago

zdyj3170101136 commented 9 months ago

code

import ddtrace.auto
import gevent.monkey
gevent.monkey.patch_all()

from ddtrace.profiling import Profiler
import os
import time
prof = Profiler(url="http://127.0.0.1:7070")
prof.start()
time.sleep(3)
print(os.getpid())
prof.stop()
print("wait for stop")

work great when use pprof:

DD_PROFILING_OUTPUT_PPROF=pprof python3.7 test.py
20142
wait for stop

deadlock when use pytest:

DD_PROFILING_OUTPUT_PPROF=pprof python3.7 -m pytest -s abc.py
========================================================================= test session starts =========================================================================
platform linux -- Python 3.7.7, pytest-7.1.3, pluggy-1.2.0
rootdir: /root
plugins: ddtrace-1.20.16
collecting ... 20216

^CKeyboardInterrupt
2024-02-04T09:36:35Z
collected 0 items / 1 error

=============================================================================== ERRORS ================================================================================
_______________________________________________________________________ ERROR collecting abc.py _______________________________________________________________________
<frozen importlib._bootstrap>:983: in _find_and_load
    ???
<frozen importlib._bootstrap>:967: in _find_and_load_unlocked
    ???
<frozen importlib._bootstrap>:677: in _load_unlocked
    ???
/usr/lib/python3.7/site-packages/ddtrace/internal/module.py:224: in _exec_module
    self.loader.exec_module(module)
/usr/lib/python3.7/site-packages/_pytest/assertion/rewrite.py:168: in exec_module
    exec(co, module.__dict__)
abc.py:12: in <module>
    prof.stop()
/usr/lib/python3.7/site-packages/ddtrace/profiling/profiler.py:78: in stop
    self._profiler.stop(flush)
/usr/lib/python3.7/site-packages/ddtrace/internal/service.py:85: in stop
    self._stop_service(*args, **kwargs)
/usr/lib/python3.7/site-packages/ddtrace/profiling/profiler.py:329: in _stop_service
    self._scheduler.join()
/usr/lib/python3.7/site-packages/ddtrace/internal/periodic.py:148: in join
    self._worker.join(timeout)
/usr/lib/python3.7/threading.py:1044: in join
    self._wait_for_tstate_lock()
/usr/lib/python3.7/threading.py:1060: in _wait_for_tstate_lock
    elif lock.acquire(block, timeout):
/usr/lib/python3.7/site-packages/gevent/thread.py:121: in acquire
    acquired = BoundedSemaphore.acquire(self, blocking, timeout)
src/gevent/_semaphore.py:180: in gevent._gevent_c_semaphore.Semaphore.acquire
    ???
src/gevent/_semaphore.py:249: in gevent._gevent_c_semaphore.Semaphore.acquire
    ???
src/gevent/_abstract_linkable.py:521: in gevent._gevent_c_abstract_linkable.AbstractLinkable._wait
    ???
src/gevent/_abstract_linkable.py:487: in gevent._gevent_c_abstract_linkable.AbstractLinkable._wait_core
    ???
src/gevent/_abstract_linkable.py:490: in gevent._gevent_c_abstract_linkable.AbstractLinkable._wait_core
    ???
src/gevent/_abstract_linkable.py:442: in gevent._gevent_c_abstract_linkable.AbstractLinkable._AbstractLinkable__wait_to_be_notified
    ???
src/gevent/_abstract_linkable.py:451: in gevent._gevent_c_abstract_linkable.AbstractLinkable._switch_to_hub
    ???
src/gevent/_greenlet_primitives.py:61: in gevent._gevent_c_greenlet_primitives.SwitchOutGreenletWithLoop.switch
    ???
src/gevent/_greenlet_primitives.py:65: in gevent._gevent_c_greenlet_primitives.SwitchOutGreenletWithLoop.switch
    ???
src/gevent/_gevent_c_greenlet_primitives.pxd:35: in gevent._gevent_c_greenlet_primitives._greenlet_switch
    ???
E   KeyboardInterrupt

During handling of the above exception, another exception occurred:
/usr/lib/python3.7/importlib/__init__.py:127: in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
<frozen importlib._bootstrap>:1006: in _gcd_import
    ???
<frozen importlib._bootstrap>:983: in _find_and_load
    ???
<frozen importlib._bootstrap>:152: in __exit__
    ???
<frozen importlib._bootstrap>:107: in release
    ???
E   RuntimeError: cannot release un-acquired lock
======================================================================= short test summary info =======================================================================
ERROR abc.py - RuntimeError: cannot release un-acquired lock
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Interrupted: 1 error during collection !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
=

zdyj3170101136 commented 9 months ago

not suitable with 2.5.0:

python3.9 -m pytest -s ./test_abc.py 
============================================================================= test session starts =============================================================================
platform darwin -- Python 3.9.18, pytest-8.0.0, pluggy-1.4.0
rootdir: /Users/jie.yang05/neo-core
plugins: celery-4.4.7, ddtrace-2.5.0, typeguard-2.11.0
collecting ... 2993

^CKeyboardInterrupt
2024-02-04T09:43:06Z
collected 0 items / 1 error                                                                                                                                                   

=================================================================================== ERRORS ====================================================================================
_______________________________________________________________________ ERROR collecting w/test_abc.py ________________________________________________________________________
test_abc.py:12: in <module>
    prof.stop()
/opt/homebrew/lib/python3.9/site-packages/ddtrace/profiling/profiler.py:76: in stop
    self._profiler.stop(flush)
/opt/homebrew/lib/python3.9/site-packages/ddtrace/internal/service.py:84: in stop
    self._stop_service(*args, **kwargs)
/opt/homebrew/lib/python3.9/site-packages/ddtrace/profiling/profiler.py:342: in _stop_service
    self._scheduler.join()
/opt/homebrew/lib/python3.9/site-packages/ddtrace/internal/periodic.py:156: in join
    self._worker.join(timeout)
/opt/homebrew/Cellar/python@3.9/3.9.18_1/Frameworks/Python.framework/Versions/3.9/lib/python3.9/threading.py:1060: in join
    self._wait_for_tstate_lock()
/opt/homebrew/Cellar/python@3.9/3.9.18_1/Frameworks/Python.framework/Versions/3.9/lib/python3.9/threading.py:1080: in _wait_for_tstate_lock
    if lock.acquire(block, timeout):
/opt/homebrew/lib/python3.9/site-packages/gevent/thread.py:121: in acquire
    acquired = BoundedSemaphore.acquire(self, blocking, timeout)
src/gevent/_semaphore.py:180: in gevent._gevent_c_semaphore.Semaphore.acquire
    ???
src/gevent/_semaphore.py:249: in gevent._gevent_c_semaphore.Semaphore.acquire
    ???
src/gevent/_abstract_linkable.py:521: in gevent._gevent_c_abstract_linkable.AbstractLinkable._wait
    ???
src/gevent/_abstract_linkable.py:487: in gevent._gevent_c_abstract_linkable.AbstractLinkable._wait_core
    ???
src/gevent/_abstract_linkable.py:490: in gevent._gevent_c_abstract_linkable.AbstractLinkable._wait_core
    ???
src/gevent/_abstract_linkable.py:442: in gevent._gevent_c_abstract_linkable.AbstractLinkable._AbstractLinkable__wait_to_be_notified
    ???
src/gevent/_abstract_linkable.py:451: in gevent._gevent_c_abstract_linkable.AbstractLinkable._switch_to_hub
    ???
src/gevent/_greenlet_primitives.py:61: in gevent._gevent_c_greenlet_primitives.SwitchOutGreenletWithLoop.switch
    ???
src/gevent/_greenlet_primitives.py:65: in gevent._gevent_c_greenlet_primitives.SwitchOutGreenletWithLoop.switch
    ???
src/gevent/_gevent_c_greenlet_primitives.pxd:35: in gevent._gevent_c_greenlet_primitives._greenlet_switch
    ???
E   KeyboardInterrupt

During handling of the above exception, another exception occurred:
/opt/homebrew/Cellar/python@3.9/3.9.18_1/Frameworks/Python.framework/Versions/3.9/lib/python3.9/importlib/__init__.py:127: in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
<frozen importlib._bootstrap>:1030: in _gcd_import
    ???
<frozen importlib._bootstrap>:1007: in _find_and_load
    ???
<frozen importlib._bootstrap>:161: in __exit__
    ???
<frozen importlib._bootstrap>:116: in release
    ???
E   RuntimeError: cannot release un-acquired lock
============================================================================== warnings summary ===============================================================================
../../../../opt/homebrew/lib/python3.9/site-packages/ddtrace/internal/module.py:224
  /opt/homebrew/lib/python3.9/site-packages/ddtrace/internal/module.py:224: DeprecationWarning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html
    self.loader.exec_module(module)

../../../../opt/homebrew/lib/python3.9/site-packages/pkg_resources/__init__.py:2871
  /opt/homebrew/lib/python3.9/site-packages/pkg_resources/__init__.py:2871: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('mpl_toolkits')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages
    declare_namespace(pkg)

../../../../opt/homebrew/lib/python3.9/site-packages/pkg_resources/__init__.py:2871
../../../../opt/homebrew/lib/python3.9/site-packages/pkg_resources/__init__.py:2871
  /opt/homebrew/lib/python3.9/site-packages/pkg_resources/__init__.py:2871: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('zope')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages
    declare_namespace(pkg)

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
=========================================================================== short test summary info ===========================================================================
ERROR test_abc.py - RuntimeError: cannot release un-acquired lock

zdyj3170101136 commented 9 months ago

deadlock would not happen if not imported gevent.monkey.patch_all() in pytest.

zdyj3170101136 commented 9 months ago

even without gevent.patch_all(), use pytest to run would return error:

import ddtrace.auto
#import gevent.monkey
#gevent.monkey.patch_all()

from ddtrace.profiling import Profiler
import os
import time
prof = Profiler(url="http://127.0.0.1:7070")
prof.start()
time.sleep(3)
print(os.getpid())
prof.stop()
print("wait for stop")

output:

DD_PROFILING_OUTPUT_PPROF=pprof python3.7 -m pytest -s abc.py
========================================================================= test session starts =========================================================================
platform linux -- Python 3.7.7, pytest-7.1.3, pluggy-1.2.0
rootdir: /root
plugins: ddtrace-1.20.16
collecting ... 21399
wait for stop
collected 0 items / 1 error

=============================================================================== ERRORS ================================================================================
_______________________________________________________________________ ERROR collecting abc.py _______________________________________________________________________
/usr/lib/python3.7/importlib/__init__.py:127: in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
<frozen importlib._bootstrap>:1006: in _gcd_import
    ???
<frozen importlib._bootstrap>:983: in _find_and_load
    ???
<frozen importlib._bootstrap>:967: in _find_and_load_unlocked
    ???
<frozen importlib._bootstrap>:682: in _load_unlocked
    ???
E   KeyError: 'root.abc'
======================================================================= short test summary info =======================================================================
ERROR abc.py - KeyError: 'root.abc'

if we do not import ddtrace.auto and gevent.monkey, fined.

zdyj3170101136 commented 9 months ago

when only use gevent.patch and do not import ddtrace.auto.

pytest would deadlock. python would work correct.

P403n1x87 commented 9 months ago

@zdyj3170101136 many thanks for your investigation on this. It looks like our support for gevent in pytest is incomplete. We will look into it.

cc @romainkomorndatadog for (CI) visibility.

romainkomorndatadog commented 6 months ago

I'm not sure this is exactly a pytest / CI App issue.

I can reproduce the deadlock with a call to the CLI that disables the ddtrace plugin altogether:

pytest original_test.py -p no:ddtrace -p no:ddtrace.pytest_bdd -p no:ddtrace.pytest_benchmark

eg:

% pytest original_test.py -p no:ddtrace -p no:ddtrace.pytest_bdd -p no:ddtrace.pytest_benchmark
=============================================================================== test session starts ===============================================================================
platform darwin -- Python 3.11.0, pytest-8.1.1, pluggy-1.4.0
rootdir: /Users/romain.komorn/scratch/geventtest
collected 0 items / 1 error

===================================================================================== ERRORS ======================================================================================
...

In fact, not only can I still reproduce the issue if I comment out every line in our plugins:

ddtrace/contrib/pytest/plugin.py
ddtrace/contrib/pytest_bdd/plugin.py
ddtrace/contrib/pytest_benchmark/plugin.py

but I can still reproduce it if I remove our pytest plugin altogether:

romain.komorn@COMP-CLXFH7L2J3 dd-trace-py % git status
On branch romain.komorn/CIVIS-9657/pytest_gevent_compatibility
Changes to be committed:
  (use "git restore --staged <file>..." to unstage)
    deleted:    ddtrace/contrib/pytest/plugin.py
    deleted:    ddtrace/contrib/pytest_bdd/plugin.py
    deleted:    ddtrace/contrib/pytest_benchmark/plugin.py

Changes not staged for commit:
  (use "git add <file>..." to update what will be committed)
  (use "git restore <file>..." to discard changes in working directory)
    modified:   pyproject.toml

romain.komorn@COMP-CLXFH7L2J3 dd-trace-py % git diff pyproject.toml
diff --git a/pyproject.toml b/pyproject.toml
index f841fdd0e..955849d44 100644
--- a/pyproject.toml
+++ b/pyproject.toml
@@ -56,10 +56,10 @@ ddtrace-run = "ddtrace.commands.ddtrace_run:main"
 [project.entry-points.opentelemetry_context]
 ddcontextvars_context = "ddtrace.opentelemetry._context:DDRuntimeContext"

-[project.entry-points.pytest11]
-ddtrace = "ddtrace.contrib.pytest.plugin"
-"ddtrace.pytest_bdd" = "ddtrace.contrib.pytest_bdd.plugin"
-"ddtrace.pytest_benchmark" = "ddtrace.contrib.pytest_benchmark.plugin"
+#[project.entry-points.pytest11]
+#ddtrace = "ddtrace.contrib.pytest.plugin"
+#"ddtrace.pytest_bdd" = "ddtrace.contrib.pytest_bdd.plugin"
+#"ddtrace.pytest_benchmark" = "ddtrace.contrib.pytest_benchmark.plugin"

 [project.urls]
 "Bug Tracker" = "https://github.com/DataDog/dd-trace-py/issues"

and I still get the hang:

(pytest_civis_9657_dev) romain.komorn@COMP-CLXFH7L2J3 geventtest % python -m pytest -s original_test.py
=============================================================================== test session starts ===============================================================================
platform darwin -- Python 3.11.0, pytest-8.1.1, pluggy-1.4.0
rootdir: /Users/romain.komorn/scratch/geventtest
collecting ... 36537

And just to basically confirm, with our pytest plugin entirely absent as above:

import ddtrace.auto combined with gevent.monkey.patch_all() hangs
import ddtrace.auto without gevent.monkey.patch_all() does not hang
gevent.monkey.patch_all() without import ddtrace.auto does not hang (and import gevent.monkey doesn't seam to factor at all)

Out of further curiosity, I tried using DD_PATCH_MODULES:

DD_PATCH_MODULES="gevent:false" python -m pytest -s original_test.py hangs
DD_PATCH_MODULES="gevent:false" ddtrace-run python -m pytest -s original_test.py does not hang

I assume the latter doesn't hang because, with ddtrace-run, we've already made the decision not to patch gevent by the time it's imported in the test Python file, whereas in the bare python command, import ddtrace.auto doesn't go through DD_PATCH_MODULES.

romainkomorndatadog commented 6 months ago

For further testing, I tried simply removing the profile piece, with a really simple script:

import ddtrace.auto
import gevent.monkey
gevent.monkey.patch_all()

import os
import time
time.sleep(3)
print(os.getpid())
print("wait for stop")

and ran the same type of tests.

As-is, it fails with:

% DD_PATCH_MODULES="gevent:false" python -m pytest -s no_profile_test.py
=============================================================================== test session starts ===============================================================================
platform darwin -- Python 3.11.0, pytest-8.1.1, pluggy-1.4.0
rootdir: /Users/romain.komorn/scratch/geventtest
collecting ... 64395
wait for stop
collected 0 items / 1 error

===================================================================================== ERRORS ======================================================================================
_______________________________________________________________________ ERROR collecting no_profile_test.py _______________________________________________________________________
../../.pyenv/versions/3.11.0/lib/python3.11/importlib/__init__.py:126: in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
<frozen importlib._bootstrap>:1206: in _gcd_import
    ???
<frozen importlib._bootstrap>:1175: in _find_and_load
    ???
<frozen importlib._bootstrap>:174: in __exit__
    ???
<frozen importlib._bootstrap>:129: in release
    ???
E   RuntimeError: cannot release un-acquired lock
============================================================================= short test summary info =============================================================================
ERROR no_profile_test.py - RuntimeError: cannot release un-acquired lock
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Interrupted: 1 error during collection !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
================================================================================ 1 error in 3.30s =================================================================================
Exception ignored in thread started by: <bound method Thread._bootstrap of <PeriodicThread(ddtrace.internal.remoteconfig.worker:RemoteConfigPoller, started daemon 6202781696)>>
Traceback (most recent call last):
  File "/Users/romain.komorn/.pyenv/versions/3.11.0/lib/python3.11/threading.py", line 995, in _bootstrap
    self._bootstrap_inner()
  File "/Users/romain.komorn/.pyenv/versions/3.11.0/lib/python3.11/threading.py", line 1042, in _bootstrap_inner
    self._delete()
  File "/Users/romain.komorn/.pyenv/versions/3.11.0/lib/python3.11/threading.py", line 1074, in _delete
    del _active[get_ident()]
        ~~~~~~~^^^^^^^^^^^^^
KeyError: 4337466688

If I comment out either the import ddtrace.auto or the gevent.monkey.patch_all() lines, nothing complains:

% DD_PATCH_MODULES="gevent:false" python -m pytest -s no_profile_test.py
=============================================================================== test session starts ===============================================================================
platform darwin -- Python 3.11.0, pytest-8.1.1, pluggy-1.4.0
rootdir: /Users/romain.komorn/scratch/geventtest
collecting ... 64988
wait for stop
collected 0 items

============================================================================== no tests ran in 3.06s ==============================================================================

so I think this really points to a bad interaction between ddtrace.auto, gevent.monkey.patch_all(), and pytest.

romainkomorndatadog commented 6 months ago

And finally, I gave pytest-gevent a try, and it appears to (at least) work around the hanging issue (though it swallows the print without passing -s to it):

% pytest-gevent -s original_test.py
=============================================================================== test session starts ===============================================================================
platform darwin -- Python 3.11.0, pytest-8.1.1, pluggy-1.4.0
rootdir: /Users/romain.komorn/scratch/geventtest
collecting ... 68951
Unable to export profile: ddtrace.profiling.exporter.ExportError: HTTP upload request failed: [Errno 61] Connection refused. Ignoring.
wait for stop
collected 0 items

================================================================================ warnings summary =================================================================================
../../go/src/github.com/DataDog/dd-trace-py/ddtrace/bootstrap/sitecustomize.py:42
  /Users/romain.komorn/go/src/github.com/DataDog/dd-trace-py/ddtrace/bootstrap/sitecustomize.py:42: RuntimeWarning: Loading ddtrace after gevent.monkey.patch_all() is not supported and is likely to break the application. Use ddtrace-run to fix this, or import ddtrace.auto before calling gevent.monkey.patch_all().
    warnings.warn(  # noqa: B028

../../go/src/github.com/DataDog/dd-trace-py/ddtrace/provider.py:9
  /Users/romain.komorn/go/src/github.com/DataDog/dd-trace-py/ddtrace/provider.py:9: DDTraceDeprecationWarning: The context provider interface is deprecated.: The trace context is an internal interface and will no longer be supported.
    deprecate(

../../go/src/github.com/DataDog/dd-trace-py/ddtrace/span.py:6
  /Users/romain.komorn/go/src/github.com/DataDog/dd-trace-py/ddtrace/span.py:6: DDTraceDeprecationWarning: The span module is deprecated and will be moved.: A new span interface will be provided by the trace sub-package.
    deprecate(

../../go/src/github.com/DataDog/dd-trace-py/ddtrace/context.py:6
  /Users/romain.komorn/go/src/github.com/DataDog/dd-trace-py/ddtrace/context.py:6: DDTraceDeprecationWarning: The context interface is deprecated.: The trace context is an internal interface and will no longer be supported.
    deprecate(

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
============================================================================== 4 warnings in 27.41s ===============================================================================

romainkomorndatadog commented 6 months ago

And going back to the "real" original state, in an environment with an unmodified ddtrace==2.8.0, the hang also disappears, though we do end up with an error (reliably: I've tried it 3 times):

% pytest-gevent -s original_test.py
=============================================================================== test session starts ===============================================================================
platform darwin -- Python 3.11.0, pytest-8.1.1, pluggy-1.4.0
rootdir: /Users/romain.komorn/scratch/geventtest
plugins: ddtrace-2.8.0
collecting ... 70043
Unable to export profile: ddtrace.profiling.exporter.ExportError: HTTP upload request failed: [Errno 61] Connection refused. Ignoring.
wait for stop
collected 0 items / 1 error

===================================================================================== ERRORS ======================================================================================
________________________________________________________________________ ERROR collecting original_test.py ________________________________________________________________________
../../.pyenv/versions/3.11.0/lib/python3.11/importlib/__init__.py:126: in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
<frozen importlib._bootstrap>:1206: in _gcd_import
    ???
<frozen importlib._bootstrap>:1178: in _find_and_load
    ???
<frozen importlib._bootstrap>:1149: in _find_and_load_unlocked
    ???
<frozen importlib._bootstrap>:701: in _load_unlocked
    ???
E   KeyError: 'original_test'
================================================================================ warnings summary =================================================================================
../../.pyenv/versions/3.11.0/envs/pytest_civis_9657_test/lib/python3.11/site-packages/ddtrace/bootstrap/sitecustomize.py:42
  /Users/romain.komorn/.pyenv/versions/3.11.0/envs/pytest_civis_9657_test/lib/python3.11/site-packages/ddtrace/bootstrap/sitecustomize.py:42: RuntimeWarning: Loading ddtrace after gevent.monkey.patch_all() is not supported and is likely to break the application. Use ddtrace-run to fix this, or import ddtrace.auto before calling gevent.monkey.patch_all().
    warnings.warn(  # noqa: B028

../../.pyenv/versions/3.11.0/envs/pytest_civis_9657_test/lib/python3.11/site-packages/ddtrace/provider.py:9
  /Users/romain.komorn/.pyenv/versions/3.11.0/envs/pytest_civis_9657_test/lib/python3.11/site-packages/ddtrace/provider.py:9: DDTraceDeprecationWarning: The context provider interface is deprecated.: The trace context is an internal interface and will no longer be supported.
    deprecate(

../../.pyenv/versions/3.11.0/envs/pytest_civis_9657_test/lib/python3.11/site-packages/ddtrace/span.py:6
  /Users/romain.komorn/.pyenv/versions/3.11.0/envs/pytest_civis_9657_test/lib/python3.11/site-packages/ddtrace/span.py:6: DDTraceDeprecationWarning: The span module is deprecated and will be moved.: A new span interface will be provided by the trace sub-package.
    deprecate(

../../.pyenv/versions/3.11.0/envs/pytest_civis_9657_test/lib/python3.11/site-packages/ddtrace/context.py:6
  /Users/romain.komorn/.pyenv/versions/3.11.0/envs/pytest_civis_9657_test/lib/python3.11/site-packages/ddtrace/context.py:6: DDTraceDeprecationWarning: The context interface is deprecated.: The trace context is an internal interface and will no longer be supported.
    deprecate(

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
============================================================================= short test summary info =============================================================================
ERROR original_test.py - KeyError: 'original_test'
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Interrupted: 1 error during collection !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
========================================================================== 4 warnings, 1 error in 12.18s ==========================================================================

So, in the end, I don't think, from the pytest plugin side, there's much for us to do as long as the "customer" code imports ddtrace.auto in some way (and I suspect there are other ddtrace imports that would result in the same thing).

ptmcg commented 6 months ago

Here is some added info.

Through our DD support channel, Datadog suggested I convert from using pytest directly to using pytest-gevent. Never having used pytest-gevent, I looked it up in PyPI, which led me to this doc: https://pypi.org/project/pytest-gevent/ and this alternative:

gevent.monkey provides a cli directly, though it's quite clunky to use

python -m gevent.monkey $(which pytest) ...
# with gevent 1.5+ you'll be able to do
# python -m gevent.monkey --module pytest ...

I modified my sample project's tox.ini file changing this:

commands =
    pytest {posargs}

which results in this error:

FAIL Required test coverage not reached.
==================================================================================================================== short test summary info ====================================================================================================================
ERROR example_app/tests/example_namespace_test.py - RuntimeError: cannot release un-acquired lock
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Interrupted: 1 error during collection !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
================================================================================================================= 3 warnings, 1 error in 0.59s ==================================================================================================================
py3-next: exit 2 (1.25 seconds) /Users/me/dev/example_app> pytest pid=66070

to this:

commands =
    python -m gevent.monkey --module pytest {posargs}

which completes successfully.

I'm still looking for a solution that works without us having to update every project in the company.

romainkomorndatadog commented 6 months ago

@ptmcg , I was the "far end" of that support conversation. :)

I agree our gevent integration should "just work" with pytest, but it's good to validate the solution from pytest-gevent (or the -m gevent.monkey).

As an extra detail, are you importing from ddtrace in the codebase(s) you're testing, or only using gevent in the code that's being tested with pytest ?

romainkomorndatadog commented 6 months ago

@ptmcg , another question for you: are you seeing the same kind of deadlocks that this issue originally brought up?

I can't tell from the Interrupted: 1 error during collection message in your paste whether that's a result of you ^Cing out of pytest or if it's pytest exiting on its own.

ptmcg commented 6 months ago

At the moment we have code like this at the top of our __main__.py file, to avoid ddtrace.auto importing with pytest:

if "pytest" not in sys.modules:
    # this import must come before calling gevent.monkey.patch_all()
    # (but fails in pytest)
    import ddtrace.auto  # noqa

import gevent.monkey

# The ideal place to invoke gevent's monkey patch is the first line in the
# __main__.py of the application itself. We've put it here as this will be
# the application entry point and it will be used by the daemon framework.
if not gevent.monkey.is_module_patched("socket"):
    gevent.monkey.patch_all()

So it is rather mysterious to me just how ddtrace is even relevant here when running with pytest. But the fact remains that, all other things being equal, ddtrace < 2 works, but ddtrace >= 2 fails.

And the Interrupted message in my paste was purely from pytest, I did not ^C during this run.

ptmcg commented 6 months ago

If I change that code to (to force the import of ddtrace.auto):

if "pytest" not in sys.modules or True:

I get the deadlock condition, and have to ^C to exit.

romainkomorndatadog commented 6 months ago

@ptmcg , one more question, just to double check: are you looking to use our CI Visibility product (ie: running pytest --ddtrace), or are you always running pytest without --ddtrace?

With regards to why ddtrace factors here, I suspect it's because of our pytest plugins' import ddtrace lines (similar to #4845 ).

I suspect you can validate that by running

pytest -p no:ddtrace -p no:ddtrace.pytest_benchmark -p no:ddtrace.pytest_bdd

which should make your error go away as that stops our plugin modules from being imported by pytest (but that, obviously, disables our CI Visibility functionality).

This is more of a note for us at Datadog, but it looks like this comes down to an order of operations issue in the way things run when pytest is involved because, for example, ddtrace-run pytest seems to work regardless of whether or not gevent is patched: I can get both DD_PATCH_MODULES="gevent:false" ddtrace-run pytest and DD_PATCH_MODULES="gevent:true" ddtrace-run pytest to work on a simple test scenario.

That said, I can't think of any significant changes in the way our pytest plugins import ddtrace. The imports in 1.20 and the imports in 2.x are largely the same.

romainkomorndatadog commented 6 months ago

Another note mostly for Datadog folks: this also looks unrelated to our patching of gevent. I modified our patch() function to return immediately without replacing anything and the issue is still present.

It looks like the main issue is, plainly put: import ddtrace before gevent.monkey.patch_all() causes problems when pytest is executing, regardless of the ddtrace plugin.

Using pytest -p no:ddtrace -p no:ddtrace.pytest_benchmark -p no:ddtrace.pytest_bdd to run pytest without our plugin, I can reintroduce the issue by setting up a conftest.py with just

import ddtrace

Perhaps more relevant, I can introduce the issue by having a test import a file that uses:

import ddtrace
import gevent.monkey
gevent.monkey.patch_all()

import gevent.monkey
import ddtrace
gevent.monkey.patch_all()

But I can't repro the issue using a test that imports a file with:

import gevent.monkey
gevent.monkey.patch_all()
import ddtrace

It made me hope for a quick win by using

import gevent.monkey
gevent.monkey.patch_all()
import ddtrace

at the top of plugin.py, but that does not resolve the issue.

ptmcg commented 6 months ago

@ptmcg , one more question, just to double check: are you looking to use our CI Visibility product (ie: running pytest --ddtrace), or are you always running pytest without --ddtrace?

At this time, we simply run pytest without --ddtrace. If this gets in the way of adopting CI Visibility product in the future, we can burn that bridge when we get to it.

With regards to why ddtrace factors here, I suspect it's because of our pytest plugins' import ddtrace lines (similar to #4845 ).

I suspect you can validate that by running
pytest -p no:ddtrace -p no:ddtrace.pytest_benchmark -p no:ddtrace.pytest_bdd
which should make your error go away as that stops our plugin modules from being imported by pytest (but that, obviously, disables our CI Visibility functionality).

Yes, this runs successfully.

romainkomorndatadog commented 6 months ago

I put together #8999 to defer import ddtrace until we've validated that our pytest plugin is in fact being used (eg: pytest --ddtrace ), but it turns out that we still have an issue with gevent and pytest which comes from ddtrace/__init__.py 's import and enabling of the telemetry writer.

The way pytest discovers modules is through the entry-points.pytest11 project configuration which specifies which modules to import, and since all our plugins live under ddtrace.contrib.*, we end up going through ddtrace/__init__.py on the way.

We're still investigating why and how to deal with this.

brettlangdon commented 5 months ago

We have a change from #9141 which appears to fix this, we are trying to get the fix released in v2.8.4 and v2.9.1 (v2.9.0 release is already in progress so needs to be a bug fix release).