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