bpo-39385: Add an assertNoLogs context manager to unittest.TestCase (GH-18067)

[kitchoi]

https://bugs.python.org/issue39385

https://bugs.python.org/issue39385

Automerge-Triggered-By: @vsajip

[the-knights-who-say-ni]

Hello, and thanks for your contribution!

I'm a bot set up to make sure that the project can legally accept this contribution by verifying everyone involved has signed the PSF contributor agreement (CLA).

CLA Missing

Our records indicate the following people have not signed the CLA:

@kitchoi

For legal reasons we need all the people listed to sign the CLA before we can look at your contribution. Please follow the steps outlined in the CPython devguide to rectify this issue.

If you have recently signed the CLA, please wait at least one business day
before our records are updated.

You can check yourself to see if the CLA has been received.

Thanks again for the contribution, we look forward to reviewing it!

[kitchoi]

CLA is signed, but it needs to wait another business day.

[remilapeyre]

If the feature is accepted, you will also need to update the documentation and add a blurb excerpt.

[remilapeyre]

What's the point of overriding this method here?

[kitchoi]

This was to return None instead of returning the _LoggingWatcher instance, which is expected to be empty. I see it also does not hurt to return the watcher anyway. I will remove it.

[remilapeyre]

I think both __exit__ could share more of there code to avoid duplication.

[kitchoi]

I see what you mean. I pushed some changes. Hope that's better now.

[remilapeyre]

To add a NEWS entry (https://devguide.python.org/committing/#what-s-new-and-news-entries), you can use https://blurb-it.herokuapp.com/

[kitchoi]

Thank you @remilapeyre for looking into this!

[kitchoi]

This was to return None instead of returning the _LoggingWatcher instance, which is expected to be empty. I see it also does not hurt to return the watcher anyway. I will remove it.

[kitchoi]

I see what you mean. I pushed some changes. Hope that's better now.

[kitchoi]

you will also need to update the documentation

Oops, haven't done that yet... on it...

[calebzmeyer]

Thanks a lot for adding this! It's a good improvement. I think this failure message would be improved if it was Unexpected logs found: ... or Logs unexpectedly found: ... (probably the first)

[kitchoi]

Oops, yes you are right. Thank you for spotting this.

[remilapeyre]

You can use multiple context managers at once (in this test and all others):

        with self.assertRaises(ZeroDivisionError), \
                self.assertLogs():
            raise ZeroDivisionError("Unexpected")

[kitchoi]

Thanks. I realize that a lot of other existing tests in this module use nested with, and none uses , \. For consistencies maybe the nested with should be kept?

[vsajip]

Instead of creating a base class and two subclasses for the context manager, why not just use the existing class with an additional initialization keyword parameter no_logs, defaulting to False? The only difference between the two cases are:

1. The check for the number of collected records -- zero vs. non-zero.
2. The message displayed when the assertion fails.

Instead, the class _AssertLogsContext could get the no_logs=False keyword parameter, which it stores in an attribute. At check time, this attribute is checked and the appropriate logic followed. The higher-level API (assertNoLogs) remains the same, but the implementation just returns a _AssertLogsContext called with no_logs=True.

Wouldn't that be simpler and shorter?

[kitchoi]

Yeah that would work too.

[kitchoi]

The only problem with no_logs, is that I ended up having to write if not self.no_logs for assertLogs, which is quite confusing 😂
Another naming suggestion for the flag is welcome.

[calebzmeyer]

The only problem with no_logs, is that I ended up having to write if not self.no_logs for assertLogs, which is quite confusing 😂
Another naming suggestion for the flag is welcome.

I'm just some random person lurking around this particular issue. 😂

Thinking about this a little bit, it's a little complex. For example, let's say you called it things like:
allow_log, require_log, expect_log, can_log or must_log... Names of this nature. There's this case where require_log=False, but, there's ambiguity about whether a log is "allowed" even if it is not "required".

The name needs to convey requires_and_allows_log or can_and_must_log. But, this is super verbose. 😭

The best name I can come up with is: should_log? Hope this helps.

[vsajip]

The only problem with no_logs, is that I ended up having to write if not self.no_logs for assertLogs, which is quite confusing 😂

How so? I see it like this - _AssertLogsContext changes like so:

    def __init__(self, test_case, logger_name, level, no_logs=False):
        # existing code omitted
        self.no_logs = no_logs
        
    def __exit__(self, exc_type, exc_value, tb):
        # initial part of existing code omitted
        # the assertion check changes as follows
        num_records = len(self.watcher.records)
        if self.no_logs:
            if num_records > 0:
                self._raiseFailure(
                    "Unexpected logs found: {!r}".format(self.watcher.output)
                )
        elif num_records == 0:
            self._raiseFailure(
                "no logs of level {} or higher triggered on {}"
                .format(logging.getLevelName(self.level), self.logger.name))

Then assertLogs is unchanged and assertNoLogs becomes

    def assertNoLogs(self, logger=None, level=None):
        # docstring omitted
        from ._log import _AssertLogsContext
        return _AssertLogsContext(self, logger, level, no_logs=True)

[vsajip]

My reasoning for choosing no_logs as a name: the _AssertLogsContext is now making assertions about the absence or presence of logs. If no_logs is True, we want no logs - else we fail the test. If no_logs is False, we want some logs - else we fail the test.

[kitchoi]

Thank you @vsajip and @calebmarchent for your input!
I have combined the two classes into one, using the flag as suggested. Since this is internal implementation details, it can be changed easily in the future.

What is more important, I think, is the public facing API. Initially when I started with two classes, one of the main motivations was to have assertNoLogs yield nothing, so I implemented __enter__ and __exit__ separately. When I addressed this #18067 (comment), I inevitably made assertNoLogs yield the watcher just like assertLogs does. I'd like to go back on that change. In my last commit, I have removed the watcher from the returned value of assertNoLogs. My reasons are as follows:
(1) If a test should need to inspect any captured logs, the test should be using assertLogs, not assertNoLogs. I can't think of a use case where someone should need a watcher from a successful assertion of assertNoLogs.
(2) If assertNoLogs yields a watcher, that will be a feature in the public API. It is more difficult to remove or change something that already exists in the public API. Whereas if assertNoLogs should yield nothing, it is still possible to add the watcher back later when there is needed.

[vsajip]

I can't think of a use case where someone should need a watcher from a successful assertion of assertNoLogs.

Failures can yield useful information, too. Surely if you want to assert that there were no logs, but some appear, you want (at least in some instances) to know what they are, so you can find the problem that caused them? Have I misunderstood what you're saying? Of course the failure message is there, but I mean that you might want to do something with the logs programmatically in case the basic error message isn't enough.

[kitchoi]

Failures can yield useful information, too. Surely if you want to assert that there were no logs, but some appear, you want (at least in some instances) to know what they are, so you can find the problem that caused them? Have I misunderstood what you're saying? Of course the failure message is there, but I mean that you might want to do something with the logs programmatically in case the basic error message isn't enough.

I understand that there might be a use case. It is just that possible use case isn't concrete enough to me at the moment. For example, I haven't yet found myself in a situation where I would do something like this instead of using assertLogs:

with self.assertRaises(AssertionError):
    with self.assertNoLogs(...) as watcher:
        # code
    # do something with the nonempty watcher here

Not adding the watcher now does not prevent the watcher to be added later. If there is a need, there can be a new issue to add the watcher to assertNoLogs. If the watcher is included now, and if later there are new use cases for the return value of assertNoLogs to change, having to maintain the existing API will make that work harder.

What I am proposing is that we can defer the decision as to what assertNoLogs should yield by not yielding anything now, so we can be sure in the future no ones has been doing with self.assertNoLogs as blah if the API needs to change.

[kitchoi]

Of course the failure message is there, but I mean that you might want to do something with the logs programmatically in case the basic error message isn't enough.

Ah, I think you meant this:

try:
    with self.assertNoLogs(...) as watcher:
        ...
except AssertionError:
    # do something with the nonempty watcher, probably provide a different failure message.
    self.fail(...)

In that case, having another custom exception that subclasses AssertionError might be better, because one can be sure the exception comes from assertNoLogs and not anything else. And then that exception instance can provide more information about the captured logs.
Then again I also haven't found myself in this situation, and I'd still propose deferring that decision until there is a clear need.

[bedevere-bot]

🤖 New build scheduled with the buildbot fleet by @vsajip for commit 730b2c1 🤖

If you want to schedule another build, you need to add the ":hammer: test-with-buildbots" label again.