An example Django project with nice logging settings for debugging failures.
- stdout & rotating file logging
- timestamps in the log format
- logs visible from runserver, gunicorn, uwsgi, systemd, honcho, Docker
- deploy to Heroku button which just works with
heroku logs - show how to upgrade to Sentry
Tested in Django 1.9, but should work since 1.3, though 1.9 made some changes to the default Django loggers.
Sample log file output:
2016-04-05 22:12:32,984 [Thread-1 ] [INFO ] [djangoproject.logger] This is a manually logged INFO string.
2016-04-05 22:12:32,984 [Thread-1 ] [DEBUG] [djangoproject.logger] This is a manually logged DEBUG string.
2016-04-05 22:12:32,984 [Thread-1 ] [ERROR] [django.request ] Internal Server Error: /
Traceback (most recent call last):
File "/Users/kermit/.virtualenvs/fail-nicely-django/lib/python3.5/site-packages/django/core/handlers/base.py", line 149, in get_response
response = self.process_exception_by_middleware(e, request)
File "/Users/kermit/.virtualenvs/fail-nicely-django/lib/python3.5/site-packages/django/core/handlers/base.py", line 147, in get_response
response = wrapped_callback(request, *callback_args, **callback_kwargs)
File "/Users/kermit/projekti/git/fail-nicely-django/djangoproject/brokenapp/views.py", line 12, in brokenview
raise Exception('This is an exception raised in a view.')
Exception: This is an exception raised in a view.
Django by default seems to prefer not to write the things you log to it anywhere. It instead lets its loggers shortly meditate on the messages sent their way, after which they silently discard them. The messages are simply disintegrated... They evaporate into the circuitry's chasm of nothingness... They cease to be.
It somehow seems odd to have “the default” and “it's probably not what you want” describe the same thing 😃 ...
“If the disable_existing_loggers key in the LOGGING dictConfig is set to True (which is the default) then all loggers from the default configuration will be disabled. Disabled loggers are not the same as removed; the logger will still exist, but will silently discard anything logged to it, not even propagating entries to a parent logger. Thus you should be very careful using 'disable_existing_loggers': True; it’s probably not what you want. Instead, you can set disable_existing_loggers to False and redefine some or all of the default loggers [...].”
— Excerpt From: The Official Django Documentation
Second, if you do use loggers, the runserver/gunicorn process doesn't output
log messages in your console. Things like Docker kind of religiously depend on
the executable outputting its own log files to stdout,
so why not do it this way?
Others seem to be missing "complete working example code" for effectively using Django's logging capabilities too.
For these reason and after having
some problems of my own
getting Django/Flask, gunicorn and supervisord
to behave nicely with the log output, I started assembling
the best options I found into a nice example configuration. This is still
work in progress, so suggestions and patches are welcome 😃.
To test the setup locally:
python3 -m venv venv
source ./venv/bin/activate
pip install -r requirements.txt
python djangoproject/manage.py migrate
python djangoproject/manage.py runserver
And in another tab admire your logs:
tail -f djangoproject/djangoproject.log
To trigger some errors and log messages just open/refresh http://localhost:8000/.
To see gunicorn output, issue honcho start
and open/refresh http://localhost:5000/
You can also try it on Heroku:
And you should be able to examine the logs after you refresh the page.
heroku logs -t --app myherokuapp
Open https://myherokuapp.herokuapp.com in your browser to generate some exceptions (substitute your real app name).
Cool, then just copy the djangoproject/djangoproject/logger.py file to your project (into the same folder where your settings.py is located) and add the following line to the bottom of your settings.py file:
from .logger import LOGGING
Then in every part of your project where you wanna log something manually,
either import the logger like in
djangoproject/brokenapp/views.py.
Alternatively, if you want the logger name to be something other
than djangoproject.logger, add to the top of every module
where you want to log something:
import logging
log = logging.getLogger(__name__)
Profit:
log.info('this is very important to log')
That's it, rock on!