Ensure stdin and stdout are in blocking mode before writing test summary #2251
Comments
|
without more context on how/what you run we will have to assume you created this problem yourself |
|
The error is being raised when writing to the terminal, although you're running @godfryd without more information it is hard to pin-point the problem. |
|
I run the tests in parallel, there are 6 processes. How do you see adding there a loop with try/except for that kind of error? Now, I'm trying py-1.4.32. Thanks for the tip. |
|
Does your project do anything related to the terminal, stdout or stderr at all? Is it running locally only or remotely?
Perhaps you can isolate the problem in a reproducible example?
I'm afraid adding such a try/except to Having said that you can fork |
|
Updating py to version 1.4.32 didn't help. |
One idea is to monkeypatch import pytest
import sys
def boom_it(): assert 0
sys.stdout.close = boom_it
pytest.main()Then execute that script instead of Other than that, without looking at some code is hard to suggest what that the problem might be. |
|
(Just realized 4 probably won't find your problem, because you would probably get an |
|
Closing from lack of response. |
|
We are constantly running into this fault. It seems like the capture functionality of pytest causes this. Basically the problem disappears when capturing of test output is disabled. However, this make the test logs unreadable due to the bulk of non-error output. I'll try to reproduce. |
|
@tlandschoff-scale |
|
Unfortunately we are still at an ancient pytest version and I am still unable to reproduce this problem. Most of the time this was triggered in a plugin I wrote to report left over threads. I tried to dive down into the cause there but adding debugging code (catching the error and retrying) caused the problem to disappear as it seems. With pytest 3.7.4 we get this traceback: It seems to suffice that a test case creates a lot of output on stdout. But running just this (failing) test does not reproduce the IOError. I assume that some SIGCHLD handler is involved, but was not able to pinpoint this. |
No, apart from some tests starting child processes and using threads, but nothing driven from pytest. |
|
I have no idea how this fails for us at random intervals. I just created a test case that forks hundreds of threads, writes thousands of lines to stdout and then fails, having all the processes terminate starting at that instant. Works fine, not causing the "resource temporarily unavailable". Frankly I have no idea what could cause this on stdout. |
I'd only investigate further after updating that - it might be fixed already, and you are wasting time there then that is better spent upgrading. |
|
Thing is that fil.write refers to stdout and returns EAGAIN, which can never happen as far as I know. The problem manifests itself only in our GitLab CI, never on a local machine. About every 3rd test run fails because of that. What I want to say: I don't think that upgrading pytest will change anything here as writing a blocking stdout should not return EAGAIN. |
Seems to be possible: It depends probably on if stdout is set or blocking or not, which might be something that GitLab is doing. Maybe pytest's capturing could ensure that it is not blocking? |
|
I added reporting of the O_NONBLOCK flag on sys.stdout to our tests. It is unset at test setup and also at teardown. I wonder if it is set temporarily by some test or plugin. Unfortunately it seems impossible to shield this "global variable" against modification. My next attempt will be to monitor the flag in an extra thread and report any change. |
|
Re-opening for now. |
|
Also this: #1886 (comment) (Python's buffering options). |
|
I finally found the cause in our test suite: We are using TypeScript for some scripting and npm to build the javascript code (basically ensure that the compiled code is up to date). Now node seems to set stdout and stderr to non-blocking as reported in nodejs/node#14752. Seems like I failed to properly diagnose the flag at shutdown, I think the test output on the CI was truncated. The fun thing: node manipulate the blocking flag only when the output goes to a pipe as it seems: I would be really happy for pytest to assert that stdout and stderr are blocking when started and before printing the test summary! (Would have saved quite some headache). Surely not a fault of pytest though. Setting stdout and stderr as non-blocking in a program (without even resetting it) is highly questionable to say the least. |
Zac-HD
changed the title
Zac-HD
added
the
type: enhancement
|
Is this responsible for getting random INFO lines after the pytest summary when using import logging, os, pytest, sys
os.environ['PYTHONUNBUFFERED'] = '1' # Doesn't help on Windows 10.
def test_buffered_filter_fail():
for i in range(1000):
logging.info("i = %i", i)
if __name__ == '__main__':
logging.basicConfig(level=logging.INFO)
pytest.main(['--log-cli-level', 'warning', *sys.argv])(.venv) PS C:\Users\C\Documents\code\GitHub\steganography> python .\test\test_pytest.py -v -k test_buffered
======================================================== test session starts ========================================================
platform win32 -- Python 3.8.5, pytest-7.1.2, pluggy-0.13.1 -- C:\Users\C\Documents\code\GitHub\steganography\.venv\Scripts\python.execachedir: .pytest_cache
rootdir: C:\Users\C\Documents\code\GitHub\steganography
plugins: pylama-8.4.1
collected 1 item
test/test_pytest.py::test_buffered_filter_fail PASSED [100%]
========================================================= 1 passed in 0.86s =========================================================
INFO:root:i = 0
[...]
INFO:root:i = 435
(.venv) PS C:\Users\C\Documents\code\GitHub\steganography> python -u .\test\test_pytest.py -v -k test_buffered
======================================================== test session starts ========================================================
platform win32 -- Python 3.8.5, pytest-7.1.2, pluggy-0.13.1 -- C:\Users\C\Documents\code\GitHub\steganography\.venv\Scripts\python.execachedir: .pytest_cache
rootdir: C:\Users\C\Documents\code\GitHub\steganography
plugins: pylama-8.4.1
collected 1 item
test/test_pytest.py::test_buffered_filter_fail PASSED [100%]
========================================================= 1 passed in 0.90s =========================================================
(.venv) PS C:\Users\C\Documents\code\GitHub\steganography> |
No. This was about stdout/stderr being non-blocking. That results in errors on write operations but will not change the order.
This shouldn't help on any system, as The problem in your code snippet is calling of You can make this visible on Linux by failing the test (adding e.g. Greetings, Torsten |
|
Thanks, but why does the problem not appear on Windows when using Less so with Even with the extra logger that doesn't appear in loggerDict, pytest on python -u eats the test log output of if __name__ == "__main__":
# Don't create own logger as that's strongly advised against (So why offer it?!) according to https://docs.python.org/3/howto/logging.html
# Use global setting and disable loggers of other modules instead. Also looks dirty!
logging.basicConfig(level=logging.INFO) # Conflicts with pytest. https://github.com/pytest-dev/pytest/issues/2251#issuecomment-1214488264
# Hide PIL lines.
loggers = [logging.getLogger(name) for name in logging.root.manager.loggerDict] # pylint: disable=no-member
for v in loggers:
print("Existing logger", v)
v.setLevel('WARNING')
# test_fuzz()
logging.warning('------------------BEFORE--------------------')
pytest.main(['--log-cli-level', 'error', *sys.argv])
logging.warning('------------------AFTER--------------------') |
Hello,
I'm running unit tests in parallel with such configuration:
platform linux2 -- Python 2.7.12, pytest-3.0.6, py-1.4.31, pluggy-0.4.0 -- /tmp/pyve/bin/python2
plugins: timeout-1.2.0, xdist-1.15.0, cov-2.4.0
And I'm getting quite often such exception as follows.
As this is temporary problem with writing output maybe there could be added a loop
that catches this exception and tries again at least several times?
The text was updated successfully, but these errors were encountered: