Python: Using logging info in nose/unittest?

Question

I have a test function that manipulates the internal state of an object. The object logs the following using logging.info().

INFO:root:_change: test light red
INFO:root:_change: test light green
INFO:root:_change: test light yellow

How can I incorporate this into a nose or unittest function so that I can have a test similar to this?

def test_thing():
    expected_log_output = "INFO:root:_change: test light red\n" +\
                          "INFO:root:_change: test light green\n" +\
                          "INFO:root:_change: test light yellow\n"

    run_thing()
    assert actual_log_output matches expected_log_output

Answer 1

When it comes to testing my logging, what I usually do is mock out my logger and ensure it is called with the appropriate params. I typically do something like this:

class TestBackupInstantiation(TestCase):
    @patch('core.backup.log')
    def test_exception_raised_when_instantiating_class(self, m_log):
        with self.assertRaises(IOError) as exc:
            Backup(AFakeFactory())
        assert_equal(m_log.error.call_count, 1)
        assert_that(exc.exception, is_(IOError))

So you can even make a call where you can test to ensure what the logger is called with to validate the message.

I believe you can do something like:

m_log.error.assert_called_with("foo")

I might also add, when it comes to this kind of testing I love using test frameworks like flexmock and mock

Also, when it comes to validating matchers, py-hamcrest is awesome.