Assert that logging has been called with specific string

Question

I'm trying to use unittest to test some functions of a SimpleXMLRPCServer I made. Togethere with Mock, I'm now trying to assert that a specific message has been logged when an if statement is reached, but I can't get it to work. I've tried implementing various answers I found here on StackOverflow or by Googling, but still no luck. The calls I make in the Test Case are as follows:

def test_listen_for_tasks(self):
    el = {'release': 'default', 'component': None}
    for i in range(50):
        self.server._queue.put(el)
    ServerThread.listen_for_tasks(self.server, 'bla', 'blabla')
    with mock.patch('queue_server.logging') as mock_logging:
        mock_logging.warning.assert_called_with('There are currently {}'
                                                ' items in the queue'.format(
                                                 str(len(self.server._queue.queue))))

The function in the server is as follows:

def listen_for_tasks(self, release, component):
    item = {'release': release, 'component': component}
    for el in list(self._queue.queue):
        if self.is_request_duplicate(el, item):
            logger.debug('Already have a request'
                         ' for this component: {}'.format(item))
            return
    self._queue.put(item, False)
    if len(self._queue.queue) > 50:
        logger.warning('There are currently {}'
                       ' items in the queue'.format(
                        str(len(self._queue.queue))))

Any idea why this is not working? I'm new to unit testing in Python and asserting that a logger has done something seems the biggest problem one could face, so I might have screwed up with something really simple in the code. Any kind of help will be greatly appreciated!

EDIT: for completeness, here's the test output and failure:

.No handlers could be found for logger "queue_server"
F


FAIL: test_listen_for_tasks (__main__.TestQueueServer)

Traceback (most recent call last):
  File "artifacts_generator/test_queue_server.py", line 46, in   test_listen_for_tasks
str(len(self.server._queue.queue))))
  File "/home/lugiorgi/Desktop/Code/publisher/env/local/lib/python2.7/site-packages/mock/mock.py", line 925, in assert_called_with
raise AssertionError('Expected call: %s\nNot called' % (expected,))
AssertionError: Expected call: warning('There are currently 51 items in the queue')
Not called

Ran 2 tests in 0.137s

FAILED (failures=1)

Answer 1

Since python 3.4 you can use unittest.TestCase class method assertLogs

import logging
import unittest


class LoggingTestCase(unittest.TestCase):
    def test_logging(self):
        with self.assertLogs(level='INFO') as log:
            logging.info('Log message')
            self.assertEqual(len(log.output), 1)
            self.assertEqual(len(log.records), 1)
            self.assertIn('Log message', log.output[0])

Answer 2

You need to first mock the object, then call the function you want to test.

When mocking the object, you also need to provide the full package and object/function name of the object you are mocking, not a variable name.

Finally, it's often more convenient to use the decorator form of patch.

So, for example:

logger = logging.getLogger(__name__)

def my_fancy_function():
    logger.warning('test')

@patch('logging.Logger.warning')
def test_my_fancy_function(mock):
    my_fancy_function()
    mock.assert_called_with('test')

# if you insist on using with:
def test_my_fancy_function_with_with():
    with patch('logging.Logger.warning') as mock:
        my_fancy_function()
        mock.assert_called_with('test')