Profiling Django Templates

Post by Saul Shanabrook

I have recently been having trouble getting image resizing to perform
well in Django. That is for another post, but the basic scoop is that I
have a view that displays 40+ django imagefields and accesses their
dimensions. This was taking around 6 seconds to render. I tried tracing
it, and I could see it was hitting the storage backend a lot, hitting
S3Boto because I use Amazon S3 for my storage. However I couldn’t tell what exactly was hitting the storage.

My first step was creating a test that reproduced my issue. At its most
basic, it creates x amount of objects, attaches photos to each, and then
times requesting that page. That way I can run it and see exactly how
long it takes, and if I fix my problem, can run it again to make sure. I
wrote it as a test so that database wiping would be taken care of by the
test runner.

Next I used
cProfile to see in which functions the time was being spent.

from time import time  
import cProfile  
import pstats


print 'Accessing update list for the first time'  
start_time = time()  
pr = cProfile.Profile(subcalls=True, builtins=False)  
pr.enable()  
self.app.get(reverse('update-list'))  
pr.disable()  
print 'It took {} seconds'.format(time() - start_time)  
ps = pstats.Stats(pr)  
ps.sort_stats('cumtime')  
ps.print_stats(.05)  

However, even when I saw which functions took up all the time, I wasn’t
sure exactly where in the template those functions were being called.
Was it from photo.url or photo.width?

My next step was to generate all the url’s and dimensions in the view,
instead of in the template. This didn’t have to actually function for my
real template, but at least when I was testing, it would do all the
heavy lifting in the view. I also created little function to, say, get
the width from a photo. That way, when I saw the profile, I could see
what function all the time was spent in.

My key take from this was to create little functions to put suspect code
in and run it through profile to see if those functions do indeed use
that much time.