Extended Profiling Middleware

  1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
# Orignal version taken from http://www.djangosnippets.org/snippets/186/
# Original author: udfalkso
# Modified by: Shwagroo Team

import sys
import os
import re
import hotshot, hotshot.stats
import tempfile
import StringIO

from django.conf import settings


words_re = re.compile( r'\s+' )

group_prefix_re = [
    re.compile( "^.*/django/[^/]+" ),
    re.compile( "^(.*)/[^/]+$" ), # extract module path
    re.compile( ".*" ),           # catch strange entries
]

class ProfileMiddleware(object):
    """
    Displays hotshot profiling for any view.
    http://yoursite.com/yourview/?prof

    Add the "prof" key to query string by appending ?prof (or &prof=)
    and you'll see the profiling results in your browser.
    It's set up to only be available in django's debug mode, is available for superuser otherwise,
    but you really shouldn't add this middleware to any production configuration.

    WARNING: It uses hotshot profiler which is not thread safe.
    """
    def process_request(self, request):
        if (settings.DEBUG or request.user.is_superuser) and request.has_key('prof'):
            self.tmpfile = tempfile.mktemp()
            self.prof = hotshot.Profile(self.tmpfile)

    def process_view(self, request, callback, callback_args, callback_kwargs):
        if (settings.DEBUG or request.user.is_superuser) and request.has_key('prof'):
            return self.prof.runcall(callback, request, *callback_args, **callback_kwargs)

    def get_group(self, file):
        for g in group_prefix_re:
            name = g.findall( file )
            if name:
                return name[0]

    def get_summary(self, results_dict, sum):
        list = [ (item[1], item[0]) for item in results_dict.items() ]
        list.sort( reverse = True )
        list = list[:40]

        res = "      tottime\n"
        for item in list:
            res += "%4.1f%% %7.3f %s\n" % ( 100*item[0]/sum if sum else 0, item[0], item[1] )

        return res

    def summary_for_files(self, stats_str):
        stats_str = stats_str.split("\n")[5:]

        mystats = {}
        mygroups = {}

        sum = 0

        for s in stats_str:
            fields = words_re.split(s);
            if len(fields) == 7:
                time = float(fields[2])
                sum += time
                file = fields[6].split(":")[0]

                if not file in mystats:
                    mystats[file] = 0
                mystats[file] += time

                group = self.get_group(file)
                if not group in mygroups:
                    mygroups[ group ] = 0
                mygroups[ group ] += time

        return "<pre>" + \
               " ---- By file ----\n\n" + self.get_summary(mystats,sum) + "\n" + \
               " ---- By group ---\n\n" + self.get_summary(mygroups,sum) + \
               "</pre>"

    def process_response(self, request, response):
        if (settings.DEBUG or request.user.is_superuser) and request.has_key('prof'):
            self.prof.close()

            out = StringIO.StringIO()
            old_stdout = sys.stdout
            sys.stdout = out

            stats = hotshot.stats.load(self.tmpfile)
            stats.sort_stats('time', 'calls')
            stats.print_stats()

            sys.stdout = old_stdout
            stats_str = out.getvalue()

            if response and response.content and stats_str:
                response.content = "<pre>" + stats_str + "</pre>"

            response.content = "\n".join(response.content.split("\n")[:40])

            response.content += self.summary_for_files(stats_str)

            os.unlink(self.tmpfile)

        return response

More like this

  1. Profiling Middlware by udfalkso 7 years ago
  2. Profiling middleware using cProfile by sgb 5 years, 12 months ago
  3. Interactive Profiling Middleware by sfllaw 3 years, 8 months ago
  4. Profiling Middleware w/sorting by petrilli 4 years, 10 months ago
  5. Unit Test Profiling by justquick 5 years, 2 months ago

Comments

udfalkso (on February 25, 2008):

Very cool, thanks!

#

freejoe76 (on April 1, 2008):

Python 2.4 throws an invalid syntax error on the "if" in line 57 : res += "%4.1f%% %7.3f %s\n" % ( 100*item[0]/sum if sum else 0, item[0], item[1] )

#

hans (on April 28, 2008):

This might expose my lack of understanding of this, but how come my application code doesn't show up in the profile?

#

andrew (on May 14, 2008):

To handle views with alternative mimetypes (such as XML), you should assign to response['content-type'] on line 112

#

andrew (on May 14, 2008):

To simultaneous profile SQL queries (in DEBUG mode):

  • with your other imports, add

    from django.db import connection

    import pprint

  • in process_request, add:

    connection.queries = []

  • in process_response, add:

    response.content += '\n%d SQL Queries:\n' % len(connection.queries)

    response.content += pprint.pformat(connection.queries)

#

kedare (on October 16, 2008):

I get this error when i go to the admin area with this middleware: 'WSGIRequest' object has no attribute 'user'

#

peterbe (on November 19, 2008):

For this to work with >= 1.0 you need to change the multiple occurances of 'request.has_key' to this:

'prof' in request.GET

#

Krystal (on April 14, 2009):

You can replace the tiercary operator mentionned above with

res += "%4.1f%% %7.3f %s\n" % ( sum and 100*item[0]/sum or 0, item[0], item[1] )

So it run on python 2.4

And to have a (little) more info on SQL request, you could extend the code of andrew with this :

response.content += '\n%d SQL Queries in %.3f seconds :\n' %(
    len(connection.queries), sum([ float(i.get('time', 0)) for i in connection.queries ]))
response.content += pprint.pformat(connection.queries)

in the process_response file.

#

Krystal (on April 27, 2009):

And don't forget to put the SQL request debug code in [HTML_REMOVED]

#

adamlofts (on June 24, 2009):

I've found this snippet a bit weird in that it reuses the old response object. This works fine except when the content type is not html, e.g. looking at XML output. A quick fix to this problem is to add:

response['Content-Type'] = 'text/html'

to the end of process_response()

#

(Forgotten your password?)