capsys fixture does not collect the same test output as reported by pytest

[pytestbot]

Originally reported by: Jurko Gospodnetić (BitBucket: jurko, GitHub: jurko)

---

I noticed that test fixture output gets reported by pytest as part of the output captured for a particular test. However, when you use the capsys fixture to access all the output collected for that test - test fixture output is not included and instead still gets reported as captured output at the end of the test.

You can use the following test to illustrate the problem. Just run it as a part of the internal pytest test suite.

import fnmatch

def test_consistent_reported_and_capsys_test_output(testdir):
    """
    capsys test fixture should allow collecting complete test output.

    Running a test with the capsys fixture should allow the test to collect the
    exact same output as reported by pytest when running a matching test
    without using capsys.

    Illustrates a defect in pytest 2.5.0 where capsys does not allow accessing
    fixture output but still reports that output as part of the test's captured
    output.

    """
    testdir.makepyfile(r"""\
import pytest

@pytest.fixture()
def ola(request):
    print("<DIRECT> in the fixture")

def do_the_unga_bunga(capsys=None):
    print("<DIRECT> in the test")
    if capsys:
        out, err = capsys.readouterr()
        for line in out[:-1].split("\n"):
            print("<CAPSYS> %s" % (line[9:],))
    pytest.fail()

def test_direct(ola):
    do_the_unga_bunga()

def test_with_capsys(ola, capsys):
    do_the_unga_bunga(capsys)
""")

    result = testdir.runpytest("--tb=short", "-k", "test_direct")
    output = result.stdout.lines
    direct_lines = fnmatch.filter(output, "<DIRECT>*")
    capsys_lines = fnmatch.filter(output, "<CAPSYS>*")
    assert len(direct_lines) == 2
    assert len(capsys_lines) == 0
    output_direct = [x[9:] for x in direct_lines]

    result = testdir.runpytest("--tb=short", "-k", "test_with_capsys")
    output = result.stdout.lines
    direct_lines = fnmatch.filter(output, "<DIRECT>*")
    capsys_lines = fnmatch.filter(output, "<CAPSYS>*")
    assert len(direct_lines) + len(capsys_lines) == 2
    output_capsys = [x[9:] for x in capsys_lines]
    assert output_direct == output_capsys

The test can be instrumented with more precise assertions that would fail earlier, but as it stands, it illustrates exactly the point I'm trying to make here - that the directly captured output and the output captured via capsys do not match.

Hope this helps.

Best regards,
Jurko Gospodnetić

---

• Bitbucket: https://bitbucket.org/pytest-dev/pytest/issue/439

[pytestbot]

Original comment by Jurko Gospodnetić (BitBucket: jurko, GitHub: jurko):

---

My suggestion would be to make capsys collect all the output reported as captured for the particular test.

[pytestbot]

Original comment by holger krekel (BitBucket: hpk42, GitHub: hpk42):

---

currently, captured output includes the setup output. We actually go through some effort to show the setup-captured along with the failed captured output. It's shown in a different section. So i am not sure we should really regard this as a bug. If you agree please close this, otherwise please suggest what should be changed concretely.

[pytestbot]

Original comment by Jurko Gospodnetić (BitBucket: jurko, GitHub: jurko):

---

My point in this issue is that pytest does internally capture both setup & test output (and displays both after a failing test), but does not make that captured setup output available to the test code.

In a test function you can use capsys/capfd fixtures to get access to the output captured by pytest, but that output does not seem to include the output captured during the test setup phase. Even though, later, that output gets reported as part of the output captured for this test.

I would like for tests to be able to access the same captured output as pytest reports capturing for that test. This is something a test developer expects when he uses a system provided to allow access to the captured output, and not you can get only some of the captured output, we already captured some more, we'll tell you about it later but we'll not show it to you until then. 😄

My preferred solution would be for capsys/capfd fixtures to be updated so when their readouterr() method is called for the first time in a test, its results include the output captured during that test's setup phase. If a test developer explicitly wants to ignore such output - he can just call readouterr() once at the start of the test and ignore its results.

If the suggested solution risks causing too many backward compatibility issues, I guess a separate captured_setup_output_sys/captured_setup_output_fd set of fixtures could be added instead (exact naming unimportant). But I do not really like this solution as it makes the pytest interface more complex than needed.

In any case, if capsys/capfd fixture implementation stays as it is now, its documentation should be updated to state explicitly that they do not provide access to output captured during the test setup phase. Then you at least have the RTFM argument available. 😉

Best regards,
Jurko Gospodnetić

[pytestbot]

Original comment by Jurko Gospodnetić (BitBucket: jurko, GitHub: jurko):

---

Oh, and if you want, I can easily add a similar test using the capfd fixture.

Best regards,
Jurko Gospodnetić

[pytestbot]

Original comment by Jurko Gospodnetić (BitBucket: jurko, GitHub: jurko):

---

Just one more thing... 😄

Reading the captured output via capsys/capfd, automatically removes that output from the one reported by pytest when the test fails. If this behaviour is not changed - then reading the captured setup test output should prevent that output from being reported by pytest as well.

However there is one thing that is slightly different in this case - if a test wants to have access to captured output and still have that output displayed by pytest, it needs to collect all the captured output and print it out again itself at the end of the test (preferably in a finally block to make sure it gets printed out in case of a failure). This works correctly for output captured during the test's execute phase, but with output captured during the test's setup phase that will make the output be displayed in a different output section.

Best regards,
Jurko Gospodnetić

P.S.
This reading erases the captured output behaviour is something I do not really like but that's a separate issue to be raised some other time. 😄

[pytestbot]

Original comment by holger krekel (BitBucket: hpk42, GitHub: hpk42):

---

I must say that i disagree. capsys/fd is meant for capturing output during the actual test execution. Especially with trunk the "setup" phase is reported separately (that used to be different with 2.5.2 where you couldn't see if output came from setup or test call). So the expectation that "capsys" captures during setup is wrong IMHO. Unless i am missing something i am thus inclined to mark this issue as invalid. We could go for a clarification in the docs if you think it's needed, though.

[pytestbot]

Original comment by Jurko Gospodnetić (BitBucket: jurko, GitHub: jurko):

---

Ok, I originally ran into this back when you couldn't see if captured test output came from the test itself or its setup phase. I'm fine with a doc update.

I know, I know... pull requests welcome... I'll look into it... 😄

Adding support for tests accessing the output captured during their setup phase can be implemented later on when we have an actual use case requiring it. My original use case has since been patched up to work well enough for my needs.

Best regards,
Jurko Gospodnetić

[pytestbot]

Original comment by holger krekel (BitBucket: hpk42, GitHub: hpk42):

---

fix issue439: clarify that capsys/capfd capture output during
test execution, not test setup.