Hidden variable lookup failures and template performance

[akaihola]

Here's an issue to be aware of wrt template performance:

I noticed that one of my templates was getting really slow. I profiled
it and it seemed to spend lots of time calling the __str__ method of
one of my models. The method contains a query for a related object,
which slowed things down quite a bit.

The mystery was, why was __str__ called in the first place, since my
template never prints out instances of that particular models, but only
accesses its properties directly.

The root cause of the slowdown was an {% ifnotequal myobj None %} tag,
which causes a variable lookup failure since 'None' is not part of the
context. You can't compare None values this way in Django of course,
and I should have known that, and in this particular case changing the
condition to {% if myobj %} works just fine too; problem solved and
customer happy.

I was still left intrigued about the __str__ call, and with some
debugging I made the following observations:

The reason for the __str__ call lies in the default Model.__repr__
method (django/db/models/base.py:79 in Django r4269), which ends up
evaluating '%s' % self as a part of the string it builds.

Why was __repr__ called then?

It turns out that even though failed variable lookups in many cases
silently evaluate as empty strings in Django templates, exceptions are
raised and caught behind the scenes, and to generate some of the
exception messages calls to model methods are required. In my case the
__repr__ call was triggered in the resolve_variable function
(django/template/__init__.py:663 in r4269) when 'None' was not found in
the context. Actually, if I'm not mistaken, __repr__ is called
recursively for every object in the context tree!

So, to avoid template performance problems, one should make sure that:
- no unnecessary variable lookup failures occur
- model __str__ methods are lightweight
- or, alternatively, lightweight __repr__ methods are defined for
models

This kind of performance problems are tricky to profile and debug, so
some help from Django's side would be useful. Any ideas?

[Karen]

Bah, I feel guilty. I ran into this several months ago and reported it
here, got some feedback that I should open an issue on it but never
followed up. So now I have:

http://code.djangoproject.com/ticket/3235

The suggestions you make for django user's code to avoid the
performance hit are valid, but I don't think django itself ought to
include a potentially big performance hit for looking up a non-existant
variable, so hopefully this will be addressed in the base code as well.

Cheers,
Karen

[akaihola]

Karen,

Thanks for opening the ticket. Nice to see a patch as well.