Log message hiding interfers with pytest log caputure fixture.

[jenshnielsen]

The log message hiding merged in #1535 interferes with pytests log capturing.

In the example below I am using the caplog fixture to capture the log message and test that they are correct.
In this simple case just asserting the number of messages. This results in an empty record list in the first call with 3.69.11 but works as expected with 3.69.10

import logging
from hypothesis import given, strategies

@given(x=strategies.floats(min_value=-3, max_value=3))
def test_logcapture(x, caplog):

    with caplog.at_level(logging.CRITICAL, logger='root'):
        caplog.clear()
        logging.critical(f"x is {x}")
    assert len(caplog.records) == 1 

[Zac-HD]

...Yep, I can see how this is doing the wrong thing, but I don't know what the right behaviour might be. @jenshnielsen @DRMacIver any ideas? The goal is that

1. Each test case has the normal logging config, whatever that is for the user
2. When a test fails, only the logging from the last test case is observable

Unfortunately #1535 gave up (1) to achieve (2). Should we just revert it and go back to the drawing board?

[DRMacIver]

I don't know much about how logging works internally, but is it possible to in some way mess with it so that logging is enabled (ed: This originally said "disabled", which caused this sentence to not make any sense) but the actual printing to screen is turned off? e.g. it's a bit aggressive, but we could actually try messing with the raw file handles and redirect them inside non-final tests. Anything that relies on output capturing would still work, but anything that actually prints to the screen would not.

(Making that work across unixish OSes and Windows will be a pain).

My reluctant conclusion is that reverting #1535 is probably going to be the right thing to do regardless of what the correct solution is though. 😢 Logging shouldn't be disabled if we want this sort of test to work, regardless of what the actual solution we implement is.

[jenshnielsen]

The best would be if this could grab the handler that is responsible for printing to the screen / std_out and disable the output for that one only. I find https://docs.python.org/2/_images/logging_flow.png useful for understanding how the logger logic works

[Zac-HD]

Disabling a streamhandler would break tests that capture and check stdout and stderr though 😭

I think we have to take this out of the Hypothesis core entirely, though we may be able to do something in the pytest plugin to clear the captured logs at the start of every test case. This would achieve (1) and partly (2), by assuming that logging is only observable via the pytest log capture mechanism.