/dozer/profile.py

  1try:
  2    import cProfile
  3except ImportError:
  4    # python2.4
  5    import profile as cProfile
  6import cPickle
  7import errno
  8import time
  9import os
 10import re
 11import thread
 12from datetime import datetime
 13from pkg_resources import resource_filename
 14
 15from mako.lookup import TemplateLookup
 16from paste import urlparser
 17from webob import Request, Response
 18from webob import exc
 19
 20here_dir = os.path.dirname(os.path.abspath(__file__))
 21
 22DEFAULT_IGNORED_PATHS = [r'/favicon\.ico$', r'^/error/document']
 23
 24class Profiler(object):
 25    def __init__(self, app, global_conf=None, profile_path=None,
 26                 ignored_paths=DEFAULT_IGNORED_PATHS,
 27                 dot_graph_cutoff=0.2, **kwargs):
 28        """Profiles an application and saves the pickled version to a
 29        file
 30        """
 31        assert profile_path, "need profile_path"
 32        assert os.path.isdir(profile_path), "%r: no such directory" % profile_path
 33        self.app = app
 34        self.conf = global_conf
 35        self.dot_graph_cutoff = float(dot_graph_cutoff)
 36        self.profile_path = profile_path
 37        self.ignored_paths = map(re.compile, ignored_paths)
 38        tmpl_dir = os.path.join(here_dir, 'templates')
 39        self.mako = TemplateLookup(directories=[tmpl_dir])
 40
 41    def __call__(self, environ, start_response):
 42        assert not environ['wsgi.multiprocess'], (
 43            "Dozer middleware is not usable in a "
 44            "multi-process environment")
 45        req = Request(environ)
 46        req.base_path = req.application_url + '/_profiler'
 47        if req.path_info_peek() == '_profiler':
 48            return self.profiler(req)(environ, start_response)
 49        for regex in self.ignored_paths:
 50            if regex.match(environ['PATH_INFO']) is not None:
 51                return self.app(environ, start_response)
 52        return self.run_profile(environ, start_response)
 53
 54    def profiler(self, req):
 55        assert req.path_info_pop() == '_profiler'
 56        next_part = req.path_info_pop() or 'showall'
 57        method = getattr(self, next_part, None)
 58        if method is None:
 59            return exc.HTTPNotFound('Nothing could be found to match %r' % next_part)
 60        if not getattr(method, 'exposed', False):
 61            return exc.HTTPForbidden('Access to %r is forbidden' % next_part)
 62        return method(req)
 63
 64    def media(self, req):
 65        """Static path where images and other files live"""
 66        path = resource_filename('dozer', 'media')
 67        app = urlparser.StaticURLParser(path)
 68        return app
 69    media.exposed = True
 70
 71    def show(self, req):
 72        profile_id = req.path_info_pop()
 73        if not profile_id:
 74            return exc.HTTPNotFound('Missing profile id to view')
 75        dir_name = self.profile_path or ''
 76        fname = os.path.join(dir_name, profile_id) + '.pkl'
 77        data = cPickle.load(open(fname, 'rb'))
 78        top = [x for x in data['profile'].values() if not x.get('callers')]
 79        res = Response()
 80        res.body = self.render('/show_profile.mako', time=data['time'],
 81                               profile=top, profile_data=data['profile'],
 82                               environ=data['environ'], id=profile_id)
 83        return res
 84    show.exposed = True
 85
 86    def showall(self, req):
 87        dir_name = self.profile_path
 88        profiles = []
 89        errors = []
 90        max_cost = 0
 91        for profile_file in os.listdir(dir_name):
 92            if profile_file.endswith('.pkl'):
 93                path = os.path.join(self.profile_path, profile_file)
 94                modified = os.stat(path).st_mtime
 95                try:
 96                    data = cPickle.load(open(path, 'rb'))
 97                except Exception, e:
 98                    errors.append((modified, '%s: %s' % (e.__class__.__name__, e), profile_file[:-4]))
 99                else:
100                    environ = data['environ']
101                    top = [x for x in data['profile'].values() if not x.get('callers')]
102                    if top:
103                        total_cost = max(float(x['cost']) for x in top)
104                    else:
105                        total_cost = 0
106                    max_cost = max(max_cost, total_cost)
107                    profiles.append((modified, environ, total_cost, profile_file[:-4]))
108
109        profiles.sort(reverse=True)
110        errors.sort(reverse=True)
111        res = Response()
112        if profiles:
113            earliest = profiles[-1][0]
114        else:
115            earliest = None
116        res.body = self.render('/list_profiles.mako', profiles=profiles,
117                               errors=errors, now=time.time(),
118                               earliest=earliest, max_cost=max_cost)
119        return res
120    showall.exposed = True
121
122    def delete(self, req):
123        profile_id = req.path_info_pop()
124        if profile_id: # this prob a security risk
125            try:
126                for ext in ('.gv', '.pkl'):
127                    os.unlink(os.path.join(self.profile_path, profile_id + ext))
128            except OSError, e:
129                if e.errno == errno.ENOENT:
130                    pass # allow a file not found exception
131                else:
132                    raise
133            return Response('deleted %s' % profile_id)
134
135        for filename in os.listdir(self.profile_path):
136            if filename.endswith('.pkl') or filename.endswith('.gv'):
137                os.unlink(os.path.join(self.profile_path, filename))
138        res = Response()
139        res.location = '/_profiler/showall'
140        res.status_int = 302
141        return res
142    delete.exposed = True
143
144
145    def render(self, name, **vars):
146        tmpl = self.mako.get_template(name)
147        return tmpl.render(**vars)
148
149    def run_profile(self, environ, start_response):
150        """Run the profile over the request and save it"""
151        prof = cProfile.Profile()
152        response_body = []
153
154        def catching_start_response(status, headers, exc_info=None):
155            start_response(status, headers, exc_info)
156            return response_body.append
157
158        def runapp():
159            appiter = self.app(environ, catching_start_response)
160            try:
161                response_body.extend(appiter)
162            finally:
163                if hasattr(appiter, 'close'):
164                    appiter.close()
165
166        prof.runcall(runapp)
167        body = ''.join(response_body)
168        results = prof.getstats()
169        tree = buildtree(results)
170
171        # Pull out 'safe' bits from environ
172        safe_environ = {}
173        for k, v in environ.iteritems():
174            if k.startswith('HTTP_'):
175                safe_environ[k] = v
176            elif k in ['REQUEST_METHOD', 'SCRIPT_NAME', 'PATH_INFO',
177                       'QUERY_STRING', 'CONTENT_TYPE', 'CONTENT_LENGTH',
178                       'SERVER_NAME', 'SERVER_PORT', 'SERVER_PROTOCOL']:
179                safe_environ[k] = v
180        safe_environ['thread_id'] = str(thread.get_ident())
181        profile_run = dict(time=datetime.now(), profile=tree,
182                           environ=safe_environ)
183        fname_base = str(time.time()).replace('.', '_')
184        prof_file = fname_base + '.pkl'
185
186        dir_name = self.profile_path or ''
187        cPickle.dump(profile_run, open(os.path.join(dir_name, prof_file), 'wb'))
188        write_dot_graph(results, tree, os.path.join(dir_name, fname_base+'.gv'),
189                        cutoff=self.dot_graph_cutoff)
190        del results, tree, profile_run
191        return [body]
192
193
194def label(code):
195    """Generate a friendlier version of the code function called"""
196    if isinstance(code, str):
197        return code
198    else:
199        return '%s %s:%d' % (code.co_name,
200                             code.co_filename,
201                             code.co_firstlineno)
202
203
204def graphlabel(code):
205    lb = label(code)
206    return lb.replace('"', "'").strip()
207
208
209def setup_time(t):
210    """Takes a time generally assumed to be quite small and blows it
211    up into millisecond time.
212
213    For example:
214        0.004 seconds     -> 4 ms
215        0.00025 seconds   -> 0.25 ms
216
217    The result is returned as a string.
218
219    """
220    t = t*1000
221    t = '%0.2f' % t
222    return t
223
224def color(w):
225    # color scheme borrowed from
226    # http://gprof2dot.jrfonseca.googlecode.com/hg/gprof2dot.py
227    hmin, smin, lmin = 2/3., 0.8, .25
228    hmax, smax, lmax = 0, 1, .5
229    gamma = 2.2
230    h = hmin + w * (hmax - hmin)
231    s = smin + w * (smax - smin)
232    l = lmin + w * (lmax - lmin)
233    # http://www.w3.org/TR/css3-color/#hsl-color
234    if l <= 0.5:
235        m2 = l * (s + 1)
236    else:
237        m2 = l + s - l * s
238    m1 = l * 2 - m2
239    def h2rgb(m1, m2, h):
240        if h < 0:
241            h += 1.0
242        elif h > 1:
243            h -= 1.0
244        if h * 6 < 1.0:
245            return m1 + (m2 - m1) * h * 6
246        elif h * 2 < 1:
247            return m2
248        elif h * 3 < 2:
249            return m1 + (m2 - m1) * (2/3.0 - h) * 6
250        else:
251            return m1
252    r = h2rgb(m1, m2, h + 1/3.0)
253    g = h2rgb(m1, m2, h)
254    b = h2rgb(m1, m2, h - 1/3.0)
255    # gamma correction
256    r **= gamma
257    g **= gamma
258    b **= gamma
259    # graphvizification
260    r = min(max(0, round(r * 0xff)), 0xff)
261    g = min(max(0, round(g * 0xff)), 0xff)
262    b = min(max(0, round(b * 0xff)), 0xff)
263    return "#%02X%02X%02X" % (r, g, b)
264
265
266def write_dot_graph(data, tree, filename, cutoff=0.2):
267    f = open(filename, 'w')
268    f.write('digraph prof {\n')
269    f.write('\tsize="11,9"; ratio = fill;\n')
270    f.write('\tnode [style=filled];\n')
271
272    # Find the largest time
273    highest = 0.00
274    for entry in tree.values():
275        if float(entry['cost']) > highest:
276            highest = float(entry['cost'])
277    if highest == 0:
278        highest = 1 # avoid division by zero
279
280    for entry in data:
281        code = entry.code
282        entry_name = graphlabel(code)
283        skip = float(setup_time(entry.totaltime)) < cutoff
284        if isinstance(code, str) or skip:
285            continue
286        else:
287            t = tree[label(code)]['cost']
288            c = color(float(t) / highest)
289            f.write('\t"%s" [label="%s\\n%sms",color="%s",fontcolor="white"]\n' % (entry_name, code.co_name, t, c))
290        if entry.calls:
291            for subentry in entry.calls:
292                subcode = subentry.code
293                skip = float(setup_time(subentry.totaltime)) < cutoff
294                if isinstance(subcode, str) or skip:
295                    continue
296                sub_name = graphlabel(subcode)
297                f.write('\t"%s" -> "%s" [label="%s"]\n' % \
298                    (entry_name, sub_name, subentry.callcount))
299    f.write('}\n')
300    f.close()
301
302
303def buildtree(data):
304    """Takes a pmstats object as returned by cProfile and constructs
305    a call tree out of it"""
306    functree = {}
307    callregistry = {}
308    for entry in data:
309        node = {}
310        code = entry.code
311        # If its a builtin
312        if isinstance(code, str):
313            node['filename'] = '~'
314            node['source_position'] = 0
315            node['func_name'] = code
316        else:
317            node['filename'] = code.co_filename
318            node['source_position'] = code.co_firstlineno
319            node['func_name'] = code.co_name
320            node['line_no'] = code.co_firstlineno
321        node['cost'] = setup_time(entry.totaltime)
322        node['function'] = label(code)
323
324        if entry.calls:
325            for subentry in entry.calls:
326                subnode = {}
327                subnode['builtin'] = isinstance(subentry.code, str)
328                subnode['cost'] = setup_time(subentry.totaltime)
329                subnode['function'] = label(subentry.code)
330                subnode['callcount'] = subentry.callcount
331                node.setdefault('calls', []).append(subnode)
332                callregistry.setdefault(subnode['function'], []).append(node['function'])
333        else:
334            node['calls'] = []
335        functree[node['function']] = node
336    for key in callregistry:
337        node = functree[key]
338        node['callers'] = callregistry[key]
339    return functree