Using pytest, sometimes does not capture stderr

[David]

Hi,

I have just begun using pytest at a basic level and I am
seeing behaviour that I do not understand.

My platform is Debian 10.9

There are 3 files involved, contents are provided below, and attached.
- module_1.py passes the test as expected
- module_2.py has a tiny change, and fails unexpectedly.
- my_test.py runs the same test on each module

Can anyone explain why the module_2.py test fails?
Is it because stderr during module import is not the same as during test?
Is it something to do with mutable defaults?
How to investigate this?
And how can I get the test to pass without changing module_2?

Thanks :)

#---------------------------------------------------------------------
Here is the file module_1.py:
#!/usr/bin/python3
import sys
def msg(*args):
print(*args, file=sys.stderr)

#---------------------------------------------------------------------
Here is the file module_2.py:
#!/usr/bin/python3
import sys
MSG_DESTINATION = sys.stderr
def msg(*args):
print(*args, file=MSG_DESTINATION)

#---------------------------------------------------------------------
Here is the file: my_test.py
#!/usr/bin/python3
import module_1
import module_2
def test__1(capsys):
module_1.msg("a", "message")
captured = capsys.readouterr()
assert captured.err == """a message\n"""
def test__2(capsys):
module_2.msg("a", "message")
captured = capsys.readouterr()
assert captured.err == """a message\n"""

#---------------------------------------------------------------------
Here is the pytest output:

$ pytest-3
======================== test session starts =========================
platform linux -- Python 3.7.3, pytest-3.10.1, py-1.7.0, pluggy-0.8.0
rootdir: /mnt/hart/home/d10/david/work/src/py/lab/pytest/capture/bug, inifile:
collected 2 items
my_test.py .F [100%]
============================== FAILURES ==============================
______________________________ test__2 _______________________________
capsys = <_pytest.capture.CaptureFixture object at 0x7ff6457134a8>
def test__2(capsys):
module_2.msg("a", "message")
captured = capsys.readouterr()
> assert captured.err == """a message\n"""
E AssertionError: assert '' == 'a message\n'
E + a message
my_test.py:14: AssertionError
------------------------ Captured stderr call ------------------------
a message
================= 1 failed, 1 passed in 0.03 seconds =================

[Cameron Simpson]

The code in module_2.py runs at different times.

When it is imported, sys.stderr is the OS-provided stderr. That
reference is kept in MSG_DESTINATION.

Then your test code runs, and changes sys.stderr. It then runs msg(),
which writes to the _original_ sys.stderr as preserved by
MSG_DESTINATION. Thus not captured.

By contrast, module_1.py looks up sys.stderr inside msg(), and finds the
new one the code harness put at sys.stderr. So it writes to the thing
that captures stuff.

Cheers,
Cameron Simpson <c...@cskk.id.au>

[David]

On Mon, 5 Apr 2021 at 13:44, Cameron Simpson <c...@cskk.id.au> wrote:
> On 05Apr2021 13:28, David <bounci...@gmail.com> wrote:

> >Can anyone explain why the module_2.py test fails?
> >Is it because stderr during module import is not the same as during test?
> >Is it something to do with mutable defaults?
> >How to investigate this?
> >And how can I get the test to pass without changing module_2?

> The code in module_2.py runs at different times.

> When it is imported, sys.stderr is the OS-provided stderr. That
> reference is kept in MSG_DESTINATION.

> Then your test code runs, and changes sys.stderr. It then runs msg(),
> which writes to the _original_ sys.stderr as preserved by
> MSG_DESTINATION. Thus not captured.

> By contrast, module_1.py looks up sys.stderr inside msg(), and finds the
> new one the code harness put at sys.stderr. So it writes to the thing
> that captures stuff.

Hi Cameron,

Thanks for confirming my suspicions so quickly. What you wrote
makes sense, but there are two points that still puzzle me.
1) The final line of the pytest failure output seems to shows that
pytest did capture (or is at least aware of) the stderr message
from module_2.
2) My actual code that I would like to test does look like module_2.
Is there any way to test it with pytest?

Thanks.

[Cameron Simpson]

On 05Apr2021 13:56, David <bounci...@gmail.com> wrote:
>On Mon, 5 Apr 2021 at 13:44, Cameron Simpson <c...@cskk.id.au> wrote:
>> On 05Apr2021 13:28, David <bounci...@gmail.com> wrote:
>> >Can anyone explain why the module_2.py test fails?
>> >Is it because stderr during module import is not the same as during test?
>> >Is it something to do with mutable defaults?
>> >How to investigate this?
>> >And how can I get the test to pass without changing module_2?
>
>> The code in module_2.py runs at different times.
>
>> When it is imported, sys.stderr is the OS-provided stderr. That
>> reference is kept in MSG_DESTINATION.
>
>> Then your test code runs, and changes sys.stderr. It then runs msg(),
>> which writes to the _original_ sys.stderr as preserved by
>> MSG_DESTINATION. Thus not captured.
>
>> By contrast, module_1.py looks up sys.stderr inside msg(), and finds the
>> new one the code harness put at sys.stderr. So it writes to the thing
>> that captures stuff.
>

>Thanks for confirming my suspicions so quickly. What you wrote
>makes sense, but there are two points that still puzzle me.
>1) The final line of the pytest failure output seems to shows that
> pytest did capture (or is at least aware of) the stderr message
> from module_2.

Yes. Unsure what's going on there. It could be timing. Suppose this
happens:

- pytest pushes a capturing stderr onto sys.stderr
- pytest loads your module, which imports module_1 and module_2
- the test runner pushes a separate stderr capturer for the test?
- module_1 finds the per-test sys.stderr value
- module_2 finds pytest's outermost capturer (present when it was
imported), and doesn't look up sys.stderr at test time, instead using
the outer capturer

>2) My actual code that I would like to test does look like module_2.
> Is there any way to test it with pytest?

I'd be inclined to give msg() an optional file= parameter:

def msg(*args, file=None):
if file is None:
file = MSG_DESTINATION
print(*args, file=file)

Then your test code can go:

msg("a", "message", file=sys.stderr)

which looks up sys.stderr as it is inside the test itself, and passes it
to msg(). Thus captured.

If you truly need to test msg() _without_ the file= parameter, you could
monkey patch module_2:

old_MSG_DESTINATION = module_2.MSG_DESTINATION
module_2.MSG_DESTINATION = sys.stderr
# now the module_2 module has an updated reference for sys.stderr
...
msg("a", "message")
...
module_2.MSG_DESTINATION = old_MSG_DESTINATION
# normality restored

Cheers,
Cameron Simpson <c...@cskk.id.au>

[David]

On Mon, 5 Apr 2021 at 14:26, Cameron Simpson <c...@cskk.id.au> wrote:

> On 05Apr2021 13:56, David <bounci...@gmail.com> wrote:

> >Thanks for confirming my suspicions so quickly. What you wrote
> >makes sense, but there are two points that still puzzle me.
> >1) The final line of the pytest failure output seems to shows that
> > pytest did capture (or is at least aware of) the stderr message
> > from module_2.

> Yes. Unsure what's going on there. It could be timing. Suppose this
> happens:

> - pytest pushes a capturing stderr onto sys.stderr
> - pytest loads your module, which imports module_1 and module_2
> - the test runner pushes a separate stderr capturer for the test?
> - module_1 finds the per-test sys.stderr value
> - module_2 finds pytest's outermost capturer (present when it was
> imported), and doesn't look up sys.stderr at test time, instead using
> the outer capturer

Ok. I do understand that my function parameter defaults are defined
when the function is defined, so something like this could happen.

> >2) My actual code that I would like to test does look like module_2.
> > Is there any way to test it with pytest?

> I'd be inclined to give msg() an optional file= parameter:

Understood.

> If you truly need to test msg() _without_ the file= parameter, you could
> monkey patch module_2:

I tried this, it works too.

Thanks so much for your guidance! It's great to be steered through
puzzlement by experts. I hope you're having a good day, you made
mine better :)

[Peter Otten]

On 05/04/2021 06:25, Cameron Simpson wrote:

> If you truly need to test msg() _without_ the file= parameter, you could
> monkey patch module_2:
>

> old_MSG_DESTINATION = module_2.MSG_DESTINATION
> module_2.MSG_DESTINATION = sys.stderr
> # now the module_2 module has an updated reference for sys.stderr
> ...
> msg("a", "message")
> ...
> module_2.MSG_DESTINATION = old_MSG_DESTINATION
> # normality restored

I was about to write "use contextlib.redirect_sterr()", and noted my
error just before hitting send. There is a tool in the stdlib that might
work though:

from unittest import mock

with mock.patch("module_2.MSG_DESTINATION", sys.stderr):

[Peter Otten]