Skip to content
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

Everything hangs when pytest is enabled because of broken test discovery #24501

Closed
somenewacc opened this issue Nov 29, 2024 · 7 comments
Closed
Assignees
Labels
area-testing bug Issue identified by VS Code Team member as probable bug

Comments

@somenewacc
Copy link

somenewacc commented Nov 29, 2024

Type: Bug

Behaviour

When using "python.testing.pytestEnabled": true, in settings.json everything hangs after several file saves.
Python log stops at

Running discovery for pytest using the new test adapter.

It is happening only if there are errors during discovery (no pytest at all, or no pytest output)
Git extension stops working (inifinite loading), codeium stops working, I cannot rename or move files, cannot restart test discovery, etc.
All started from v2024.21.2024111202 (pre-release), v2024.20.0 don't have this issue.

Steps to reproduce:

Method 1 - without pytest:

Setup:

.
├── .vscode
│   └── settings.json
└── a.py

settings.json:

{
    "python.testing.pytestEnabled": true,
}

a.py is empty file

Method 2 - with pytest and broken pytest plugin:

Setup:

.
├── .vscode
│   └── settings.json
└── a.py
└── conftest.py

settings.json:

{
    "python.testing.pytestEnabled": true,
}

a.py:

1 / 0

conftest.py:

pytest_plugins = ('a',)
  1. Go to file a.py;
  2. Press Ctrl+S several times;
  3. Check Python Output window, wait for Running discovery for pytest using the new test adapter. message;
  4. Every other Ctrl+S will result in [error] Test discovery already in progress, not starting a new one..

Diagnostic data

Method 1: Output for Python in the Output panel (ViewOutput, change the drop-down the upper-right of the Output panel to Python)

2024-11-30 02:01:35.587 [info] Experiment 'pythonRecommendTensorboardExt' is active
2024-11-30 02:01:35.587 [info] Experiment 'pythonSurveyNotification' is active
2024-11-30 02:01:35.587 [info] Experiment 'pythonTerminalEnvVarActivation' is active
2024-11-30 02:01:35.587 [info] Experiment 'pythonTestAdapter' is active
2024-11-30 02:01:35.587 [warning] Dir "/home/grigoriy/vscode-test2/.pixi/envs" is not watchable (directory does not exist)
2024-11-30 02:01:35.587 [info] Python interpreter path: /bin/python3
2024-11-30 02:01:35.681 [info] > pyenv which python
2024-11-30 02:01:35.681 [info] cwd: .
2024-11-30 02:01:35.886 [info] Shell integration status changed, can confirm it's working.
2024-11-30 02:01:45.982 [info] Starting Pylance language server.
2024-11-30 02:01:48.125 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:01:48.125 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:01:48.131 [info] All environment variables set for pytest discovery: {...}
2024-11-30 02:01:48.151 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --rootdir=.
2024-11-30 02:01:48.151 [info] cwd: .
2024-11-30 02:01:48.161 [error] /bin/python3: No module named pytest

2024-11-30 02:01:48.172 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2.
2024-11-30 02:01:48.172 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2. Creating and sending error discovery payload
2024-11-30 02:01:48.173 [error] pytest test discovery error for workspace:  /home/grigoriy/vscode-test2 
  
 The python test process was terminated before it could exit on its own, the process errored with: Code: 1, Signal: null for workspace /home/grigoriy/vscode-test2
2024-11-30 02:01:49.968 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:01:49.968 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:01:49.972 [info] arg: --rootdir already exists in args, not adding.
2024-11-30 02:01:49.972 [info] All environment variables set for pytest discovery: {...}
2024-11-30 02:01:50.029 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --rootdir=.
2024-11-30 02:01:50.029 [info] cwd: .
2024-11-30 02:01:50.038 [error] /bin/python3: No module named pytest

2024-11-30 02:01:50.040 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2.
2024-11-30 02:01:50.043 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2. Creating and sending error discovery payload
2024-11-30 02:01:50.043 [error] pytest test discovery error for workspace:  /home/grigoriy/vscode-test2 
  
 The python test process was terminated before it could exit on its own, the process errored with: Code: 1, Signal: null for workspace /home/grigoriy/vscode-test2
2024-11-30 02:01:51.498 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:01:51.498 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:01:51.502 [info] arg: --rootdir already exists in args, not adding.
2024-11-30 02:01:51.502 [info] All environment variables set for pytest discovery: {}
2024-11-30 02:01:51.521 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --rootdir=.
2024-11-30 02:01:51.521 [info] cwd: .
2024-11-30 02:01:51.530 [error] /bin/python3: No module named pytest

2024-11-30 02:01:51.532 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2.
2024-11-30 02:01:51.532 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2. Creating and sending error discovery payload
2024-11-30 02:01:51.532 [error] pytest test discovery error for workspace:  /home/grigoriy/vscode-test2 
  
 The python test process was terminated before it could exit on its own, the process errored with: Code: 1, Signal: null for workspace /home/grigoriy/vscode-test2
2024-11-30 02:01:52.825 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:01:52.825 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:05:33.433 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:05:33.433 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:05:33.434 [error] Test discovery already in progress, not starting a new one.
2024-11-30 02:05:38.123 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:05:38.124 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:05:38.124 [error] Test discovery already in progress, not starting a new one.
2024-11-30 02:05:41.684 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:05:41.684 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:05:41.684 [error] Test discovery already in progress, not starting a new one.

Method 2: Output for Python in the Output panel (ViewOutput, change the drop-down the upper-right of the Output panel to Python)

2024-11-30 02:32:46.928 [info] Experiment 'pythonRecommendTensorboardExt' is active
2024-11-30 02:32:46.928 [info] Experiment 'pythonSurveyNotification' is active
2024-11-30 02:32:46.928 [info] Experiment 'pythonTerminalEnvVarActivation' is active
2024-11-30 02:32:46.928 [info] Experiment 'pythonTestAdapter' is active
2024-11-30 02:32:46.928 [warning] Dir "/home/grigoriy/vscode-test2/.pixi/envs" is not watchable (directory does not exist)
2024-11-30 02:32:46.928 [info] Python interpreter path: /bin/python3
2024-11-30 02:32:46.981 [info] > pyenv which python
2024-11-30 02:32:46.981 [info] cwd: .
2024-11-30 02:32:47.045 [info] > conda info --json
2024-11-30 02:32:59.276 [info] Starting Pylance language server.
2024-11-30 02:32:59.512 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:32:59.512 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:32:59.537 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --rootdir=.
2024-11-30 02:32:59.538 [info] cwd: .
2024-11-30 02:32:59.713 [error] Traceback (most recent call last):
  File "/usr/lib/python3.10/runpy.py", line 196, in _run_module_as_main
...
  File "/home/grigoriy/vscode-test2/a.py", line 1, in <module>
    1 / 0
ZeroDivisionError: division by zero

2024-11-30 02:32:59.736 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2.
2024-11-30 02:32:59.736 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2. Creating and sending error discovery payload
2024-11-30 02:32:59.736 [error] pytest test discovery error for workspace:  /home/grigoriy/vscode-test2 
  
 The python test process was terminated before it could exit on its own, the process errored with: Code: 1, Signal: null for workspace /home/grigoriy/vscode-test2
2024-11-30 02:33:03.004 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:33:03.004 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:33:03.096 [info] arg: --rootdir already exists in args, not adding.
2024-11-30 02:33:03.121 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --rootdir=.
2024-11-30 02:33:03.121 [info] cwd: .
2024-11-30 02:33:03.340 [error] Traceback (most recent call last):
  File "/usr/lib/python3.10/runpy.py", line 196, in _run_module_as_main
...
  File "/home/grigoriy/vscode-test2/a.py", line 1, in <module>
    1 / 0
ZeroDivisionError: division by zero

2024-11-30 02:33:03.368 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2.
2024-11-30 02:33:03.370 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2. Creating and sending error discovery payload
2024-11-30 02:33:03.370 [error] pytest test discovery error for workspace:  /home/grigoriy/vscode-test2 
  
 The python test process was terminated before it could exit on its own, the process errored with: Code: 1, Signal: null for workspace /home/grigoriy/vscode-test2
2024-11-30 02:33:05.948 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:33:05.949 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:33:05.965 [info] arg: --rootdir already exists in args, not adding.
2024-11-30 02:33:05.988 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --rootdir=.
2024-11-30 02:33:05.988 [info] cwd: .
2024-11-30 02:33:06.192 [error] Traceback (most recent call last):
  File "/usr/lib/python3.10/runpy.py", line 196, in _run_module_as_main
...
  File "/home/grigoriy/vscode-test2/a.py", line 1, in <module>
    1 / 0
ZeroDivisionError: division by zero

2024-11-30 02:33:06.212 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2.
2024-11-30 02:33:06.212 [error] Subprocess exited unsuccessfully with exit code 1 and signal null on workspace /home/grigoriy/vscode-test2. Creating and sending error discovery payload
2024-11-30 02:33:06.212 [error] pytest test discovery error for workspace:  /home/grigoriy/vscode-test2 
  
 The python test process was terminated before it could exit on its own, the process errored with: Code: 1, Signal: null for workspace /home/grigoriy/vscode-test2
2024-11-30 02:33:08.693 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:33:08.694 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:33:11.174 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-11-30 02:33:11.174 [info] Running discovery for pytest using the new test adapter.
2024-11-30 02:33:11.175 [error] Test discovery already in progress, not starting a new one.

Extension version: v2024.21.2024112901 (pre-release)
VS Code version: Code 1.95.3 (f1a4fb101478ce6ec82fe9627c43efbf9e98c813, 2024-11-13T14:50:04.152Z)
OS version: Windows_NT x64 10.0.22631
Modes:
Remote OS version: Linux x64 5.15.167.4-microsoft-standard-WSL2

  • Python version (& distribution if applicable, e.g. Anaconda): 3.10.12
  • Type of virtual environment used (e.g. conda, venv, virtualenv, etc.): Global
  • Value of the python.languageServer setting: Default
User Settings


languageServer: "Pylance"

testing
• pytestEnabled: true

Installed Extensions
Extension Name Extension Id Version
JavaScript Debugger ms-vscode.js-debug 1.95.3
Mypy Type Checker ms-python.mypy-type-checker 2024.0.0
Pylance ms-python.vscode-pylance 2024.11.102
Python ms-python.python 2024.21.2024112901
Python Debugger ms-python.debugpy 2024.13.2024112901
Python Environment Manager donjayamanne.python-environment-manager 1.2.4
Python Extension Pack donjayamanne.python-extension-pack 1.7.0
Table Visualizer for JavaScript Profiles ms-vscode.vscode-js-profile-table 1.0.10
A/B Experiments
vsliv368:30146709
vspor879:30202332
vspor708:30202333
vspor363:30204092
pythonvspyt551:31179978
vscod805:30301674
binariesv615:30325510
vsaa593:30376534
py29gd2263:31024239
vscaac:30438847
c4g48928:30535728
azure-dev_surveyone:30548225
2i9eh265:30646982
962ge761:30959799
pythonnoceb:30805159
asynctok:30898717
pythonmypyd1:30879173
h48ei257:31000450
pythontbext0:30879054
cppperfnew:31000557
dsvsc020:30976470
pythonait:31006305
dsvsc021:30996838
dvdeprecation:31068756
dwnewjupyter:31046869
nativerepl2:31139839
pythonrstrctxt:31112756
cf971741:31144450
iacca1:31171482
notype1:31157159
5fd0e150:31155592
dwcopilot:31170013
stablechunks:31184530

@github-actions github-actions bot added the triage-needed Needs assignment to the proper sub-team label Nov 29, 2024
@somenewacc somenewacc changed the title Everything hangs when pytest is enabled because of test discovery Everything hangs when pytest is enabled because of broken test discovery Nov 29, 2024
@eleanorjboyd
Copy link
Member

Hi! What is your goal here with the a.py plugin or is this just a general observation you have regarding ZeroDivisionError handling? Also in the logs for the method 2, are you triggering discovery multiple times or is this all logged after a single attempt? I am seeing it exit the subprocess "python test process was terminated" which should then resolve the test discovery and not hang the UI so curious where it might be messing up in that error handling if the subprocess with pytest does exit correctly.

@github-actions github-actions bot added the info-needed Issue requires more information from poster label Dec 2, 2024
@somenewacc
Copy link
Author

Hi, @eleanorjboyd.

  1. These are just examples of how to trigger this error. I found this in real production with import errors. It can be any exception in plugin code on discovery. There are other cases when it can occur.
    Another example that is not a product case but causes a hang.
    Running pytest with the help parameter:
    settings.json:
{
    "python.testing.pytestArgs": ["--help"],
    "python.testing.pytestEnabled": true,
}
Method 3: Output for Python in the Output panel (ViewOutput, change the drop-down the upper-right of the Output panel to Python)

2024-12-02 21:57:31.407 [info] Experiment 'pythonRecommendTensorboardExt' is active
2024-12-02 21:57:31.407 [info] Experiment 'pythonSurveyNotification' is active
2024-12-02 21:57:31.408 [info] Experiment 'pythonTerminalEnvVarActivation' is active
2024-12-02 21:57:31.408 [info] Experiment 'pythonTestAdapter' is active
2024-12-02 21:57:31.408 [warning] Dir "/home/grigoriy/vscode-test2/.pixi/envs" is not watchable (directory does not exist)
2024-12-02 21:57:31.408 [info] Python interpreter path: /bin/python3
2024-12-02 21:57:31.412 [info] > pyenv which python
2024-12-02 21:57:31.412 [info] cwd: .
2024-12-02 21:57:32.459 [info] > conda info --json
2024-12-02 21:57:33.503 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-12-02 21:57:33.503 [info] Running discovery for pytest using the new test adapter.
2024-12-02 21:57:33.579 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --help --rootdir=.
2024-12-02 21:57:33.579 [info] cwd: .
2024-12-02 21:57:33.710 [info] usage: __main__.py [options] [file_or_dir] [file_or_dir] [...]

positional arguments:
  file_or_dir

general:
  -k EXPRESSION         Only run tests which match the given substring
...
to see available markers type: pytest --markers
to see available fixtures type: pytest --fixtures
(shown according to specified file_or_dir or current dir if not specified; fixtures with leading '_' are only shown with the '-v' option

2024-12-02 21:57:42.984 [info] Starting Pylance language server.
2024-12-02 21:57:44.410 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-12-02 21:57:44.410 [info] Running discovery for pytest using the new test adapter.
2024-12-02 21:57:44.414 [info] arg: --rootdir already exists in args, not adding.
2024-12-02 21:57:44.480 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --help --rootdir=.
2024-12-02 21:57:44.480 [info] cwd: .
2024-12-02 21:57:44.569 [info] usage: __main__.py [options] [file_or_dir] [file_or_dir] [...]

positional arguments:
  file_or_dir

general:
  -k EXPRESSION         Only run tests which match the given substring
...
to see available markers type: pytest --markers
to see available fixtures type: pytest --fixtures
(shown according to specified file_or_dir or current dir if not specified; fixtures with leading '_' are only shown with the '-v' option

2024-12-02 21:57:46.072 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-12-02 21:57:46.072 [info] Running discovery for pytest using the new test adapter.
2024-12-02 21:57:46.076 [info] arg: --rootdir already exists in args, not adding.
2024-12-02 21:57:46.133 [info] > /bin/python3 -m pytest -p vscode_pytest --collect-only --help --rootdir=.
2024-12-02 21:57:46.133 [info] cwd: .
2024-12-02 21:57:46.220 [info] usage: __main__.py [options] [file_or_dir] [file_or_dir] [...]

positional arguments:
  file_or_dir

general:
  -k EXPRESSION         Only run tests which match the given substring
...
to see available markers type: pytest --markers
to see available fixtures type: pytest --fixtures
(shown according to specified file_or_dir or current dir if not specified; fixtures with leading '_' are only shown with the '-v' option

2024-12-02 21:57:47.235 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-12-02 21:57:47.235 [info] Running discovery for pytest using the new test adapter.
2024-12-02 21:59:10.742 [info] Discover tests for workspace name: vscode-test2 - uri: /home/grigoriy/vscode-test2/a.py
2024-12-02 21:59:10.742 [info] Running discovery for pytest using the new test adapter.
2024-12-02 21:59:10.742 [error] Test discovery already in progress, not starting a new one.

  1. I press Ctrl+S multiple times to trigger this (with delay between them), hang happens after several attempts.

@github-actions github-actions bot removed the info-needed Issue requires more information from poster label Dec 2, 2024
@eleanorjboyd
Copy link
Member

hm yes I tried the ["--help"] and it doesn't hang for me- can you attach a screen recording of it happening? Thanks!

@github-actions github-actions bot added the info-needed Issue requires more information from poster label Dec 12, 2024
@somenewacc
Copy link
Author

@eleanorjboyd "hangs" not like UI freeze, but some extensions stop working until reload (can't use git, can't use codeium, discovery won't work anymore, etc).
Maybe the title is too dramatic, I wrote it late night.

I hope this helps:
https://github.com/user-attachments/assets/dc332ebe-7d1d-4665-9481-309bd8c279cd

@github-actions github-actions bot removed the info-needed Issue requires more information from poster label Dec 12, 2024
@eleanorjboyd eleanorjboyd added area-testing bug Issue identified by VS Code Team member as probable bug and removed triage-needed Needs assignment to the proper sub-team labels Dec 16, 2024
@eleanorjboyd
Copy link
Member

wondering if it might be related to this: #24611. The fix is out on insiders tomorrow so you could try and it and test there to see if it is fixed

@aa-sff15
Copy link

yes, this immediately fixed the issue for me, thank you!

@somenewacc
Copy link
Author

@eleanorjboyd yeah, fixed now, thanks

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-testing bug Issue identified by VS Code Team member as probable bug
Projects
None yet
Development

No branches or pull requests

3 participants