Logging output running django tests under Pycharm

Question

When running/debugging individual tests using django.test.TestCase under PyCharm logging.logger messages are not shown. I've tried setting logging.basicConfig(level=logging.DEBUG) as suggested by How can I see log messages when unit testing in PyCharm? but that didn't help either. I suspect it might be django's TestCase setup interferring.

Is there some other way in test setup or runner configuration that I can turn on debug logging for the test run?

The logging I have set up in my settings.py right now is:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'formatter': 'verbose'
        },
        'file': {
            'level': 'DEBUG',
            'class': 'logging.handlers.TimedRotatingFileHandler',
            'filename': '/var/log/em/mcqueen-dev.log',
            'when': 'midnight',
            'formatter': 'verbose',
        },
    },
    'formatters': {
        'verbose': {
            'format': '%(asctime)s.%(msecs).03d - %(process)d - %(thread)d - %(levelname)8s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s'
        },
        'simple': {
            'format': '%(asctime)s - %(levelname)s %(message)s'
        },
    },
    'loggers': {
        'mcqueen_api': {
            'handlers': ['console', 'file'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'DEBUG')
        },
        'mcqueen_app': {
            'handlers': ['console', 'file'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'DEBUG')
        },
        'mcqueen_base': {
            'handlers': ['console', 'file'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'DEBUG')
        },
    },
}

Can you share django_test config in your case that i suggested? — Son Lam, Apr 09 '16 at 03:42

score 11 · Answer 1 · answered Nov 15 '17 at 13:28

When I want to see logs while working on tests for Django project in PyCharm I'm putting this snippet of code in the file with test:

import logging
logger = logging.getLogger(__name__)
logging.disable(logging.NOTSET)
logger.setLevel(logging.DEBUG)

While running Django tests level for disabling logs is set high (to 50), lowering it (as in line #3 in code above) will cause that logs will be displayed (or saved to file - depending on log handler that is in use).

score 2 · Answer 2 · edited Oct 02 '18 at 17:21

I think it will be work

Log configuration on settings.py

    LOGGING = {
        'version': 1,
        'disable_existing_loggers': False,
        'formatters': {
            'verbose': {
    'format': "[%(asctime)s] %(levelname)s %(message)s",
                'datefmt': "%d/%b/%Y %H:%M:%S"
            }
        },
        'handlers': {
            'file': {
                'level': 'DEBUG',
                'class': 'logging.FileHandler',
                'filename': '/var/log/django_practices.log',
                'formatter': 'verbose'
            },
            'console': {
                'level': 'DEBUG',
                'class': 'logging.StreamHandler',
                'stream': sys.stdout,
                'formatter': 'verbose'
            },
        },
        'loggers': {

            'django_test': {
                'handlers': ['file', 'console'],
                'level': 'DEBUG',
            },
            'name_your_app': {
                'handlers': ['file', 'console'],
                'level': 'DEBUG',
            }

        }
    }

In UnitTest file

import logging
logger = logging.getLogger('django_test')
logger.info('test_log')

And Log will be appearance.

Yes. The output always just shows django's messages about creating the test database and then destroying it, no logging. However, if i put print() in my test it does show up there, so it's definitely a console window — Arne Claassen, Apr 08 '16 at 06:58
In addition to the above settings, i added the 'django-test' block you suggested — Arne Claassen, Apr 08 '16 at 16:41

score 2 · Answer 3 · answered Sep 10 '17 at 11:11

This thread on stackoverflow explains the probable reason your logging output not showing to console. Apparently, django's unittest runner replaces the global sys.stdout/sys.stderr, but the StreamHandler specified from the django settings is still bound up with the original sys.stdout/sys.stderr. The fix is to add a stream handler to your logger in the test module, based on the values of sys.stdout/sys.stderr during execution.

If you want the logger to log to console for all methods of your test case, then you're probably best using a custom base class (see linked to thread for more details) to wrap the logic for adding/removing at setUp/tearDown.

I prefer to use decorators over the individual test methods for wrapping. For example (using the 'django_test' logger config provided by Sơn Lâm's answer):

import logging
import sys
from contextlib import contextmanager

from django.test import TestCase

@contextmanager
def streamhandler_to_console(lggr):
    # Use 'up to date' value of sys.stdout for StreamHandler,
    # as set by test runner.
    stream_handler = logging.StreamHandler(sys.stdout)
    lggr.addHandler(stream_handler)
    yield
    lggr.removeHandler(stream_handler)

def testcase_log_console(lggr):
    def testcase_decorator(func):
        def testcase_log_console(*args, **kwargs):
            with streamhandler_to_console(lggr):
                return func(*args, **kwargs)
        return testcase_log_console
    return testcase_decorator

logger = logging.getLogger('django_test')

class SomeTestCase(TestCase):
    @testcase_log_console(logger)
    def test_something(self):    
        logger.info('show something to console.')

score 0 · Answer 4 · answered Nov 02 '17 at 16:43

I think this is to do with the test runner that you're using - assuming you're using the inbuilt Django tests setup in PyCharm then it should already be setting an environment variable PYTHONUNBUFFERED=1 which I think is what makes the output print directly without being buffered and only showing at the end (which is what I presume is happening). Check that this is set in the test configuration and if it isn't then try that.

See also: Pycharm unit test interactive debug command line doesn't work (particularly if you're using a different test runner)

Logging output running django tests under Pycharm

4 Answers4