pytest capture logging error still happening

[spearsem]

Good morning,

I am seeing the same issue as described in https://github.com/pytest-dev/pytest/issues/14 but using a much more modern combination of both (anaconda) Python and pytest.

Test session starts (platform: linux, Python 3.6.8, pytest 4.6.3, pytest-sugar 0.9.2)
rootdir: /ml/tests/ml/services, inifile: all-tests.ini
plugins: forked-1.0.2, xdist-1.29.0, sugar-0.9.2, cov-2.7.1, mock-1.10.4

In the relevant .ini file I have this:

[pytest]
testpaths = tests
addopts =
    -n 4
    --durations=20
    --disable-warnings

where -n 4 is to use 4 parallel test runners with pytest-xdist. Edit: I was able to isolate the behavior to when using parallel worker with xdist, so likely it is an issue with an xdist worker prematurely closing a logger stream.

Basically, when I run one particular test file, I see a large number of repeated error messages in the pytest output:

--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.6/logging/__init__.py", line 996, in emit
    stream.write(msg)
  File "/usr/local/lib/python3.6/dist-packages/_pytest/capture.py", line 441, in write
    self.buffer.write(obj)
ValueError: I/O operation on closed file
Call stack:
  File "/usr/lib/python3.6/threading.py", line 884, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.6/threading.py", line 916, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.6/threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "/ml/ml/models/neighbors.py", line 289, in re_index
    success = self._re_index()
  File "/ml/ml/models/neighbors.py", line 349, in _re_index
    logger.info('== Fit new model with {} ids and a dimensionality of {} =='.format(n, dim))
Message: '== Fit new model with 48 ids and a dimensionality of 2 =='
Arguments: ()

The issue appears to be related to pytest prematurely closing the stream associated with a given logger for the underlying code module in question. I can't really post all the code since it is an extended example from my work, but I can confirm there is nothing exotic or unusual happening with this logger. The module being tested just uses the normal convention to define

logger = logging.getLogger(__name__)

and there are no duplicate loggers or conflicts with this logger's name. The logger itself is not defined in any multiprocessing context or anything like that. Just a boring import of a top-level module from our code base.

But during the test execution, something weird is happening with pytest such that the eventual calls into that logger produce these errors.

If I turn off pytest capturing with --capture=no, then the messages go away, but unfortunately so does a bunch of other necessary output that I want pytest to capture and display.

How can I debug this further? I'm sorry that I cannot provide a minimal working example, but I can definitely confirm that there is nothing weird going on with these tests. It's a very straightforward use of logging and a very straightforward test file with simple imports and function calls.

• [x ] a detailed description of the bug or suggestion
• [ x] output of pip list from the virtual environment you are using
• [ x] pytest and operating system versions
• [ x] minimal example if possible

[Zac-HD]

A reproducing case, which doesn't need xdist:

import atexit
import logging

LOGGER = logging.getLogger(__name__)

def test_1():
    pass    

atexit.register(lambda: LOGGER.error("test in atexit"))
logging.basicConfig()

[bannsec]

I'm having the same issue. Mine are debug logs during atexit.

[sshishov]

Same happening here in Python 3.7 and latest pytest

[spearsem]

@Zac-HD Thanks for migrating that example from the other issue. In my case with my original bug, there was simply no way to reproduce an example, since it contained so many moving parts related to pytest and pytest-xdist and a large test suite in the project. In general it is quite complex to try to reduce pytest errors to small & reproducible errors, though I agree that's the ideal thing to strive for. Unfortunately most of the time the best effort someone can really do is to paste in the error message and give general context around the use case where the error appears, and hope pytest devs who know much more about the internals can take it from there to scope it down to the reproducible essence of the bug. Just wanted to say it is very appreciated!

[nicoddemus]

Hi everyone,

What I believe is happening is:

1. pytest changes sys.stdout and sys.stderr to a buffer while importing test modules.
2. If there's user code setting up logging and/or creating a logging.StreamHandler at the import level, it will attach itself to pytest's buffer.
3. When pytest is about to finish the test session, it will restore sys.stdout and sys.stderr to the original values, and close the "capture" buffer.
4. Here the problem happens: if any message is emitted at this point, the StreamHandler will try to attach itself to the buffer, hence the error.

Unfortunately I don't see how pytest can work around this, because we can't know who kept a reference to the capture buffer and somehow tell the owner of the reference that we are now "dead".

@spearsem, are you calling basicConfig at import time in your application, or setting up logging yourself at import time?

If I'm getting this right, my suggestion is to avoid setting up your logging configuration at import time, moving it to a function which is called only when running your actual production code.

[spearsem]

@nicoddemus the application we are testing unfortunately requires setting up logging at import time. It is part of a Flask application that has an in-house framework for configuring logging so that it is standardized across all microservices (for compliance). I think this is actually a very commonly needed use case for automating logging in microservices. Some of our pytest code is using Flask testing clients to test these services, and the construction of the services will always produce this problem (unless we change the whole framework).

I can also say this was not always happening with pytest, it appeared in some old bug reports but then went away for a while and came back with recent versions. How did pytest handle this differently inbetween (or am I mistaken about this and it was always present)? Particularly in item 3. from your comment, what prevents pytest from being able to wait definitively for the testing code to complete and be torn down entirely before switching stdout and stderr back?

You mention,

Unfortunately I don't see how pytest can work around this, because we can't know who kept a reference to the capture buffer and somehow tell the owner of the reference that we are now "dead".

but I don't understand. Shouldn't pytest exactly be able to keep track of this, or at least wait until all test operations are completed so that any pytest unit of execution possibly containing an object that requested access to the buffers has fully completed before pytest makes the "undo" switch back?

[blueyed]

Maybe related to https://github.com/pytest-dev/pytest/pull/4943 and/or https://github.com/pytest-dev/pytest/pull/4988.

Shouldn't pytest exactly be able to keep track of this, or at least wait until all test operations are completed so that any pytest unit of execution possibly containing an object that requested access to the buffers has fully completed before pytest makes the "undo" switch back?

Yes, that would be good. But likely we would need to wrap around atexit then - are you using that also?

[blueyed]

I guess what should be done here is duplicate/redirect the handlers, instead of closing them.

[blueyed]

https://github.com/pytest-dev/pytest/pull/6034 should fix this, if you want to give it a try.

[wanam]

@blueyed I'm not a python expert, but your fix seems to me like a workaround rather than a fix, I'm wondering why we cannot do it the atexit way? It seems to work fine for me (https://github.com/wanam/pytest/commit/d0d1274486e57196e5e1cc1f0ace67ff6b48e641)

[RonnyPfannschmidt]

i'd rather switch thos to a exception that clearly tells to use a better logging setup and a documented best practice for setup of logging

from my pov its important to just say NO to tactically broken but convenient setups that would make the internals a more painful mess

if you set logging in import, you deal with the fallout ! pytest shouldn't suffer excess complexity to supplement for what basically amounts to broken/discouraged setups that don't play well with the rest of the world

[bluenote10]

i'd rather switch thos to a exception that clearly tells to use a better logging setup and a documented best practice for setup of logging

from my pov its important to just say NO to tactically broken but convenient setups that would make the internals a more painful mess

I understand the motivation for this, but it would be a very unfortunate decision e.g. for people using ROS (robot operation system). I ran into https://github.com/pytest-dev/pytest/issues/5577 specifically in this context. The problem is that the "tactically broken" logging setup can come out of ROS itself, and -- what makes this an impossible problem to work-around as a user -- the ROS Python side is tightly coupled to its native distribution (yes, it is quite ugly...). As a result, "fixing" these issues is not a very realistic option, because one would have to maintain their own ROS distribution fork :(.

That is just one example. It would be nice if we were able to use py.test even if third party libraries are guilty of logging setup at import -- in particular if these libraries are not pip-installable and thus hard to fix. Even worse: Third party library authors may even prefer to stick to the anti-pattern for personal reasons (I recently had such a discussion about a related on-import anti-pattern).

I'll have to give #6034 a try.

[RonnyPfannschmidt]

whats preventing issuing a actual issue against ros?

i an case its safe to say that hiding this issue will just make things hideeous and strangely, i would strongly suggest to disable capture on broken platforms and reporting issues against the platform instead of putting resource leaks into pytest to "work" on broken platforms

your message can very easily be read as "our vendor wont fix things anyway, so lets make pytest worse instead"

and i reject that notion, please get at your vendor and have them fix stuff,

[bluenote10]

whats preventing issuing a actual issue against ros?

Nothing, but much like an operating system, ROS comes in distributions with slow release cycles. Usually robotic developers stay with one ROS distribution for years, because it is neither straightforward to migrate from one release to another nor to maintain an own distribution containing backports. In other words: Even if the upstream issues gets fixed, we wouldn't be able to use it any time soon because we have to target existing releases.

Keep in mind that in C/C++ libraries like ROS the Python bindings play a inferior role. The maintainers are not Python developers, and often Python best practices don't play a big role or are even ignored deliberately to optimize for special use cases. It might be not entirely straightforward to fix this issue in ROS in general.

your message can very easily be read as "our vendor wont fix things anyway, so lets make pytest worse instead"

I've indeed experienced such unwillingness to adhere to Python best practices already. In any case, to me pytest would be "better" if it less restrictive on the code it supports. Even for such "broken" libraries, py.test is a great tool to write unit tests ;).

[RonnyPfannschmidt]

@bluenote10 in that case i advise deactivating capture as a starting point and i suspect there can be a pytest plugin, that hijacks the logging system on rhos for example, and then enables a pytest compatible setup/configruation

that way core pytest doesn't have to care about a broken system, and a pytest plugin can fix/patch the mess ups of the vendor,

in an case this should and must be a issue against ros - retiring a shoddy workaround after a decade is less horrible than leaving it be because nobody did fix the origin

given that others mess up with logging as well, this perhaps could be pytest-gumby-logging which would deal with logging in the fashion of the gumbys (see the monty python sketches)

[blueyed]

@wanam #6034 uses atexit - similar to your patch. But with yours it might run out of open file descriptors, e.g. with pytest's own test suite.

[spearsem]

from my pov its important to just say NO to tactically broken but convenient setups that would make the internals a more painful mess

I think it suggests the internals are in a messy state if a certain aspect of basing end-to-end usage isn't well supported by existing internal primitives. If this use case is somehow weird or special from point of view of what assumption pytest is making, that strikes me as a criticism of those assumptions, not a criticism of the use case.

if you set logging in import, you deal with the fallout ! pytest shouldn't suffer excess complexity to supplement for what basically amounts to broken/discouraged setups that don't play well with the rest of the world

Setting logging in import is such a ubiquitous thing that I just can't agree with this. It's like saying, "if you define your own functions, then you deal with the following mess". These are not at all broken / discouraged setups, but are straightforward basic workflows for tons of use cases that need pytest to support it.

I understand it's a difference of opinion, but it feels like it's straying very far into a philosophical contortion to justify not doing something that clearly is an end to end use case users need supported. I really don't think, "don't do it that way," is a reasonable answer to this.

[RonnyPfannschmidt]

@spearsem the technical best practice is - libraries don't set up logging on import, applications set up logging on startup

and that prevents a number of issues - like triggering configuration of logging in a situation where the system state is unexpected

so as far as i'm concerned, this is about practical missuse of the stdlib logging module

the stdlib itself even suggests to not to trigger this at import, but rather at program startup

so for me this is not a topic about far off philosophy, this is about ignoring the best practices that are in place to prevent the very fallout that's now being complained about

[blueyed]

Duplicate of https://github.com/pytest-dev/pytest/issues/5282.

[nicoddemus]

After reading this thread and considering this some more, I think the real issue is that pytest is not playing well with any system which hijacks sys.stdout or sys.stderr, and I can see this happening for other cases other than logging (something like hijacking sys.stdout to write to both stdout and to a file).

Given that this does not affect logging only, might make sense for pytest to make an effort here if feasible, after all pytest itself is hijacking stdout and stderr, so it might as well try to play nice with others when possible.

6034 by @blueyed is an attempt at this.

[blueyed]

@nicoddemus Yep. But isn't it still a duplicate?

[analog-cbarber]

Whatever your philosophy about how logging should be set up, I would hope that the underlying philosophy of a testing framework should be that it should not change the underlying semantics of the runtime system.

If pytest breaks your code when doing something that works perfectly fine otherwise -- recommended or not -- then you are putting a heavy burden on the user when they encounter a problem like this.

Practically speaking even after reading all of the above I still don't understand how to fix my broken tests.

[bannsec]

I "fixed" my tests by explicitly changing logging to zero during at exit. If something goes wrong, it will except out and I can manually add print and other statements and rerun the test without pytest there so it doesn't break.

On Sat, Jun 20, 2020, 2:03 PM Christopher Barber notifications@github.com wrote:

Whatever your philosophy about how logging should be set up, I would hope that the underlying philosophy of a testing framework should be that it should not change the underlying semantics of the runtime system.

If pytest breaks your code when doing something that works perfectly fine otherwise -- recommended or not -- then you are putting a heavy burden on the user when they encounter a problem like this.

Practically speaking even after reading all of the above I still don't understand how to fix my broken tests.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/pytest-dev/pytest/issues/5502#issuecomment-647027824, or unsubscribe https://github.com/notifications/unsubscribe-auth/AB2HPYAKI3B2M6SOOEVL43LRXT2YXANCNFSM4H34OUIQ .

[analog-cbarber]

Clearing all the log handlers during at test teardown works for me.

I invoke the following function in my shared test fixture to remove all logging handlers. In my case, I only need to reset the root logger, but depending on your application, you may need to do all of them.

def clear_loggers():
    """Remove handlers from all loggers"""
    import logging
    loggers = [logging.getLogger()] + list(logging.Logger.manager.loggerDict.values())
    for logger in loggers:
        handlers = getattr(logger, 'handlers', [])
        for handler in handlers:
            logger.removeHandler(handler)

[jazelenk]

Our codebase tampers with sys.stdout and sys.stderr, so the various handler workarounds did not work for me. I ended up doing this:

@pytest.fixture(autouse=True)
def capture_wrap():
    sys.stderr.close = lambda *args: None
    sys.stdout.close = lambda *args: None
    yield

Not a great general-purpose workaround, but posting it here in case someone else finds the approach useful.

[kmcminn]

@analog-cbarber's fixed worked for me within a pytest_sessionfinish hook within conftest.py to cleanup handlers in multi-threaded libraries.

[mgoldey]

A quick fix for me was to turn off capturing following https://www.stefaanlippens.net/pytest-disable-log-capturing.html I added the following to my pytest invocation --capture=no --log-cli-level=INFO though I'm still a little miffed at an external library I am using that dumps info via logging and print invocations, making life way noisier.

[abadger]

I just ran into this too. In our case, setting up logger is done in a function, not at module level. But we run into this because we have a few tests for the function which sets up the logger and check that the logger is outputting to the right place using capsys (The combination of these two is what triggers the error). Those tests didn't think of the fact that setting up the logger would have a global side effect of adding handlers to the global logger. I've worked around this by creating https://github.com/pytest-dev/pytest/issues/5502#issuecomment-647157873 as a fixture which I added to those test functions.

I feel like this deserves to be documented somewhere but I'm not sure where. The messages are going to be emitted far away from where the actual issue lies.... Maybe as a warning in the capture howto? https://docs.pytest.org/en/7.1.x/how-to/capture-stdout-stderr.html

[bocekm]

Clearing all the log handlers during at test teardown works for me.

I invoke the following function in my shared test fixture to remove all logging handlers. In my case, I only need to reset the root logger, but depending on your application, you may need to do all of them.

def clear_loggers():
    """Remove handlers from all loggers"""
    import logging
    loggers = [logging.getLogger()] + list(logging.Logger.manager.loggerDict.values())
    for logger in loggers:
        handlers = getattr(logger, 'handlers', [])
        for handler in handlers:
            logger.removeHandler(handler)

@analog-cbarber, by calling the removeHandler() you effectively mutate the list you're iterating on (returned by getattr(logger, "handlers", [])). The end result is that not all handlers are removed from the logger. What fixes it is making a shallow copy of the handlers list, for example by using a slice notation (inspiration: https://youtu.be/xeLecww65Zg?t=805).

This works well then:

def clear_loggers():
    """Remove handlers from all loggers"""
    import logging
    loggers = [logging.getLogger()] + list(logging.Logger.manager.loggerDict.values())
    for logger in loggers:
        if not hasattr(logger, "handlers"):
            continue
        for handler in logger.handlers[:]:
            logger.removeHandler(handler)

By the way, the credit goes to this person: https://stackoverflow.com/a/7484605/3499937.

[RonnyPfannschmidt]

Pytest probably needs to warn every time a log handler does the "crime" of setting up stdio handlers in test setup

[quickhouse]

Why pytest can't leave system stream open? It is totally wrong that you substitute sys.stdout with something which can be closed at any moment. Don't restore it, just keep it open. @nicoddemus

[RonnyPfannschmidt]

Pytest correctly cleaning up after itself is not negotiable

People setting up logging broken is something people need to fix

[excitoon]

@RonnyPfannschmidt once pytest replaced content of sys.stdout it is responsible for any use case of that content. You replace duck with a goose and surprised that it does not work. Caching global variable is totally legit action.

[RonnyPfannschmidt]

All i read from this is "i want to keep my broken logging setup, acomodate meeeee"

Fixing broken logging setup does work better that removing cleanup and silently stealing the logs from other tests

If we just keep random files open, the next thing people with broken setup will do is asking for monkeypatching the stdlib to fix the mess

The correct answer is no, fix your logging setup

It would be nice if the stdlib had redirect aware stdio loggers, as stream breaking redirection is part of the stdlib these days

At the end of the day i prefer telling people to do correct logging setups instead of making the already complicated capture mechanism even more of a mess

[excitoon]

You are wrong. It's not broken. I want to use code like:

mystdout = sys.stdout
atexit(... mystdout.write("Bye") ...)

This shows that pytest is incompatible with standard library and have to be fixed. Yes, accommodate standard library, please.

[RonnyPfannschmidt]

@excitoon if you want that code to work, either disable capture, or provide a actually working implementation

[BinarSkugga]

def clear_loggers():
    """Remove handlers from all loggers"""
    import logging
    loggers = [logging.getLogger()] + list(logging.Logger.manager.loggerDict.values())
    for logger in loggers:
        handlers = getattr(logger, 'handlers', [])
        for handler in handlers:
            logger.removeHandler(handler)

This worked for me. I never even setup logging on import. I use it inside daemon threads that might close unexpectedly. The logging errors were preventing me from seeing the tests report with nox. It shouldn't be captured.

[gatopeich]

Still similar issue happens in latest pytest wheel pytest-7.2.1-py3-none-any.whl:

--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.8/logging/__init__.py", line 1088, in emit
    stream.write(msg + self.terminator)
ValueError: I/O operation on closed file.
Call stack:
  File "/usr/lib/python3.8/multiprocessing/util.py", line 332, in _exit_function
    info('process shutting down')
  File "/usr/lib/python3.8/multiprocessing/util.py", line 54, in info
    _logger.log(INFO, msg, *args)
Message: 'process shutting down'
Arguments: ()

[quickhouse]

They think every other library is wrong except theirs XD

On Thu, Jan 26, 2023, 12:01 PM gatopeich @.***> wrote:

Still similar issue happens in latest pytest wheel pytest-7.2.1-py3-none-any.whl:

--- Logging error --- Traceback (most recent call last): File "/usr/lib/python3.8/logging/init.py", line 1088, in emit stream.write(msg + self.terminator) ValueError: I/O operation on closed file. Call stack: File "/usr/lib/python3.8/multiprocessing/util.py", line 332, in _exit_function info('process shutting down') File "/usr/lib/python3.8/multiprocessing/util.py", line 54, in info _logger.log(INFO, msg, *args) Message: 'process shutting down' Arguments: ()

— Reply to this email directly, view it on GitHub https://github.com/pytest-dev/pytest/issues/5502#issuecomment-1404713747, or unsubscribe https://github.com/notifications/unsubscribe-auth/AZ5CUDSDEGYYIWBYPTAZLOLWUI4OPANCNFSM4H34OUIQ . You are receiving this because you commented.Message ID: @.***>

[RonnyPfannschmidt]

@gatopeich how is the logging set up for that?

@quickhouse the fact stands that safe io capture is incompatible with randomly taking streams which are subject to resource cleanup

It's not unreasonable to expect correct handling of capture or disabling the features

It's unreasonable to expect this library to accommodate unwillingness to write code that is incorrect in the face of io capture, one can just disable io capture

This is not about correctness of pytest, this is about entitled people expecting pytest to carry the maintenance cost of their decisions

You can pick between enabling the feature and having to integrate with it, or opting out of the feature

Or actually step up and create a implementation that won't lie/loose date, put things where they don't belong

It's very hard to give correct reports in the face of incorrect resources management

Feel free to prove me wrong by providing a implementation that won't lie, but until then so what, io error is better than putting the logs in the wrong place

There are some possible mechanisms to sidestep the object replacement, but then one gets lots of possibly incorrect resources, and those would have to print errors as well to notify of the missuse

[nicoddemus]

Why pytest can't leave system stream open? It is totally wrong that you substitute sys.stdout with something which can be closed at any moment. Don't restore it, just keep it open. @nicoddemus

(Answering this message specifically as I was pinged)

I understand why some users are frustrated about something which to them should "just work", but the capture code is complex and has to make compromises, which means it cannot support every possible use case.

Unfortunately there is no standard way to redirect a global resource like sys.stdout other than just overwritting the attribute, so this clashes with some other standard features (like atexit).

If pytest overwrites a global resource such as sys.stdout with its own, the right thing to do is to close that resource and restore the original sys.stdout at the end of the session. Unfortunately this has the clear drawback of not being compatible with all possible ways sys.stdout can be used.

It is clear however that eventually people are bitten by this, so I think one thing we should do is improve the docs:

1. Explain how capture works, and which features it could clash with.
2. Recommend how to use logging so it will work well with capture.
3. If all else fails, show how to disable capture altogether.

[excitoon]

Well, suppose, logging is wrong. Simpler case, I have a task queue, and I put functools.partial(write, sys.stdout) there. In this case pytest capture will break my code too.

The problem is in restore mechanism specifically, it works partially, restoring only last "copy" of sys.stdout, and breaking all other copies at the same time.

On Thu, Jan 26, 2023, 1:45 PM Ronny Pfannschmidt @.***> wrote:

@gatopeich https://github.com/gatopeich how is the logging set up for that?

@quickhouse https://github.com/quickhouse the fact stands that safe io capture is incompatible with randomly taking streams which are subject to resource cleanup

It's not unreasonable to expect correct handling of capture or disabling the features

It's unreasonable to expect this library to accommodate unwillingness to write code that is incorrect in the face of io capture, one can just disable io capture

This is not about correctness of pytest, this is about entitled people expecting pytest to carry the maintenance cost of their decisions

You can pick between enabling the feature and having to integrate with it, or opting out of the feature

Or actually step up and create a implementation that won't lie/loose date, put things where they don't belong

It's very hard to give correct reports in the face of incorrect resources management

Feel free to prove me wrong by providing a implementation that won't lie, but until then so what, io error is better than putting the logs in the wrong place

There are some possible mechanisms to sidestep the object replacement, but then one gets lots of possibly incorrect resources, and those would have to print errors as well to notify of the missuse

— Reply to this email directly, view it on GitHub https://github.com/pytest-dev/pytest/issues/5502#issuecomment-1404828611, or unsubscribe https://github.com/notifications/unsubscribe-auth/AARGSB2AKEAHFRIRBKBKIL3WUJIVRANCNFSM4H34OUIQ . You are receiving this because you were mentioned.Message ID: @.***>

[excitoon]

I would also like to highlight, that given the popularity of pytest, there are lots of programmers which have to use pytest, and could not change it to whatever they like.

On Thu, Jan 26, 2023, 1:45 PM Ronny Pfannschmidt @.***> wrote:

@gatopeich https://github.com/gatopeich how is the logging set up for that?

@quickhouse https://github.com/quickhouse the fact stands that safe io capture is incompatible with randomly taking streams which are subject to resource cleanup

It's not unreasonable to expect correct handling of capture or disabling the features

It's unreasonable to expect this library to accommodate unwillingness to write code that is incorrect in the face of io capture, one can just disable io capture

This is not about correctness of pytest, this is about entitled people expecting pytest to carry the maintenance cost of their decisions

You can pick between enabling the feature and having to integrate with it, or opting out of the feature

Or actually step up and create a implementation that won't lie/loose date, put things where they don't belong

It's very hard to give correct reports in the face of incorrect resources management

Feel free to prove me wrong by providing a implementation that won't lie, but until then so what, io error is better than putting the logs in the wrong place

There are some possible mechanisms to sidestep the object replacement, but then one gets lots of possibly incorrect resources, and those would have to print errors as well to notify of the missuse

— Reply to this email directly, view it on GitHub https://github.com/pytest-dev/pytest/issues/5502#issuecomment-1404828611, or unsubscribe https://github.com/notifications/unsubscribe-auth/AARGSB2AKEAHFRIRBKBKIL3WUJIVRANCNFSM4H34OUIQ . You are receiving this because you were mentioned.Message ID: @.***>

[RonnyPfannschmidt]

@excitoon in your example the test isolation is right to trigger an error

We should probably extend the error message to mention that a reference to a replaced stream was taken

[RonnyPfannschmidt]

@excitoon again, the instructions are clear, safe io capture has to error on invalid resources, if unsafe resource usage is necessary for you, turn it off

For me this discussion feels like trying to explain the use and limits of seat belts to people who want to dance at the top of the driving car

[nicoddemus]

@excitoon

I would also like to highlight, that given the popularity of pytest, there are lots of programmers which have to use pytest, and could not change it to whatever they like.

Indeed, but to be clear, it is easy to disable capture in that case, just pass --capture=no. Or is that not possible in your case?

Also I noticed you use log = functools.partial(write, sys.stdout), I think a way to make it work with pytest capture is to not bind to sys.stdout, but use a function:

def log(s):
    write(sys.stdout, s)

This way, you will always write to whatever sys.stdout is pointing to, instead of binding it to sys.stdout at the time partial is created.

---

Please understand that is not that we do not want to fix it, this is a complex problem without an obvious solution. Hijacking sys.stdout (like pytest does for capture) has its drawbacks (as is being demonstrated here).

"Just never close sys stdout" is not a proper solution, because if pytest hijacks sys.stdout, it should restore it at the end of the session. Not doing so we risk breaking other use cases, like pytest being called inside another script, or embedded into an IDE.

[excitoon]

It actually has an obvious and clear solution — wrap sys.stdout so it would redirect output to original stream after end of session and do its' magic before that.

Thing is, sys.stdout is not supposed to be closed. And copy of it is not supposed to be closed either. Imagine every developer will start to check if it's closed every time they use it. :) That is why I would not dance on rooftop having pytest in requirements. And just in case simply dance or come into large buildings.

On Thu, Jan 26, 2023, 3:58 PM Bruno Oliveira @.***> wrote:

@excitoon https://github.com/excitoon

I would also like to highlight, that given the popularity of pytest, there are lots of programmers which have to use pytest, and could not change it to whatever they like.

Indeed, but to be clear, it is easy to disable capture in that case, just pass --capture=no. Or is that not possible in your case?

Also I noticed you use log = functools.partial(write, sys.stdout), I think a way to make it work with pytest capture is to not bind to sys.stdout, but use a function:

def log(s): write(sys.stdout, s)

This way, you will always write to whatever sys.stdout is pointing to, instead of binding it to sys.stdout at the time partial is created.

Also, please understand that is not that we do not want to fix it, this is a complex problem without an obvious solution. Hijacking sys.stdout (like pytest does for capture) has its drawbacks (as is being demonstrated here).

"Just never close sys stdout" is not a proper solution, because if pytest hijacks sys.stdout, it should restore it at the end of the session. Not doing so we risk breaking other use cases, like pytest being called inside another script, or embedded into an IDE.

— Reply to this email directly, view it on GitHub https://github.com/pytest-dev/pytest/issues/5502#issuecomment-1404969577, or unsubscribe https://github.com/notifications/unsubscribe-auth/AARGSB4XP5Y634XEEKIV67TWUJYIHANCNFSM4H34OUIQ . You are receiving this because you were mentioned.Message ID: @.***>

[RonnyPfannschmidt]

@excitoon as per the documentation and examples for https://docs.python.org/3/library/contextlib.html#contextlib.redirect_stdout this is demonstrably false

[nicoddemus]

It actually has an obvious and clear solution — wrap sys.stdout so it would redirect output to original stream after end of session and do its' magic before that.

That's actually a good idea, haven't thought of it. Has this been mentioned in this thread before? I missed it.

Perhaps we could indeed install a "wrapper", which would hold a pointer to the original sys.stdout, which redirects all calls to a a separate capture stream... after we are done, the wrapper can then redirect the calls to the original sys.stdout. :thinking:

[RonnyPfannschmidt]

@nicoddemus as part of fd capture at least we have to destroy the textio, the buffer and the file-descriptor of stdout/err

so the file object being held would be broken to begin with

as far as execnet/xdist is concerned, it also goes deep into the file descriptors

i propose that pytest adds a own logging setup that adds a handler well before importing user code, thus preventing the problem with logging basic setup as a starting point

imho its much better to have the test specific capture streams turn dysfunctional at the end of a test, as that commonly indicates a resource control issue in the context of having io capture with stdlib compliant stdio redirection

additionally we cannot keep fd capture file descriptors safely around, as that would create file descriptor exhaustion in larger testsuites