New version of vscode doesn't allow pytest plugin proper execution

[PicouAymeric]

After updating vscode some pytest hook functions that were running well before update are not called anymore:

In my case those function are:

@pytest.hookimpl(hookwrapper=True)
def pytest_pycollect_makeitem(self, collector, name, obj):

def pytest_generate_tests(self, metafunc):

@pytest.hookimpl(tryfirst=True, hookwrapper=True)
def pytest_runtest_makereport(self, item, call):

Yet I am sure my plugin is loaded since some of its hooks are called without issues:

def pytest_configure(config):

def pytest_sessionstart(self, session):

@pytest.hookimpl(tryfirst=True)
def pytest_collection(self, session):

def pytest_sessionfinish(self, session: Session, exitstatus):

Executing with pytest.main works perfectly fine.

I can see that behaviour whether I run test collection, run test or run test in debug mode.

Probably the vscode_pytest plugin prevent my functions from being called somehow.

Does anyone has an idea why and how to work it around?

[FrankCRoth]

I had the same issue and reverted back to the previous version to get my tests running again.

[LiteApplication]

In my project I use functions to generate tests, and pytest detects them properly. However when I run them from the vscode extension, the number of tests discovered gets multiplied by 50 (600 -> 3000) and it hangs forever at around 600.

The should be reproducible by cloning the branch nbt-serializable of this repo and executing the tests.

[PicouAymeric]

I found where the issue comes from in my case.
VScode changed the way it is running all tests: before it wasn't giving any test id argument to pytest which pytest understand as "all tests".
Now instead it is giving to pytest the list of all the test ids.
In my case I am editing the list of test to execute in pytest_collection and I wasn't expecting more than one argument in that case.
So I was creating an inconsistent list of test to execute. which was making pytest fail outside of my hooks, resulting in some my hooks that couldn't be executed.
I am surpised of how exceptions are managed in pytest, I would have expected the whole process to fail and not just skipping some hooks without error output in my case. But that's not the subject here.

If you want to test if your issue is also coming from those pytest arguments, you can go to PYTHONPATH/vscode_pytest/run_pytest_script.py, you should have a line that looks like:

arg_array = ["-p", "vscode_pytest"] + args + test_ids_from_buffer

remove "+ test_ids_from_buffer" and test again. this will remove the test id argument and if you have the same issue it should run all the tests.
I hope this helps you.

@LiteApplication I tried to reproduce your issue, but I generate 576 tests, that is what is expected right?

[LiteApplication]

That's expected indeed @PicouAymeric, I'll try your fix to see if it resolves the issue

[PicouAymeric]

BTW I would be curious to know why the devs chose to change the action behind the run button.
Pytest was already doing the job of identifying which test it has to run when we give it no arguments or an incomplete path argument. I never saw any bug with that.

[LiteApplication]

After some more testing, I found that the bug only crashes the window when "View as tree" is selected, not when "View as list" is.
Before running the tests the count does go up to 3k but comes down to around 600 at the end.

After checking again 576 is the exact number of tests needed, and they all pass with @PicouAymeric's fix.

[eleanorjboyd]

Hi everyone- catching up on this now as I was on vacation. Thanks

@PicouAymeric We have always passed specific test ids as args- do you have a different version where you think it didn't / which one is this? Are you specifically talking about using the "run" button at the top of the test explorer to run all tests or are you running specific subsections of tests?

Also @LiteApplication what do you mean by "running the tests the count does go up to 3k", where are you seeing this number?

I will try and repro now and let you know what I find- thanks!

[LiteApplication]

This is the count that goes up

The output of pytest . is

pytest .
================================================================================ test session starts =================================================================================
platform linux -- Python 3.11.9, pytest-7.4.2, pluggy-1.0.0
rootdir: ~/project_root
configfile: pyproject.toml
plugins: cov-5.0.0, httpx-0.24.0, anyio-3.7.1, asyncio-0.21.1
asyncio: mode=Mode.AUTO
collected 736 items                                                                                                                                                                  

tests/mcproto/test_buffer.py ..........                                                                                                                                        [  1%]
tests/mcproto/test_connection.py [more tests ...]

So there should be at most 736 tests, not 3690.

[PicouAymeric]

@eleanorjboyd; I didn't check the version of my Vscode before update, and I don't find any log with that information.
So I don't know if this was my previous version, but I could test with vscode = 1.85.2 and python extension = v2023.8.0
I made a test project with those tests:

When I click on run on the test folder I have the following output:

~\AppData\Local\pypoetry\Cache\virtualenvs\test-vscode-pytest-FbLf_Xbk-py3.11\Scripts\python.exe -m pytest --rootdir .  ./test

When I click on run on subtest:

~\AppData\Local\pypoetry\Cache\virtualenvs\test-vscode-pytest-FbLf_Xbk-py3.11\Scripts\python.exe -m pytest --rootdir .  ./test/subtest

When I click on run on test_module.py:

~\AppData\Local\pypoetry\Cache\virtualenvs\test-vscode-pytest-FbLf_Xbk-py3.11\Scripts\python.exe -m pytest --rootdir .  ./test/subtest/test_module.py

Finally when I click on run on test_function I have:

~\AppData\Local\pypoetry\Cache\virtualenvs\test-vscode-pytest-FbLf_Xbk-py3.11\Scripts\python.exe -m pytest --rootdir . ./test/subtest/test_module.py::test_function

With the new version of vscode / python extension, this would have been something like:

Running pytest with args: ['-p', 'vscode_pytest', '--rootdir=c:\\Users\\aymer\\git\\perso\\test_vscode_pytest', 'c:\\Users\\aymer\\git\\perso\\test_vscode_pytest\\test\\subtest\\test_module.py::test_function', 'c:\\Users\\aymer\\git\\perso\\test_vscode_pytest\\test\\subtest\\test_module.py::test_function2']

[PicouAymeric]

Update: I reinstalled vscode 1.89 and I have the same behaviour, so it seems that it depends only on the Python extension version.

[eleanorjboyd]

This is the count that goes up

The output of pytest . is

pytest .
================================================================================ test session starts =================================================================================
platform linux -- Python 3.11.9, pytest-7.4.2, pluggy-1.0.0
rootdir: ~/project_root
configfile: pyproject.toml
plugins: cov-5.0.0, httpx-0.24.0, anyio-3.7.1, asyncio-0.21.1
asyncio: mode=Mode.AUTO
collected 736 items                                                                                                                                                                  

tests/mcproto/test_buffer.py ..........                                                                                                                                        [  1%]
tests/mcproto/test_connection.py [more tests ...]

So there should be at most 736 tests, not 3690.

seeing this too- will investigate. Does seem different from the other issues but I am not entirely sure yet

[eleanorjboyd]

@PicouAymeric or @FrankCRoth could you send a minimal repro of when you are seeing this problem?

With the new version of vscode / python extension, this would have been something like:

Running pytest with args: ['-p', 'vscode_pytest', '--rootdir=c:\\Users\\aymer\\git\\perso\\test_vscode_pytest', 'c:\\Users\\aymer\\git\\perso\\test_vscode_pytest\\test\\subtest\\test_module.py::test_function', 'c:\\Users\\aymer\\git\\perso\\test_vscode_pytest\\test\\subtest\\test_module.py::test_function2']

in reference to this, what are your args in your settings? And all of these come from the newer broken extension right, and is this a python print statement (so after we append the testIds) or from the extension before the subprocess gets run?

Generally I think some logs would help since that could show me exactly where the problem is happening- could someone add theirs? To do so first set your log level to trace via theDeveloper: set log level command in the command palette then check the output panel and select "python from the dropdown.

[PicouAymeric]

Hi, Sorry, I just got back from vacation.
I published a test repo so you can reproduce: https://github.com/apicouSP/test_vscode
it contains my settings.json file, it is the one created by default when I select pytest.
With the current release version, If you click on run test on the test folder, you can see that:

With the version v2023.8.0 you have:

This is my trace log:

2024-05-13 15:10:23.952 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:10:23.953 [debug] Starting Test Result named pipe
2024-05-13 15:10:23.953 [debug] Creating named pipe server on \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock
2024-05-13 15:10:23.954 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:10:24.010 [debug] Activation Commands received undefined for shell cmd, resource c:\Users\aymer\git\perso\test_vscode and interpreter C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:10:24.012 [debug] Creating named pipe server on \\.\pipe\python-test-ids-ed17aa06f30ad595b8be-sock

[environment variable display]

2024-05-13 15:10:24.029 [info] Running pytest with arguments: c:\Users\aymer\.vscode\extensions\ms-python.python-2024.6.0\python_files\vscode_pytest\run_pytest_script.py --rootdir=c:\Users\aymer\git\perso\test_vscode for workspace c:\Users\aymer\git\perso\test_vscode 

2024-05-13 15:10:24.030 [info] > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe ~\.vscode\extensions\ms-python.python-2024.6.0\python_files\vscode_pytest\run_pytest_script.py --rootdir=.
2024-05-13 15:10:24.030 [info] cwd: .
2024-05-13 15:10:24.284 [debug] new client is connected to the socket, connectionCount:  1 \\.\pipe\python-test-ids-ed17aa06f30ad595b8be-sock
2024-05-13 15:10:24.284 [debug] Test Ids named pipe connected
2024-05-13 15:10:24.284 [debug] new client is connected to the socket, connectionCount:  2 \\.\pipe\python-test-ids-ed17aa06f30ad595b8be-sock
2024-05-13 15:10:24.284 [debug] Test Ids named pipe connected
2024-05-13 15:10:24.339 [debug] client emitted close event, connectionCount:  1
2024-05-13 15:10:24.340 [debug] client emitted close event, connectionCount:  0
2024-05-13 15:10:24.340 [debug] connection count is <= 0, closing the server:  \\.\pipe\python-test-ids-ed17aa06f30ad595b8be-sock
2024-05-13 15:10:24.498 [debug] new client is connected to the socket, connectionCount:  1 \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock
2024-05-13 15:10:24.498 [debug] Test Result named pipe \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock connected
2024-05-13 15:10:24.499 [debug] Test Result named pipe \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock received data
2024-05-13 15:10:24.499 [debug] Test Result named pipe \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock received data
2024-05-13 15:10:24.500 [debug] Test Result named pipe \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock received data
2024-05-13 15:10:24.502 [debug] Test Result named pipe \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock received data
2024-05-13 15:10:24.502 [debug] Test Result named pipe \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock received data
2024-05-13 15:10:24.502 [debug] EOT received, resolving deferredTillServerClose
2024-05-13 15:10:24.503 [debug] client emitted close event, connectionCount:  0
2024-05-13 15:10:24.503 [debug] connection count is <= 0, closing the server:  \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock
2024-05-13 15:10:24.503 [debug] Test Result named pipe \\.\pipe\python-test-results-af6d09e46ea8a9ae05bd-sock closed. Disposing of listener/s.
2024-05-13 15:10:24.534 [debug] Test run finished, subprocess closed.
2024-05-13 15:10:24.534 [debug] Finished running tests, ending runInstance.
2024-05-13 15:10:25.353 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:10:56.433 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:10:59.551 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:11:00.834 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:11:03.966 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:11:11.063 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:11:32.959 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:11:37.688 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:11:45.535 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:11:47.421 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe
2024-05-13 15:12:08.680 [debug] Found cached env for C:\Users\aymer\AppData\Local\Microsoft\WindowsApps\python3.10.exe