Profiling Django

Install django-extensions

http://pythonhosted.org/django-extensions/runprofileserver.html


1) sudo pip install django-extensions

2) add 'django_extensions' to your app's INSTALLED_APPS list.

Run server in profiling mode

python  ./manage.py runprofileserver --prof-path=/tmp 8001

Do a query

time curl -i http://localhost:8001/account/eventboard/update/

Write little reporting module

prof.py -- given later

Run report

/tmp/account.eventboard.update.017442ms.1363891644.prof :
         202963 function calls (197801 primitive calls) in 17.443 seconds

   Ordered by: internal time, call count
   List reduced from 2280 to 5 due to restriction <5>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    26201   14.956    0.001   14.956    0.001 /usr/lib/python2.7/ssl.py:154(read)
        2    0.725    0.363    0.725    0.363 /usr/lib/python2.7/ssl.py:301(do_handshake)
      937    0.470    0.001   15.069    0.016 /usr/lib/python2.7/socket.py:406(readline)
       10    0.318    0.032    0.318    0.032 /usr/lib/python2.7/socket.py:223(meth)
        2    0.238    0.119    1.291    0.646 /usr/local/lib/python2.7/dist-packages/httplib2/__init__.py:982(connect)


In this case, most of the page delay was transferring SSL data -- probably from Google Analytics. Huzzah!




#!/usr/bin/env python
# prof.py

import glob, logging, hotshot.stats, pstats, sys

logging.basicConfig(stream=sys.stderr)
LOG = logging.getLogger(__name__)

for path in sys.argv[1:] or glob.glob('/tmp/*.prof'):
    if 'static.' in path:
        continue
    try:
        stats = hotshot.stats.load(path)
    except ValueError:
        stats = pstats.Stats(path)

    stats.sort_stats('time', 'calls') # sort the output based on time spent
    print path,':'
    stats.print_stats(5) # print the top culprits