add unittest assertion for logging

[pitrou]

BPO	18937
Nosy	@vsajip, @pitrou, @ezio-melotti, @bitdancer, @voidspace
Files	assertlogs.patch assertlogs2.patch

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2013-09-14.17:46:29.381>
created_at = <Date 2013-09-05.20:26:01.476>
labels = ['type-feature', 'library']
title = 'add unittest assertion for logging'
updated_at = <Date 2013-09-14.17:46:29.380>
user = 'https://github.com/pitrou'

bugs.python.org fields:

activity = <Date 2013-09-14.17:46:29.380>
actor = 'pitrou'
assignee = 'none'
closed = True
closed_date = <Date 2013-09-14.17:46:29.381>
closer = 'pitrou'
components = ['Library (Lib)']
creation = <Date 2013-09-05.20:26:01.476>
creator = 'pitrou'
dependencies = []
files = ['31630', '31750']
hgrepos = []
issue_num = 18937
keywords = ['patch']
message_count = 15.0
messages = ['197022', '197023', '197029', '197034', '197103', '197120', '197122', '197123', '197124', '197129', '197212', '197636', '197642', '197722', '197723']
nosy_count = 6.0
nosy_names = ['vinay.sajip', 'pitrou', 'ezio.melotti', 'r.david.murray', 'michael.foord', 'python-dev']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'enhancement'
url = 'https://bugs.python.org/issue18937'
versions = ['Python 3.4']

[pitrou]

It is sometimes useful to check for the log messages emitted by some piece of code (especially a library). Would it be a good idea to add a dedicated assertion method for that? I would propose the following API:

with self.assertLogging("logger.name", level="WARN") as cm:
    ...

The cm context manager could give access to all the log records and formatted output lines for the given logger name (and children) and at least the given logging level. I have something like that here, except not with a dedicated assertion method:
https://bitbucket.org/optiflowsrd/obelus/src/c2a2f78068123264adde8cc3ece4889c61773f00/obelus/test/__init__.py?at=default#cl-20

[bitdancer]

I have project in which that would be useful, so +1 from me for the general concept.

[vsajip]

I agree a context manager would be useful. Note that I have already provided a Handler subclass (TestHandler) as well as a Matcher class which allows matching of LogRecords, and which can be used in assertions. These are in test.support as they were originally intended for Python's own tests, but could be moved to the logging package if they are considered more generally useful.

See this for how to use them:

http://plumberjack.blogspot.co.uk/2010/09/unit-testing-and-logging.html

[vsajip]

Whoops, meant to say "... moved to the unittest package ...".

[pitrou]

Proposed patch with an assertLogs() method.

[voidspace]

So making assertions about logging is very common, but I *always* do this by just mocking out the logger and making an assertion about the call. It's trivially easy to do.

[pitrou]

So making assertions about logging is very common, but I *always* do
this by just mocking out the logger and making an assertion about the
call. It's trivially easy to do.

Only works if you test the exact logger that will be triggered, rather
than e.g. a child in the hierarchy (and the exact logging method, for
that matter, too).

[voidspace]

Do you have a lot of circumstances where you want to test logging but you don't know the specific logger and method called? That's not a situation I've been in.

[pitrou]

Do you have a lot of circumstances where you want to test logging but
you don't know the specific logger and method called? That's not a
situation I've been in.

I have a lot of circumstances where I do not *care* about the specific
logger (as long as it's somewhere in a subhierarchy) and the specific
level (as long as it's e.g. a warning or above).

[bitdancer]

Exactly. It is the difference between black box testing and white box testing. IMO mock, while a great tool, should be used with caution, because it tends to lead to white box testing.

[voidspace]

The patch and approach look good to me (with docs needed).

Note, personally I would not use a leading underscore for the assertion methods (in the tests) _assertNoStderr and _assertLogRecords.

[pitrou]

Question: should the default level threshold be INFO or WARNING?
My initial patch uses INFO, but WARNING might be better since that's also logging's default level filter when not configured.

[pitrou]

Here is an updated patch:

• documentation added
• tests improved a bit and style fixed (removed leading underscores on helper methods)

[pitrou]

David told me he was in favour of keeping INFO the default, so I'll leave it like that.

[python-dev]

New changeset 4f5815747f58 by Antoine Pitrou in branch 'default':
Issue bpo-18937: Add an assertLogs() context manager to unittest.TestCase to ensure that a block of code emits a message using the logging module.
http://hg.python.org/cpython/rev/4f5815747f58