Python + nose: make statements about recorded text?

Question

Is there an easy way to capture and accept claims about registered messages with nose ?

For example, I would like to do something like:

 cook_eggs() assert_logged("eggs are ready!") 

Answer 1

You can create a custom handler that can check the message sent through logging. BufferingHandler is perfect for this job.

You may also want to attach a handler in your test to any logger that you use in your code, for example logging.getLogger('foo').addHandler(...) . Ultimately, you can bind a handler in the setUp and tearDown your test case.

 import logging import logging.handlers class AssertingHandler(logging.handlers.BufferingHandler): def __init__(self,capacity): logging.handlers.BufferingHandler.__init__(self,capacity) def assert_logged(self,test_case,msg): for record in self.buffer: s = self.format(record) if s == msg: return test_case.assertTrue(False, "Failed to find log message: " + msg) def cook_eggs(): logging.warn("eggs are ready!") import unittest class TestLogging(unittest.TestCase): def test(self): asserting_handler = AssertingHandler(10) logging.getLogger().addHandler(asserting_handler) cook_eggs() asserting_handler.assert_logged(self,"eggs are ready!") logging.getLogger().removeHandler(asserting_handler) unittest.main() 

Answer 2

This is what Mock Objects are for.

You can use the mock-up version of logging, which properly buffers log messages so that you can make statements about them later.

Answer 3

Just FWIW, in the datalad project, we needed similar functionality, as well as just learning the logs (and, perhaps, viewing). So, here is the solution - the swallow_logs context handler: https://github.com/datalad/datalad/blob/master/datalad/utils.py#L296 (currently on b633c9da46ab9cccde3d4767928d167a91857153). So now in the test we are doing something like

 def test_swallow_logs(): lgr = logging.getLogger('datalad') with swallow_logs(new_level=9) as cm: eq_(cm.out, '') lgr.log(8, "very heavy debug") eq_(cm.out, '') # not even visible at level 9 lgr.log(9, "debug1") eq_(cm.out, 'debug1\n') # not even visible at level 9 lgr.info("info") eq_(cm.out, 'debug1\ninfo\n') # not even visible at level 9