Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

crash on bad stdout #412

Closed
pytestbot opened this issue Dec 23, 2013 · 10 comments
Closed

crash on bad stdout #412

pytestbot opened this issue Dec 23, 2013 · 10 comments
Labels
type: bug problem that needs to be addressed

Comments

@pytestbot
Copy link
Contributor

Originally reported by: Alexander Steinert (BitBucket: stony8, GitHub: stony8)


In one of our tests, we get bad output on stdout. We have to fix that
ourselves, sure. However, the problem with pytest is that instead of failing
only the test the whole session crashes. Here's a minimal example where the bad
output is generated by a subprocess for reasons of simplicity.

#!python
from subprocess import call
from sys import executable
def test():
    call([executable, '-c', r'open("/proc/self/fd/1", "wb").write(b"\xc3")'])
    assert 0

This is the behavior of pytest 2.5.1. It crashes without any notice!

#!
============================= test session starts ==============================
platform linux2 -- Python 3.2.3 -- pytest-2.5.1
collected 1 items

test_bad_stdout.py

Exit code is 3.

In pytest 2.3.5, the behavior was a little better. Nevertheless the session is
still over immediately. No further tests get executed, no report gets written.

#!
============================= test session starts ==============================
platform linux2 -- Python 3.2.3 -- pytest-2.3.5
collected 1 items

test_bad_stdout.py 
INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/main.py", line 81, in wrap_session
INTERNALERROR>     doit(config, session)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/main.py", line 115, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 441, in __call__
INTERNALERROR>     return self._docall(methods, kwargs)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 452, in _docall
INTERNALERROR>     res = mc.execute()
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 370, in execute
INTERNALERROR>     res = method(**kwargs)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/main.py", line 135, in pytest_runtestloop
INTERNALERROR>     item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 441, in __call__
INTERNALERROR>     return self._docall(methods, kwargs)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 452, in _docall
INTERNALERROR>     res = mc.execute()
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 370, in execute
INTERNALERROR>     res = method(**kwargs)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/runner.py", line 62, in pytest_runtest_protocol
INTERNALERROR>     runtestprotocol(item, nextitem=nextitem)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/runner.py", line 72, in runtestprotocol
INTERNALERROR>     reports.append(call_and_report(item, "call", log))
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/runner.py", line 108, in call_and_report
INTERNALERROR>     report = hook.pytest_runtest_makereport(item=item, call=call)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/main.py", line 159, in call_matching_hooks
INTERNALERROR>     return hookmethod.pcall(plugins, **kwargs)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 445, in pcall
INTERNALERROR>     return self._docall(methods, kwargs)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 452, in _docall
INTERNALERROR>     res = mc.execute()
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/core.py", line 370, in execute
INTERNALERROR>     res = method(**kwargs)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/capture.py", line 172, in pytest_runtest_makereport
INTERNALERROR>     outerr = self.suspendcapture(item)
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/_pytest/capture.py", line 111, in suspendcapture
INTERNALERROR>     outerr = cap.suspend()
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/py/_io/capture.py", line 173, in suspend
INTERNALERROR>     outerr = self.readouterr()
INTERNALERROR>   File "/tmp/venv/lib/python3.2/site-packages/py/_io/capture.py", line 260, in readouterr
INTERNALERROR>     res = f.read()
INTERNALERROR>   File "/tmp/venv/lib/python3.2/codecs.py", line 300, in decode
INTERNALERROR>     (result, consumed) = self._buffer_decode(data, self.errors, final)
INTERNALERROR> UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc3 in position 0: unexpected end of data

===============================  in 0.06 seconds ===============================

Exit code is 3, too.

Why is pytest decoding captured output anyway? Wouldn't it be less error-prone
to capture it as-is (binary) and (on test failure) write is as-is?


@pytestbot
Copy link
Contributor Author

Original comment by Floris Bruynooghe (BitBucket: flub, GitHub: flub):


Hi, it seems I can't reproduce this. Both with 2.5.1 and with the current trunk py.test seems to capture the output correctly and simply shows the unicode replacement character (the ? in a diamond shape).

@pytestbot
Copy link
Contributor Author

Original comment by Ronny Pfannschmidt (BitBucket: RonnyPfannschmidt, GitHub: RonnyPfannschmidt):


can reproduce a crash with a os.write(1, mess)

@pytestbot
Copy link
Contributor Author

Original comment by eduardo schettino (BitBucket: schettino72, GitHub: schettino72):


I reproduced the problem with python 3.3, seems it is fine with python2.7.

The problem that not even a INTERNALERROR message is displayed was introduced on changeset: 3122:6d1e3a0d4746
( avoid "IOError: Bad Filedescriptor" on pytest shutdown by not closing )
but it seems there were many changes after that.

From what I understood the "unconfigure" methods are not even called,
using pdb I could see the execption "reading from stdin while output is captured".
not sure this was just bad interference from pdb itself.

@pytestbot
Copy link
Contributor Author

Original comment by Ronny Pfannschmidt (BitBucket: RonnyPfannschmidt, GitHub: RonnyPfannschmidt):


figured the root causes, we have a rough idea of the actions to take, its too big for the bug day tho

@pytestbot
Copy link
Contributor Author

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


@RonnyPfannschmidt is aiming to resolve this problem and cleanup our capturing code in a separate branch. https://bitbucket.org/RonnyPfannschmidt/pytest-capture-refactor

@pytestbot
Copy link
Contributor Author

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


Ronny, i can't reproduce the problem with current trunk. Could you commit an xfailing test?

@pytestbot
Copy link
Contributor Author

Original comment by Ronny Pfannschmidt (BitBucket: RonnyPfannschmidt, GitHub: RonnyPfannschmidt):


add changelog entry:
fix issue412: messing with stdout/stderr FD-level streams is now
captured without crashes.

@pytestbot
Copy link
Contributor Author

Original comment by Ronny Pfannschmidt (BitBucket: RonnyPfannschmidt, GitHub: RonnyPfannschmidt):


fix issue412 and other encoding issues. Streamline dupfile() into
a new more thoughtful safe_text_dupfile helper.

@pytestbot
Copy link
Contributor Author

Original comment by Alexander Steinert (BitBucket: stony8, GitHub: stony8):


Fix verified for 9eeb7bb8cf81.

@pytestbot
Copy link
Contributor Author

Original comment by Erik Bray (BitBucket: embray, GitHub: embray):


So the fix for this (I think) has caused several of my tests which test distutils to break, due to a line in the distutils logger which checks for stream.errors on sys.stdout and sys.stderr. Now these have been replace with _io.FileIO objects leading to this crash:

/internal/1/root/usr/local/lib/python3.4/distutils/core.py:149: in setup
    dist.run_commands()
/internal/1/root/usr/local/lib/python3.4/distutils/dist.py:955: in run_commands
    self.run_command(cmd)
/internal/1/root/usr/local/lib/python3.4/distutils/dist.py:971: in run_command
    log.info("running %s", command)
/internal/1/root/usr/local/lib/python3.4/distutils/log.py:44: in info
    self._log(INFO, msg, args)
/internal/1/root/usr/local/lib/python3.4/distutils/log.py:30: in _log
    if stream.errors == 'strict':
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <_pytest.capture.EncodedFile object at 0x7f64cae194a8>, name = 'errors'

    def __getattr__(self, name):
>       return getattr(self.buffer, name)
E       AttributeError: '_io.FileIO' object has no attribute 'errors'

/internal/1/root/usr/local/lib/python3.4/site-packages/_pytest/capture.py:242: AttributeError

I'm inclined to place the blame on distutils for assuming sys.stdout/err will have a .errors attribute. But I wonder if there's a decent workaround for this?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: bug problem that needs to be addressed
Projects
None yet
Development

No branches or pull requests

1 participant