Logging facility for Django

1 view
Skip to first unread message

Fraser Nevett

unread,
Apr 22, 2007, 4:28:39 PM4/22/07
to Django developers
Hi All,

I'm sure I'm not alone in using simple print statements to trace/log
what is going on in a Django app, especially when debugging. This
works OK when using runserver, but can be more difficult and
problematic to use with mod_python in a production environment.

To try to give greater control and flexibility in logging, I have
created "django-logging", which uses Python's built-in logging module.
It logs messages on a per-request basis and then appends these to HTML
responses so that you can easily see what happened during that
request.

I've put the source and some documentation up on Google Code:

http://code.google.com/p/django-logging/

I'd really appreciate feedback on this and any suggestions of
additional features.

Hopefully people will find this useful. If so, it would be great to
have this included as django.contrib.logging.

Thanks,

Fraser

Jeremy Dunck

unread,
Apr 22, 2007, 8:03:30 PM4/22/07
to django-d...@googlegroups.com
On 4/22/07, Fraser Nevett <fra...@gmail.com> wrote:
...

> I'm sure I'm not alone in using simple print statements to trace/log

Huzzah, you've knocked something off my to-do list. :)

I've read the doc but not yet the code. My immediate feedback is that
it'd be nice to have a convention of
logging.getLogger('project_name.app_name'). I also think it'd be
nice to have the option to turn off SQL logging, since that can be
quite verbose and not germane.

> http://code.google.com/p/django-logging/

del.icio.us :)

Malcolm Tredinnick

unread,
Apr 23, 2007, 12:49:06 AM4/23/07
to django-d...@googlegroups.com
On Sun, 2007-04-22 at 20:28 +0000, Fraser Nevett wrote:
> Hi All,
>
> I'm sure I'm not alone in using simple print statements to trace/log
> what is going on in a Django app, especially when debugging. This
> works OK when using runserver, but can be more difficult and
> problematic to use with mod_python in a production environment.
>
> To try to give greater control and flexibility in logging, I have
> created "django-logging", which uses Python's built-in logging module.
> It logs messages on a per-request basis and then appends these to HTML
> responses so that you can easily see what happened during that
> request.

I agree with Jeremy, this is a nice contribution. Thanks for writing
it. :-)

I particularly like the way the design is very non-intrusive, having no
effect at all when you are not using it.

One minor point for when you want to do a point release: I think it
would be worth shipping a copy of some documentation -- at least, how to
use it -- with the code. I originally grabbed the download, went to look
at it whilst on a train and discovered a complete lack of documentation
because it expected me to be connected to the Internet. The whole planet
does not have "always on" Internet yet (thankfully).

Regards,
Malcolm

Fraser Nevett

unread,
Apr 23, 2007, 8:55:59 AM4/23/07
to Django developers
Thanks for the feedback.

Jeremy, what database backend are you using? On MySQL I don't see any
SQL getting logged. I guess registering the handler to the root logger
must mean it gets all the log information from the other loggers too.
It's on my to-do list to add the ability to filter by logger so that
you can opt-in or -out of the messages from libraries, etc.

Malcolm, thanks for the documentation suggestion. I had written a
brief Overview wiki page, but as you say online documentation isn't
particularly useful when you're offline! Since Google Code stores wiki
pages in the subversion repository, I've added them as a svn:externals
to the module directory so that they get checked out automatically.

Cheers,

Fraser

Vinay Sajip

unread,
Apr 23, 2007, 5:09:07 PM4/23/07
to Django developers
Hi Fraser,

Thanks for sharing this app with us. After a quick read through, I've
some
points on the initialising code in middleware.py:
#==========================================
handler = ThreadBufferedHandler()
handler.setLevel(logging.NOTSET)
handler.setFormatter(logging.Formatter())
logging.root.setLevel(logging.NOTSET)
logging.root.addHandler(handler)
#==========================================
(a) Setting NOTSET on the root logger will cause absolutely everything
to
go through the logging system - this could be unnecessary overhead as
well
as being too much information.
(b) You don't need to set NOTSET on the handler - that's the default
setting.
(c) You don't need to set a do-nothing formatter on the handler, as
you are
not using the formatting capability anyway.
(d) It's probably better to put logging configuration in settings.py;
this is
something people will want to tweak without touching your app. The
middleware code still adds value in terms of adding the formatted
HTML to
the end of the response. So, I would move this code to settings.py.

Also, you could consider using thread locals to hold the list of
records, as
this usage seems what they were designed for.

> Jeremy, what database backend are you using? On MySQL I don't see any
> SQL getting logged. I guess registering the handler to the root logger

I think Jeremy is talking about the potential for a lot of logging
output.
AFAIK, Django does not use logging in the core code - this would need
to be added. Recently, when I was doing a legacy migration into
Django, I kept
hitting constraint errors which were hard to find amongst the
thousands of
records being inserted. Hence, I had to add some logging to my working
copy to
troubleshoot these issues.

> must mean it gets all the log information from the other loggers too.
> It's on my to-do list to add the ability to filter by logger so that
> you can opt-in or -out of the messages from libraries, etc.

This kind of functionality is already built into the logging system.
For
example, a user could set up in settings.py:

import logging
root = logging.root
root.setLevel(logging.ERROR) # root setting inherited by all
root.addHandler(ThreadBufferedHandler())
logging.getLogger("mysite.app1").setLevel(logging.INFO) # override
logging.getLogger("mysite.app2").setLevel(logging.DEBUG) # debugging
this now

You can set levels for loggers used by libraries from settings.py,
too.
Supposing that SQL was logged in django/db/backends/utils.py to a
logger
named "django.db.backends.util". Then by default with the above setup,
no SQL
logging below ERROR happens, because the logger inherits its settings
from its
ancestor (i.e. root, in this case). Setting the logging level in
settings.py,

logging.getLogger("django.db.backends.util").setLevel(logging.DEBUG)

will turn on SQL logging, with no other changes needed. To turn the
verbosity
down again, simply comment the line out or set some other level on the
logger.

Because loggers operate in a hierarchy, if the logger names used by a
module
are the same as the module name, then even if logging code is added to
Django
core code, you could easily turn up or down the verbosity of selected
chunks
of the framework, e.g.

logging.getLogger("django.contrib").setLevel(logging.DEBUG)

or

logging.getLogger("django.contrib.auth").setLevel(logging.DEBUG)

to affect all of the django contrib modules, or just the auth modules.

Regards,

Vinay Sajip

Fraser Nevett

unread,
Apr 23, 2007, 7:01:58 PM4/23/07
to Django developers
Hi Vinay,

Thanks for taking the time to review and provide feedback on this.
Your explanation of how the logging module works and how it can be
used was really helpful.

> (a) Setting NOTSET on the root logger will cause absolutely everything
> to go through the logging system - this could be unnecessary overhead as
> well as being too much information.

My reason for doing this was indeed to capture as much information as
possible and then give the user the ability to filter the messages
afterwards. I guess if there are lots of things logged in a single
request then this could get unmanageable.

> (b) You don't need to set NOTSET on the handler - that's the default
> setting.

This was left in from me experimenting and has now been removed.

> (c) You don't need to set a do-nothing formatter on the handler, as
> you are not using the formatting capability anyway.

I had (unnecessarily) been using that formatter to format the
timestamps for the log records, but have now removed this and tidied
it up to use strftime.

> (d) It's probably better to put logging configuration in settings.py;

Moving the level configuration into settings.py is probably a good
idea, but I think it would be good to find a balance between ease of
getting the logging facility up and running and level of control for
more advanced users.

Having the handler registered with the root logger by default means
things should just work with minimal configuration. If someone didn't
want this configuration, they could always use removeHandler to
unregister it from the root logger.

What do people think?

> Also, you could consider using thread locals to hold the list of
> records, as this usage seems what they were designed for.

I agree that thread locals would probably be ideal, but it looks like
threading.local was only introduced in Python 2.4. To stay aligned
with Django, it should really be 2.3 compatible.

Cheers,

Fraser

P.S. I have also added handling of HTTP redirects this evening as
requested by "pmdhazy" via the Google Code issue list.

Vinay Sajip

unread,
Apr 23, 2007, 7:23:53 PM4/23/07
to Django developers
Hi Fraser,

> > (a) Setting NOTSET on the root logger will cause absolutely everything
> > to go through the logging system - this could be unnecessary overhead as
> > well as being too much information.
>
> My reason for doing this was indeed to capture as much information as
> possible and then give the user the ability to filter the messages
> afterwards. I guess if there are lots of things logged in a single
> request then this could get unmanageable.

I would say it is better to use the logging package's mechanisms for
filtering, as it will mean both less run-time overhead and less work
for you. It also allows for other logging sinks than your middleware
(e.g. logging to file) and logging works much as in any other
application, with no magic.

> > (d) It's probably better to put logging configuration in settings.py;
>
> Moving the level configuration into settings.py is probably a good
> idea, but I think it would be good to find a balance between ease of
> getting the logging facility up and running and level of control for
> more advanced users.
>
> Having the handler registered with the root logger by default means
> things should just work with minimal configuration. If someone didn't
> want this configuration, they could always use removeHandler to
> unregister it from the root logger.
>
> What do people think?

I think where you presently do the initialization (in middleware.py),
you can check to see if the root logger has any handlers. If not, go
ahead and add your handler as you do presently. Otherwise, assume
logging has been configured in settings.py and don't do any
configuration. This allows both novice users and advanced users to do
the least amount of work: novice users do nothing in settings.py, and
advanced users configure logging as they would do anyway.

> > Also, you could consider using thread locals to hold the list of
> > records, as this usage seems what they were designed for.
>
> I agree that thread locals would probably be ideal, but it looks like
> threading.local was only introduced in Python 2.4. To stay aligned
> with Django, it should really be 2.3 compatible.
>

Fair point - I'd forgotten that threading.local arrived with 2.4.

Regards,

Vinay

Andrew Durdin

unread,
Apr 24, 2007, 4:12:52 AM4/24/07
to Django developers
On Apr 24, 12:23 am, Vinay Sajip <vinay_sa...@yahoo.co.uk> wrote:
>
> > I agree that thread locals would probably be ideal, but it looks like
> > threading.local was only introduced in Python 2.4. To stay aligned
> > with Django, it should really be 2.3 compatible.
>
> Fair point - I'd forgotten that threading.local arrived with 2.4.

However Django includes the _threading_local module from Python 2.4,
so that it is available to Django apps running on 2.3. Import it like
this:

try:
# Only exists in Python 2.4+
from threading import local
except ImportError:
# Import copy of _thread_local.py from Python 2.4
from django.utils._threading_local import local

Andrew

Reply all
Reply to author
Forward
0 new messages