Issues with --capture=no and parallelization (-n 2)

[otrejoso]

I'm trying to debug a problem that I have with our tests running in parallel, but I have hit couple of issues that have made my life a little harder 😓 .

I'm trying to run the following code:

import pytest


@pytest.fixture(scope="class")
def my_fixture(request):
    print("setup")
    yield
    print("teardown")


class TestClass:
    def test_1(self, my_fixture):
        print("test 1")

    def test_2(self, my_fixture):
        print("test 2")

If I run the above tests with the following command pytest test_scope.py -s -v the print statements are shown correctly in the std output:

$ pytest test_scope.py -s -v
============================================================================================= test session starts ============================================================================================== platform win32 -- Python 3.7.2, pytest-6.2.4, py-1.10.0, pluggy-0.13.1 -- c:\depot\bitbucket\test\scopes\venv\scripts\python.exe
cachedir: .pytest_cache
rootdir: C:\depot\bitbucket\test\scopes
plugins: forked-1.3.0, xdist-2.2.1
collected 2 items

test_scope.py::TestClass::test_1 setup
test 1
PASSED
test_scope.py::TestClass::test_2 test 2
PASSEDteardown

but I run them in paralllel, -s seems to have no effect pytest test_scope.py -s -v -n 2

$ pytest test_scope.py -s -v -n 2
============================================================================================= test session starts ============================================================================================== platform win32 -- Python 3.7.2, pytest-6.2.4, py-1.10.0, pluggy-0.13.1 -- c:\depot\bitbucket\test\scopes\venv\scripts\python.exe
cachedir: .pytest_cache
rootdir: C:\depot\bitbucket\test\scopes
plugins: forked-1.3.0, xdist-2.2.1
[gw0] win32 Python 3.7.2 cwd: C:\depot\bitbucket\test\scopes
[gw1] win32 Python 3.7.2 cwd: C:\depot\bitbucket\test\scopes
[gw0] Python 3.7.2 (tags/v3.7.2:9a3ffc0492, Dec 23 2018, 23:09:28) [MSC v.1916 64 bit (AMD64)]
[gw1] Python 3.7.2 (tags/v3.7.2:9a3ffc0492, Dec 23 2018, 23:09:28) [MSC v.1916 64 bit (AMD64)]
gw0 [2] / gw1 [2]
scheduling tests via LoadScheduling

test_scope.py::TestClass::test_2
test_scope.py::TestClass::test_1
[gw1] PASSED test_scope.py::TestClass::test_2
[gw0] PASSED test_scope.py::TestClass::test_1

============================================================================================== 2 passed in 0.70s ===============================================================================================

Any ideas, or am I missing something? Thanks in advance.

[RonnyPfannschmidt]

due to how xdist is implemented, -s cant be supported/used at the same time

[nicoddemus]

Indeed. Wrote pytest-dev/pytest-xdist#666 to clarify that in the README as this is a common source of confusion.

[otrejoso]

Ok... I see... So let me rephrase my question then/explain the issue that I was trying to debug and see if there is any suggestions.
How would you go about debugging the following situation? Because there is something that I don't quite understand.

I have a fixture that is scoped as a class. As the example above. Now, I have always thought that how a fixture that is scoped as a class will run the setup fixture -> run all tests -> run tear down fixture.
But when I use -n 2, that doesn't seem to be the case. As far as can I see, this is what happens.

setup fixture -> run test 1 -> run tear down fixture
_____________|
_____________|-> run test 2 -> run tear down fixture

Now that causes conflicts because tear down seems to be executed twice instead of one. I cannot really figure out what is happening since the methods of debugging this seems to be limited as you pointed out for -s

This is what I did and my reasoning behind of my "theory"

If I run the following code:

import pytest


@pytest.fixture(scope="class")
def my_fixture(request):
    pytest.set_trace()
    print("setup")
    # print(request.config.workerinput)
    yield
    pytest.set_trace()
    print("teardown")
    # print(request.config.workerinput)
    # assert False


class TestClass:
    def test_1(self, my_fixture):
        pytest.set_trace()
        print("test 1")

    def test_2(self, my_fixture):
        pytest.set_trace()
        print("test 2")

with following command pytest test_scope.py -v --pdb, I get:

============================================================================================= test session starts ============================================================================================== platform win32 -- Python 3.7.2, pytest-6.2.4, py-1.10.0, pluggy-0.13.1 -- c:\depot\bitbucket\test\scopes\venv\scripts\python.exe
cachedir: .pytest_cache
rootdir: C:\depot\bitbucket\test\scopes
plugins: forked-1.3.0, xdist-2.2.1
collected 2 items

test_scope.py::TestClass::test_1
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB set_trace (IO-capturing turned off) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> > c:\depot\bitbucket\test\scopes\test_scope.py(7)my_fixture()
-> print("setup")
(Pdb) c

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB continue (IO-capturing resumed) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB set_trace (IO-capturing turned off) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> > c:\depot\bitbucket\test\scopes\test_scope.py(19)test_1()
-> print("test 1")
(Pdb) c

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB continue (IO-capturing resumed) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PASSED                                                                                                                                                                   [ 50%]
test_scope.py::TestClass::test_2
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB set_trace (IO-capturing turned off) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> > c:\depot\bitbucket\test\scopes\test_scope.py(23)test_2()
-> print("test 2")
(Pdb) c

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB continue (IO-capturing resumed) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PASSED                                                                                                                                                                   [100%]
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB set_trace (IO-capturing turned off) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> > c:\depot\bitbucket\test\scopes\test_scope.py(11)my_fixture()
-> print("teardown")
(Pdb) c

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> PDB continue (IO-capturing resumed) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>


============================================================================================== 2 passed in 2.98s ===============================================================================================

which is what I have always expected fixtures work.

As I explained above, I have bigger issue in bigger code line where tests are running in parallel and the tear down is erroring out, and since I cannot use --pdb nor -s with -n 2, the best I could come with is the following to come up with my "theory"

import pytest


@pytest.fixture(scope="class")
def my_fixture(request):
    # pytest.set_trace()
    print("setup")
    print(request.config.workerinput)
    yield
    # pytest.set_trace()
    print("teardown")
    print(request.config.workerinput)
    assert False


class TestClass:
    def test_1(self, my_fixture):
        # pytest.set_trace()
        print("test 1")

    def test_2(self, my_fixture):
        # pytest.set_trace()
        print("test 2")

NOTE: Keep in mind that I have commented out the pytest.set_trace() and add the assert False after yield as well as print(request.config.workerinput)

Doing that, I get:

$ pytest test_scope.py -v -n 2
============================================================================================= test session starts ============================================================================================== platform win32 -- Python 3.7.2, pytest-6.2.4, py-1.10.0, pluggy-0.13.1 -- c:\depot\bitbucket\test\scopes\venv\scripts\python.exe
cachedir: .pytest_cache
rootdir: C:\depot\bitbucket\test\scopes
plugins: forked-1.3.0, xdist-2.2.1
[gw0] win32 Python 3.7.2 cwd: C:\depot\bitbucket\test\scopes
[gw1] win32 Python 3.7.2 cwd: C:\depot\bitbucket\test\scopes
[gw0] Python 3.7.2 (tags/v3.7.2:9a3ffc0492, Dec 23 2018, 23:09:28) [MSC v.1916 64 bit (AMD64)]
[gw1] Python 3.7.2 (tags/v3.7.2:9a3ffc0492, Dec 23 2018, 23:09:28) [MSC v.1916 64 bit (AMD64)]
gw0 [2] / gw1 [2]
scheduling tests via LoadScheduling

test_scope.py::TestClass::test_1
test_scope.py::TestClass::test_2
[gw1] [ 50%] PASSED test_scope.py::TestClass::test_2
[gw0] [100%] PASSED test_scope.py::TestClass::test_1
[gw0] [100%] ERROR test_scope.py::TestClass::test_1
[gw1] [100%] ERROR test_scope.py::TestClass::test_2

==================================================================================================== ERRORS ==================================================================================================== ____________________________________________________________________________________ ERROR at teardown of TestClass.test_1 _____________________________________________________________________________________ [gw0] win32 -- Python 3.7.2 c:\depot\bitbucket\test\scopes\venv\scripts\python.exe

request = <SubRequest 'my_fixture' for <Function test_1>>

    @pytest.fixture(scope="class")
    def my_fixture(request):
        # pytest.set_trace()
        print("setup")
        print(request.config.workerinput)
        yield
        # pytest.set_trace()
        print("teardown")
        print(request.config.workerinput)
>       assert False
E       assert False

test_scope.py:13: AssertionError
-------------------------------------------------------------------------------------------- Captured stdout setup --------------------------------------------------------------------------------------------- setup
{'workerid': 'gw0', 'workercount': 2, 'testrunuid': '42604c0a7590451fb3fff45651387abd', 'mainargv': ['C:\\depot\\bitbucket\\test\\scopes\\venv\\Scripts\\pytest', 'test_scope.py', '-v', '-n', '2']}
--------------------------------------------------------------------------------------------- Captured stdout call --------------------------------------------------------------------------------------------- test 1
------------------------------------------------------------------------------------------- Captured stdout teardown ------------------------------------------------------------------------------------------- teardown
{'workerid': 'gw0', 'workercount': 2, 'testrunuid': '42604c0a7590451fb3fff45651387abd', 'mainargv': ['C:\\depot\\bitbucket\\test\\scopes\\venv\\Scripts\\pytest', 'test_scope.py', '-v', '-n', '2']}
____________________________________________________________________________________ ERROR at teardown of TestClass.test_2 _____________________________________________________________________________________ [gw1] win32 -- Python 3.7.2 c:\depot\bitbucket\test\scopes\venv\scripts\python.exe

request = <SubRequest 'my_fixture' for <Function test_2>>

    @pytest.fixture(scope="module")
    def my_fixture(request):
        # pytest.set_trace()
        print("setup")
        print(request.config.workerinput)
        yield
        # pytest.set_trace()
        print("teardown")
        print(request.config.workerinput)
>       assert False
E       assert False

test_scope.py:13: AssertionError
-------------------------------------------------------------------------------------------- Captured stdout setup --------------------------------------------------------------------------------------------- setup
{'workerid': 'gw1', 'workercount': 2, 'testrunuid': '42604c0a7590451fb3fff45651387abd', 'mainargv': ['C:\\depot\\bitbucket\\test\\scopes\\venv\\Scripts\\pytest', 'test_scope.py', '-v', '-n', '2']}
--------------------------------------------------------------------------------------------- Captured stdout call --------------------------------------------------------------------------------------------- test 2
------------------------------------------------------------------------------------------- Captured stdout teardown ------------------------------------------------------------------------------------------- teardown
{'workerid': 'gw1', 'workercount': 2, 'testrunuid': '42604c0a7590451fb3fff45651387abd', 'mainargv': ['C:\\depot\\bitbucket\\test\\scopes\\venv\\Scripts\\pytest', 'test_scope.py', '-v', '-n', '2']}
=========================================================================================== short test summary info ============================================================================================ ERROR test_scope.py::TestClass::test_1 - assert False
ERROR test_scope.py::TestClass::test_2 - assert False
========================================================================================= 2 passed, 2 errors in 0.69s ==========================================================================================

Based on that, I see that each worker is doing a print with different workerIds which doesn't seem right since it is scoped as class.

In my actual issue in our code line, the tear down is moving a file which fails on some tests since the tear down of a previous test has already moved the file.

I know it is big example, but I was hoping you can help me out here to understand what is going on.