how to verfify python log format in unittest?

I know this is old but posting here since it pulled up in google for me...

Probably needs cleanup but it is the first thing that has gotten close for me so I figured it would be good to share.

Here is a test case mixin I've put together that lets me verify a particular handler is being formatted as expected by copying the formatter:

import io
import logging

from django.conf import settings
from django.test import SimpleTestCase
from django.utils.log import DEFAULT_LOGGING

class SetupLoggingMixin:
    def setUp(self):
        super().setUp()
        logging.config.dictConfig(settings.LOGGING)
        self.stream = io.StringIO()
        self.root_logger = logging.getLogger("")
        self.root_hdlr = logging.StreamHandler(self.stream)

        console_handler = None
        for handler in self.root_logger.handlers:
            if handler.name == 'console':
                console_handler = handler
                break

        if console_handler is None:
            raise RuntimeError('could not find console handler')

        formatter = console_handler.formatter
        self.root_formatter = formatter
        self.root_hdlr.setFormatter(self.root_formatter)
        self.root_logger.addHandler(self.root_hdlr)

    def tearDown(self):
        super().tearDown()
        self.stream.close()
        logging.config.dictConfig(DEFAULT_LOGGING)

And here is an example of how to use it:

class SimpleLogTests(SetupLoggingMixin, SimpleTestCase):
    def test_logged_time(self):
        msg = 'foo'
        self.root_logger.error(msg)
        self.assertEqual(self.stream.getvalue(), 'my-expected-message-formatted-as-expected')

After reading the source code of the unittest library, I've worked out the following bypass. Note, it works by changing a protected member of an imported module, so it may break in future versions.

from unittest.case import _AssertLogsContext
_AssertLogsContext.LOGGING_FORMAT = 'same format as your logger'

After these commands the logging context opened by self.assertLogs will use the above format. I really don't know why this values is left hard-coded and not configurable.

I did not find an option to read the format of a logger, but if you use logging.config.dictConfig you can use a value from the same dictionary.

I know this doesn't completely answer the OP's question but I stumbled upon this post while looking for a neat way to capture logged messages.

Taking what @user319862 did, I've cleaned it and simplified it.

import unittest
import logging

from io import StringIO

class SetupLogging(unittest.TestCase):
    def setUp(self):
        super().setUp()
        self.stream = StringIO()
        self.root_logger = logging.getLogger("")
        self.root_hdlr = logging.StreamHandler(self.stream)
        self.root_logger.addHandler(self.root_hdlr)

    def tearDown(self):
        super().tearDown()
        self.stream.close()

    def test_log_output(self):
        """ Does the logger produce the correct output? """
        msg = 'foo'
        self.root_logger.error(msg)
        self.assertEqual(self.stream.getvalue(), 'foo\n')


if __name__ == '__main__':
    unittest.main()

I new to python but have some experience in test/tdd in other languages, and found that the default way of "changing" the formatter is by adding a new streamhandler BUT in the case you already have a stream defined in your logger (i.e. using Azure functions or TestCase::assertLogs that add one for you) you end up logging twice one with your format and another with the "default" format.

If in the OP the function create_logger mutates the formatter of current StreamHandler, instead of adding a new StreamHandler (checks if exist and if doesn't creates a new one and all that jazz...)

Then you can call the create_logger after the with self.assertLogs('', 'DEBUG') as cm: and just assert the cm.output and it just works because you are mutating the Formatter of the StreamHandler that the assertLogs is adding.

So basically what's happening is that the execution order is not appropriate for the test.

The order of execution in OP is:

• import stuff
  • Add stream to logger formatter
• Run test
  • Add another stream to logger formatter via self.assertLogs
  • assert stuff in 2nd StreamHandler

When it should be the order of execution is:

• import stuff
• Add stream with logger formatter (but is irrelevant)
• Run test
• Add another stream with logger formatter via self.assertLogs
• Change current stream logger formatter
• assert stuff in only and properly formatted StreamHandler