~bzr-pqm/bzr/bzr.dev

1185.33.86 by Martin Pool
Add additional module for lsprof.
1
# this is copied from the lsprof distro because somehow
2
# it is not installed by distutils
3
# I made one modification to profile so that it returns a pair
4
# instead of just the Stats object
5
6379.6.3 by Jelmer Vernooij
Use absolute_import.
6
from __future__ import absolute_import
7
2493.2.3 by Ian Clatworthy
changes requested in jameinel's review incorporated
8
import cPickle
9
import os
1185.33.86 by Martin Pool
Add additional module for lsprof.
10
import sys
1553.7.2 by Robey Pointer
add threading support -- each thread created during an lsprof session gets its own profile object, and the Stats objects are attached to a 'threads' member of the final Stats object
11
import thread
12
import threading
1773.4.1 by Martin Pool
Add pyflakes makefile target; fix many warnings
13
from _lsprof import Profiler, profiler_entry
1185.33.86 by Martin Pool
Add additional module for lsprof.
14
5331.1.1 by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded
15
from bzrlib import errors
2805.7.4 by Ian Clatworthy
incorporate feedback from lifeless
16
1185.33.86 by Martin Pool
Add additional module for lsprof.
17
__all__ = ['profile', 'Stats']
18
19
def profile(f, *args, **kwds):
3696.3.5 by Robert Collins
Streamline _walkdirs_utf8 for utf8 file systems, reducing time to traverse a mozilla tree from 1s to .6 seconds. (Robert Collins)
20
    """Run a function profile.
3943.8.1 by Marius Kruger
remove all trailing whitespace from bzr source
21
4084.6.1 by Robert Collins
Refactor profiling exception handling to restore clear layers - command handling in commands.py, profiling in lsprof.py.
22
    Exceptions are not caught: If you need stats even when exceptions are to be
4641.3.2 by Robert Collins
lsprof support.
23
    raised, pass in a closure that will catch the exceptions and transform them
24
    appropriately for your driver function.
4084.6.1 by Robert Collins
Refactor profiling exception handling to restore clear layers - command handling in commands.py, profiling in lsprof.py.
25
5331.1.1 by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded
26
    Important caveat: only one profile can execute at a time. See BzrProfiler
27
    for details.
28
3696.3.5 by Robert Collins
Streamline _walkdirs_utf8 for utf8 file systems, reducing time to traverse a mozilla tree from 1s to .6 seconds. (Robert Collins)
29
    :return: The functions return value and a stats object.
30
    """
4641.3.2 by Robert Collins
lsprof support.
31
    profiler = BzrProfiler()
32
    profiler.start()
1185.33.86 by Martin Pool
Add additional module for lsprof.
33
    try:
4084.6.1 by Robert Collins
Refactor profiling exception handling to restore clear layers - command handling in commands.py, profiling in lsprof.py.
34
        ret = f(*args, **kwds)
1185.33.86 by Martin Pool
Add additional module for lsprof.
35
    finally:
4641.3.2 by Robert Collins
lsprof support.
36
        stats = profiler.stop()
37
    return ret, stats
38
39
40
class BzrProfiler(object):
41
    """Bzr utility wrapper around Profiler.
42
    
43
    For most uses the module level 'profile()' function will be suitable.
44
    However profiling when a simple wrapped function isn't available may
45
    be easier to accomplish using this class.
46
47
    To use it, create a BzrProfiler and call start() on it. Some arbitrary
48
    time later call stop() to stop profiling and retrieve the statistics
49
    from the code executed in the interim.
5331.1.1 by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded
50
51
    Note that profiling involves a threading.Lock around the actual profiling.
52
    This is needed because profiling involves global manipulation of the python
53
    interpreter state. As such you cannot perform multiple profiles at once.
54
    Trying to do so will lock out the second profiler unless the global 
55
    bzrlib.lsprof.BzrProfiler.profiler_block is set to 0. Setting it to 0 will
56
    cause profiling to fail rather than blocking.
4641.3.2 by Robert Collins
lsprof support.
57
    """
58
5331.1.1 by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded
59
    profiler_block = 1
60
    """Serialise rather than failing to profile concurrent profile requests."""
61
62
    profiler_lock = threading.Lock()
63
    """Global lock used to serialise profiles."""
64
4641.3.2 by Robert Collins
lsprof support.
65
    def start(self):
66
        """Start profiling.
67
        
68
        This hooks into threading and will record all calls made until
69
        stop() is called.
70
        """
71
        self._g_threadmap = {}
72
        self.p = Profiler()
5331.1.1 by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded
73
        permitted = self.__class__.profiler_lock.acquire(
74
            self.__class__.profiler_block)
75
        if not permitted:
76
            raise errors.InternalBzrError(msg="Already profiling something")
77
        try:
78
            self.p.enable(subcalls=True)
79
            threading.setprofile(self._thread_profile)
80
        except:
81
            self.__class__.profiler_lock.release()
82
            raise
4641.3.2 by Robert Collins
lsprof support.
83
84
    def stop(self):
85
        """Stop profiling.
86
87
        This unhooks from threading and cleans up the profiler, returning
88
        the gathered Stats object.
89
90
        :return: A bzrlib.lsprof.Stats object.
91
        """
5331.1.1 by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded
92
        try:
93
            self.p.disable()
94
            for pp in self._g_threadmap.values():
95
                pp.disable()
96
            threading.setprofile(None)
97
            p = self.p
98
            self.p = None
99
            threads = {}
100
            for tid, pp in self._g_threadmap.items():
101
                threads[tid] = Stats(pp.getstats(), {})
102
            self._g_threadmap = None
103
            return Stats(p.getstats(), threads)
104
        finally:
105
            self.__class__.profiler_lock.release()
3943.8.1 by Marius Kruger
remove all trailing whitespace from bzr source
106
4641.3.2 by Robert Collins
lsprof support.
107
    def _thread_profile(self, f, *args, **kwds):
108
        # we lose the first profile point for a new thread in order to
109
        # trampoline a new Profile object into place
110
        thr = thread.get_ident()
111
        self._g_threadmap[thr] = p = Profiler()
112
        # this overrides our sys.setprofile hook:
113
        p.enable(subcalls=True, builtins=True)
1185.33.86 by Martin Pool
Add additional module for lsprof.
114
115
116
class Stats(object):
5432.2.1 by John C Barstow
Provide missing docstrings for bzrlib.lsprof
117
    """Wrapper around the collected data.
118
119
    A Stats instance is created when the profiler finishes. Normal
120
    usage is to use save() to write out the data to a file, or pprint()
121
    to write human-readable information to the command line.
122
    """
1185.33.86 by Martin Pool
Add additional module for lsprof.
123
1553.7.2 by Robey Pointer
add threading support -- each thread created during an lsprof session gets its own profile object, and the Stats objects are attached to a 'threads' member of the final Stats object
124
    def __init__(self, data, threads):
1185.33.86 by Martin Pool
Add additional module for lsprof.
125
        self.data = data
1553.7.2 by Robey Pointer
add threading support -- each thread created during an lsprof session gets its own profile object, and the Stats objects are attached to a 'threads' member of the final Stats object
126
        self.threads = threads
1185.33.86 by Martin Pool
Add additional module for lsprof.
127
128
    def sort(self, crit="inlinetime"):
5432.2.1 by John C Barstow
Provide missing docstrings for bzrlib.lsprof
129
        """Sort the data by the supplied critera.
130
131
        :param crit: the data attribute used as the sort key."""
1185.33.86 by Martin Pool
Add additional module for lsprof.
132
        if crit not in profiler_entry.__dict__:
133
            raise ValueError, "Can't sort by %s" % crit
134
        self.data.sort(lambda b, a: cmp(getattr(a, crit),
135
                                        getattr(b, crit)))
136
        for e in self.data:
137
            if e.calls:
138
                e.calls.sort(lambda b, a: cmp(getattr(a, crit),
139
                                              getattr(b, crit)))
140
141
    def pprint(self, top=None, file=None):
5432.2.1 by John C Barstow
Provide missing docstrings for bzrlib.lsprof
142
        """Pretty-print the data as plain text for human consumption.
143
144
        :param top: only output the top n entries.
145
            The default value of None means output all data.
146
        :param file: the output file; if None, output will
147
            default to stdout."""
1185.33.86 by Martin Pool
Add additional module for lsprof.
148
        if file is None:
149
            file = sys.stdout
150
        d = self.data
151
        if top is not None:
152
            d = d[:top]
153
        cols = "% 12s %12s %11.4f %11.4f   %s\n"
154
        hcols = "% 12s %12s %12s %12s %s\n"
155
        cols2 = "+%12s %12s %11.4f %11.4f +  %s\n"
156
        file.write(hcols % ("CallCount", "Recursive", "Total(ms)",
157
                            "Inline(ms)", "module:lineno(function)"))
158
        for e in d:
159
            file.write(cols % (e.callcount, e.reccallcount, e.totaltime,
160
                               e.inlinetime, label(e.code)))
161
            if e.calls:
162
                for se in e.calls:
163
                    file.write(cols % ("+%s" % se.callcount, se.reccallcount,
164
                                       se.totaltime, se.inlinetime,
165
                                       "+%s" % label(se.code)))
166
167
    def freeze(self):
168
        """Replace all references to code objects with string
169
        descriptions; this makes it possible to pickle the instance."""
170
171
        # this code is probably rather ickier than it needs to be!
172
        for i in range(len(self.data)):
173
            e = self.data[i]
174
            if not isinstance(e.code, str):
175
                self.data[i] = type(e)((label(e.code),) + e[1:])
1706.2.7 by Robey Pointer
pull over some changes from the original lsprof
176
            if e.calls:
177
                for j in range(len(e.calls)):
178
                    se = e.calls[j]
179
                    if not isinstance(se.code, str):
180
                        e.calls[j] = type(se)((label(se.code),) + se[1:])
1553.7.2 by Robey Pointer
add threading support -- each thread created during an lsprof session gets its own profile object, and the Stats objects are attached to a 'threads' member of the final Stats object
181
        for s in self.threads.values():
182
            s.freeze()
183
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
184
    def calltree(self, file):
185
        """Output profiling data in calltree format (for KCacheGrind)."""
186
        _CallTreeFilter(self.data).output(file)
187
2493.2.3 by Ian Clatworthy
changes requested in jameinel's review incorporated
188
    def save(self, filename, format=None):
189
        """Save profiling data to a file.
190
191
        :param filename: the name of the output file
192
        :param format: 'txt' for a text representation;
193
            'callgrind' for calltree format;
194
            otherwise a pickled Python object. A format of None indicates
2654.2.2 by Ian Clatworthy
Put all format detection stuff in one spot as requested by John Arbash Meinel
195
            that the format to use is to be found from the filename. If
196
            the name starts with callgrind.out, callgrind format is used
197
            otherwise the format is given by the filename extension.
2493.2.3 by Ian Clatworthy
changes requested in jameinel's review incorporated
198
        """
199
        if format is None:
3535.5.1 by John Arbash Meinel
cleanup a few imports to be lazily loaded.
200
            basename = os.path.basename(filename)
2805.7.2 by Ian Clatworthy
use basename, not full path, when checking for callgrind.out file prefix
201
            if basename.startswith('callgrind.out'):
2654.2.2 by Ian Clatworthy
Put all format detection stuff in one spot as requested by John Arbash Meinel
202
                format = "callgrind"
203
            else:
3535.5.1 by John Arbash Meinel
cleanup a few imports to be lazily loaded.
204
                ext = os.path.splitext(filename)[1]
2654.2.2 by Ian Clatworthy
Put all format detection stuff in one spot as requested by John Arbash Meinel
205
                if len(ext) > 1:
206
                    format = ext[1:]
2493.2.3 by Ian Clatworthy
changes requested in jameinel's review incorporated
207
        outfile = open(filename, 'wb')
208
        try:
209
            if format == "callgrind":
210
                self.calltree(outfile)
211
            elif format == "txt":
212
                self.pprint(file=outfile)
213
            else:
214
                self.freeze()
215
                cPickle.dump(self, outfile, 2)
216
        finally:
217
            outfile.close()
218
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
219
220
class _CallTreeFilter(object):
2493.2.2 by Ian Clatworthy
Incorporate feedback from Robert Collins
221
    """Converter of a Stats object to input suitable for KCacheGrind.
222
223
    This code is taken from http://ddaa.net/blog/python/lsprof-calltree
224
    with the changes made by J.P. Calderone and Itamar applied. Note that
3943.8.1 by Marius Kruger
remove all trailing whitespace from bzr source
225
    isinstance(code, str) needs to be used at times to determine if the code
2493.2.2 by Ian Clatworthy
Incorporate feedback from Robert Collins
226
    object is actually an external code object (with a filename, etc.) or
227
    a Python built-in.
228
    """
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
229
230
    def __init__(self, data):
231
        self.data = data
232
        self.out_file = None
233
234
    def output(self, out_file):
3943.8.1 by Marius Kruger
remove all trailing whitespace from bzr source
235
        self.out_file = out_file
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
236
        out_file.write('events: Ticks\n')
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
237
        self._print_summary()
238
        for entry in self.data:
239
            self._entry(entry)
240
241
    def _print_summary(self):
242
        max_cost = 0
243
        for entry in self.data:
244
            totaltime = int(entry.totaltime * 1000)
245
            max_cost = max(max_cost, totaltime)
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
246
        self.out_file.write('summary: %d\n' % (max_cost,))
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
247
248
    def _entry(self, entry):
249
        out_file = self.out_file
250
        code = entry.code
251
        inlinetime = int(entry.inlinetime * 1000)
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
252
        #out_file.write('ob=%s\n' % (code.co_filename,))
253
        if isinstance(code, str):
254
            out_file.write('fi=~\n')
255
        else:
256
            out_file.write('fi=%s\n' % (code.co_filename,))
257
        out_file.write('fn=%s\n' % (label(code, True),))
258
        if isinstance(code, str):
2911.6.4 by Blake Winton
Fix test failures
259
            out_file.write('0  %s\n' % (inlinetime,))
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
260
        else:
261
            out_file.write('%d %d\n' % (code.co_firstlineno, inlinetime))
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
262
        # recursive calls are counted in entry.calls
263
        if entry.calls:
264
            calls = entry.calls
265
        else:
266
            calls = []
2493.2.1 by Ian Clatworthy
make profiling information easier to view and better documented
267
        if isinstance(code, str):
268
            lineno = 0
269
        else:
270
            lineno = code.co_firstlineno
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
271
        for subentry in calls:
2493.2.1 by Ian Clatworthy
make profiling information easier to view and better documented
272
            self._subentry(lineno, subentry)
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
273
        out_file.write('\n')
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
274
275
    def _subentry(self, lineno, subentry):
276
        out_file = self.out_file
277
        code = subentry.code
278
        totaltime = int(subentry.totaltime * 1000)
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
279
        #out_file.write('cob=%s\n' % (code.co_filename,))
2493.2.1 by Ian Clatworthy
make profiling information easier to view and better documented
280
        if isinstance(code, str):
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
281
            out_file.write('cfi=~\n')
5783.1.1 by John Arbash Meinel
Fix bug #758695, correctly order the 'cfn' vs 'cfi' in callgrind output.
282
            out_file.write('cfn=%s\n' % (label(code, True),))
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
283
            out_file.write('calls=%d 0\n' % (subentry.callcount,))
2493.2.1 by Ian Clatworthy
make profiling information easier to view and better documented
284
        else:
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
285
            out_file.write('cfi=%s\n' % (code.co_filename,))
5783.1.1 by John Arbash Meinel
Fix bug #758695, correctly order the 'cfn' vs 'cfi' in callgrind output.
286
            out_file.write('cfn=%s\n' % (label(code, True),))
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
287
            out_file.write('calls=%d %d\n' % (
288
                subentry.callcount, code.co_firstlineno))
289
        out_file.write('%d %d\n' % (lineno, totaltime))
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
290
1185.33.86 by Martin Pool
Add additional module for lsprof.
291
_fn2mod = {}
292
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
293
def label(code, calltree=False):
1185.33.86 by Martin Pool
Add additional module for lsprof.
294
    if isinstance(code, str):
295
        return code
296
    try:
297
        mname = _fn2mod[code.co_filename]
298
    except KeyError:
1711.2.124 by John Arbash Meinel
Use sys.modules.items() to prevent running into site.py problems
299
        for k, v in sys.modules.items():
1185.33.86 by Martin Pool
Add additional module for lsprof.
300
            if v is None:
301
                continue
1963.2.6 by Robey Pointer
pychecker is on crack; go back to using 'is None'.
302
            if getattr(v, '__file__', None) is None:
1185.33.86 by Martin Pool
Add additional module for lsprof.
303
                continue
304
            if not isinstance(v.__file__, str):
305
                continue
306
            if v.__file__.startswith(code.co_filename):
307
                mname = _fn2mod[code.co_filename] = k
308
                break
309
        else:
310
            mname = _fn2mod[code.co_filename] = '<%s>'%code.co_filename
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
311
    if calltree:
312
        return '%s %s:%d' % (code.co_name, mname, code.co_firstlineno)
313
    else:
314
        return '%s:%d(%s)' % (mname, code.co_firstlineno, code.co_name)
1185.33.86 by Martin Pool
Add additional module for lsprof.
315
316
317
if __name__ == '__main__':
318
    import os
319
    sys.argv = sys.argv[1:]
320
    if not sys.argv:
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
321
        sys.stderr.write("usage: lsprof.py <script> <arguments...>\n")
1185.33.86 by Martin Pool
Add additional module for lsprof.
322
        sys.exit(2)
323
    sys.path.insert(0, os.path.abspath(os.path.dirname(sys.argv[0])))
324
    stats = profile(execfile, sys.argv[0], globals(), locals())
325
    stats.sort()
326
    stats.pprint()