Overly loud tests in the development environment

[interDist]

We recently went through an upgrade of Django and Python, including the supporting tools, and suddenly our tests started outputting lots of extra information (that was not there before), when run in the development environment. After countless hours trying to find the source of the output, I finally discovered that DDT now adds a lastResort handler to the root logger. This change, implemented in #1603, is fairly recent (merged 6 months ago) and, unfortunately, is not documented in the changelog.
The difference between the development environment and the CI testing environment is, of course, that in the CI flow DDT is not installed.
How can DDT be updated so as to avoid all the verbose output being printed, when tests are run?

[matthiask]

Thanks for the report! I don't have a good answer right away. I certainly prefer too much logging to no logging at all in development. It's not good that this isn't mentioned in the changelog though, that's for sure.

Can this issue be fixed (or worked around) by adding (or removing) some logging configuration in your project? I have to admit that I'm a bit surprised because I have the toolbar installed everywhere these days and have never seen this behavior; but I'm at loss as to what the difference between our setups may be. If you find an easy solution (or anybody else!) we should definitely retroactively add this to the release notes, or maybe even to the installation instructions.

[tim-schilling]

I'm having difficulty reproducing this as well. @interDist could you show us how you add the toolbar into your middleware and installed apps in your settings as well as how you're including the toolbar's urls? Include any protecting if statements.

[interDist]

Sure. Here is our configuration.

settings/base.py

MIDDLEWARE = [
    'django.contrib.sessions.middleware.SessionMiddleware',
    'django.middleware.common.CommonMiddleware',
    'django.middleware.csrf.CsrfViewMiddleware',
    'django.contrib.auth.middleware.AuthenticationMiddleware',
    'django.contrib.messages.middleware.MessageMiddleware',
    'django.middleware.clickjacking.XFrameOptionsMiddleware',
    'django.contrib.flatpages.middleware.FlatpageFallbackMiddleware',
    'dnt.middleware.DoNotTrackMiddleware',
    'core.middleware.AccountFlagsMiddleware',
]

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'mail_admins_important_bits': {
            'level': 'WARNING',
            'class': 'django.utils.log.AdminEmailHandler',
        },
        'mail_admins_severe_bits': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
        },
    },
    'loggers': {
        'my_project': {
            'handlers': ['mail_admins_severe_bits'],
        },
        'my_project.auth': {
            'handlers': ['mail_admins_important_bits'],
            'propagate': False,
        },
    },
}

settings/dev.py

INSTALLED_APPS += (
    'debug_toolbar',
)

MIDDLEWARE.insert(
    [i for i, mw in enumerate(MIDDLEWARE) if mw.startswith('django')][-1] + 1,
    'debug_toolbar.middleware.DebugToolbarMiddleware'
)

DEBUG_TOOLBAR_CONFIG = {
    'JQUERY_URL': '/static/js/jquery.min.js',
    'DISABLE_PANELS': {
        'debug_toolbar.panels.redirects.RedirectsPanel',
    },
    'SHOW_TOOLBAR_CALLBACK': 'my_project.debug.show_debug_toolbar',
}

my_project.debug.py

def show_debug_toolbar(request):
    return bool(settings.DEBUG)

urls.py

urlpatterns = [
    ...
]

if settings.DEBUG:
    import debug_toolbar
    urlpatterns += [
        path('__debug__/', include(debug_toolbar.urls)),
    ]

The tests are run using unittest. python3 ./manage.py test. @matthiask I don’t mind too much logging in development env, but it clutters the output of the tests when the testsuite is run in dev. particularly since the testsuite generates on purpose error conditions to verify proper handling of those.

[tim-schilling]

Do you run your tests using settings/dev.py? I'd recommend running them in an environment where the toolbar doesn't get enabled.

[interDist]

Well, when I am writing / updating the tests, I am doing it in the development environment. Also, when updating a piece of code I would want to first run the related tests, in dev env, to check I did not break anything, right? I suppose I could use --settings=my_project.settings.devtest which would be similar to the existing settings/dev.py but without DDT stuff.

However, nothing of it is documented in the docs (usage of the lastResort logger, running tests in an environment without the toolbar, implications of running tests in an environment with the toolbar enabled)...

[tim-schilling]

@interDist sorry for not responding earlier. Yes you want to run your tests on your local machine, but I believe they should be run with your production configuration, meaning DEBUG=False, no toolbar, etc.

If you (or you @Shriukan33) could create a minimal project that reproduces this effect that would be extremely helpful to us. There is the example django project in the toolbar repo that could be extended if you'd prefer to fork this to have a small head start on building a new project.

[tim-schilling]

Django will force DEBUG = False when running tests.