I ran into a pretty weird issue while getting a test suite running with pytest. It seems xdist would capture (or preserve, not sure) setup logs only if the setup fixture is running on the same worker. Here is a minimal model of my setup:
import os
import sys
import pytest
import logging
import unittest
from time import sleep
logger = logging.getLogger(__name__)
WORK_MASTER = "EMPTY"
def ingest_file(db_schema, file_path, sep="\t"):
print('Hello world', file=sys.stdout)
logger.warning("Read csv file...")
reading_file = sleep(1)
logger.warning("Table created now")
@pytest.fixture(scope="session", autouse=True)
def setup_session(testrun_uid, worker_id):
global WORK_MASTER
if worker_id == "gw0":
WORK_MASTER = os.environ["PYTEST_XDIST_WORKER"]
logger.warning("Setting up user api environment on: %s", os.environ["PYTEST_XDIST_WORKER"])
TEST_DATA_DIR = '/opt/test-data/user_api'
PROJECT_NAME = 'p0042'
# Run a test file through the standard ingest flow, so it's
# accessible to this test case
ingest_file(f'{PROJECT_NAME}_files', TEST_DATA_DIR, sep="\t")
logger.warning("we are done here")
class OtherUserAPITest(unittest.TestCase):
def setUp(self):
self.oo = object()
def test_sources2(self):
# Should return a sorted list of string names of top-level ingested sources
sleep(2)
assert 1
def test_source3(self):
# Should return a sorted list of string names of top-level ingested sources
assert 1
def test_sources9(self):
# Should return a sorted list of string names of top-level ingested sources
assert 1
def test_name(self):
sleep(10)
global WORK_MASTER
logger.warning("What is going on %s ; %s", os.environ["PYTEST_XDIST_WORKER"], WORK_MASTER)
assert 0
It's not super deterministic, but if you play with if worker_id == "gw0" to if worker_id == "gw1" or vice versa you'll either get:
==================================================================================================================================================================================== test session starts =====================================================================================================================================================================================
platform linux -- Python 3.10.12, pytest-7.4.3, pluggy-1.3.0
rootdir: /home/martin
plugins: xdist-3.5.0
2 workers [4 items]
..F. [100%]
========================================================================================================================================================================================== FAILURES ==========================================================================================================================================================================================
_________________________________________________________________________________________________________________________________________________________________________________ OtherUserAPITest.test_name _________________________________________________________________________________________________________________________________________________________________________________
[gw0] linux -- Python 3.10.12 /ptest/pyt/bin/python3
self = <test_pytest_stuff.OtherUserAPITest testMethod=test_name>
def test_name(self):
sleep(10)
global WORK_MASTER
logger.warning("What is going on %s ; %s", os.environ["PYTEST_XDIST_WORKER"], WORK_MASTER)
> assert 0
E assert 0
test_pytest_stuff.py:57: AssertionError
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Captured stdout setup ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Hello world
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Captured log setup -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
WARNING test_pytest_stuff:test_pytest_stuff.py:25 Setting up user api environment on: gw0
WARNING test_pytest_stuff:test_pytest_stuff.py:15 Read csv file...
WARNING test_pytest_stuff:test_pytest_stuff.py:17 Table created now
WARNING test_pytest_stuff:test_pytest_stuff.py:32 we are done here
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Captured log call --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
WARNING test_pytest_stuff:test_pytest_stuff.py:56 What is going on gw0 ; gw0
===================================================================================================================================================================================== slowest durations ======================================================================================================================================================================================
10.00s call sources/ptest/test_pytest_stuff.py::OtherUserAPITest::test_name
2.00s call sources/ptest/test_pytest_stuff.py::OtherUserAPITest::test_sources2
1.01s setup sources/ptest/test_pytest_stuff.py::OtherUserAPITest::test_name
(9 durations < 0.005s hidden. Use -vv to show these durations.)
================================================================================================================================================================================== short test summary info ===================================================================================================================================================================================
FAILED test_pytest_stuff.py::OtherUserAPITest::test_name - assert 0
================================================================================================================================================================================ 1 failed, 3 passed in 11.54s ================================================================================================================================================================================
Which is what I expect, or:
==================================================================================================================================================================================== test session starts =====================================================================================================================================================================================
platform linux -- Python 3.10.12, pytest-7.4.3, pluggy-1.3.0
rootdir: /home/martin
plugins: xdist-3.5.0
2 workers [4 items]
..F. [100%]
========================================================================================================================================================================================== FAILURES ==========================================================================================================================================================================================
_________________________________________________________________________________________________________________________________________________________________________________ OtherUserAPITest.test_name _________________________________________________________________________________________________________________________________________________________________________________
[gw0] linux -- Python 3.10.12 /ptest/pyt/bin/python3
self = <test_pytest_stuff.OtherUserAPITest testMethod=test_name>
def test_name(self):
sleep(10)
global WORK_MASTER
logger.warning("What is going on %s ; %s", os.environ["PYTEST_XDIST_WORKER"], WORK_MASTER)
> assert 0
E assert 0
test_pytest_stuff.py:57: AssertionError
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Captured log call --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
WARNING test_pytest_stuff:test_pytest_stuff.py:56 What is going on gw0 ; EMPTY
===================================================================================================================================================================================== slowest durations ======================================================================================================================================================================================
10.01s call sources/ptest/test_pytest_stuff.py::OtherUserAPITest::test_name
2.00s call sources/ptest/test_pytest_stuff.py::OtherUserAPITest::test_sources2
1.01s setup sources/ptest/test_pytest_stuff.py::OtherUserAPITest::test_sources2
(9 durations < 0.005s hidden. Use -vv to show these durations.)
================================================================================================================================================================================== short test summary info ===================================================================================================================================================================================
FAILED test_pytest_stuff.py::OtherUserAPITest::test_name - assert 0
================================================================================================================================================================================ 1 failed, 3 passed in 10.59s ================================================================================================================================================================================
if it's running on the other worker. I run like pytest -n 2 --durations=0 test_pytest_stuff.py in both cases. Is this expected behaviour and if so is there a way to always show the setup logs?
I ran into a pretty weird issue while getting a test suite running with pytest. It seems xdist would capture (or preserve, not sure) setup logs only if the setup fixture is running on the same worker. Here is a minimal model of my setup:
It's not super deterministic, but if you play with
if worker_id == "gw0"
toif worker_id == "gw1"
or vice versa you'll either get:Which is what I expect, or:
if it's running on the other worker. I run like
pytest -n 2 --durations=0 test_pytest_stuff.py
in both cases. Is this expected behaviour and if so is there a way to always show the setup logs?