~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):
115
    """XXX docstring"""
116
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
117
    def __init__(self, data, threads):
1185.33.86 by Martin Pool
Add additional module for lsprof.
118
        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
119
        self.threads = threads
1185.33.86 by Martin Pool
Add additional module for lsprof.
120
121
    def sort(self, crit="inlinetime"):
122
        """XXX docstring"""
123
        if crit not in profiler_entry.__dict__:
124
            raise ValueError, "Can't sort by %s" % crit
125
        self.data.sort(lambda b, a: cmp(getattr(a, crit),
126
                                        getattr(b, crit)))
127
        for e in self.data:
128
            if e.calls:
129
                e.calls.sort(lambda b, a: cmp(getattr(a, crit),
130
                                              getattr(b, crit)))
131
132
    def pprint(self, top=None, file=None):
133
        """XXX docstring"""
134
        if file is None:
135
            file = sys.stdout
136
        d = self.data
137
        if top is not None:
138
            d = d[:top]
139
        cols = "% 12s %12s %11.4f %11.4f   %s\n"
140
        hcols = "% 12s %12s %12s %12s %s\n"
141
        cols2 = "+%12s %12s %11.4f %11.4f +  %s\n"
142
        file.write(hcols % ("CallCount", "Recursive", "Total(ms)",
143
                            "Inline(ms)", "module:lineno(function)"))
144
        for e in d:
145
            file.write(cols % (e.callcount, e.reccallcount, e.totaltime,
146
                               e.inlinetime, label(e.code)))
147
            if e.calls:
148
                for se in e.calls:
149
                    file.write(cols % ("+%s" % se.callcount, se.reccallcount,
150
                                       se.totaltime, se.inlinetime,
151
                                       "+%s" % label(se.code)))
152
153
    def freeze(self):
154
        """Replace all references to code objects with string
155
        descriptions; this makes it possible to pickle the instance."""
156
157
        # this code is probably rather ickier than it needs to be!
158
        for i in range(len(self.data)):
159
            e = self.data[i]
160
            if not isinstance(e.code, str):
161
                self.data[i] = type(e)((label(e.code),) + e[1:])
1706.2.7 by Robey Pointer
pull over some changes from the original lsprof
162
            if e.calls:
163
                for j in range(len(e.calls)):
164
                    se = e.calls[j]
165
                    if not isinstance(se.code, str):
166
                        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
167
        for s in self.threads.values():
168
            s.freeze()
169
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
170
    def calltree(self, file):
171
        """Output profiling data in calltree format (for KCacheGrind)."""
172
        _CallTreeFilter(self.data).output(file)
173
2493.2.3 by Ian Clatworthy
changes requested in jameinel's review incorporated
174
    def save(self, filename, format=None):
175
        """Save profiling data to a file.
176
177
        :param filename: the name of the output file
178
        :param format: 'txt' for a text representation;
179
            'callgrind' for calltree format;
180
            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
181
            that the format to use is to be found from the filename. If
182
            the name starts with callgrind.out, callgrind format is used
183
            otherwise the format is given by the filename extension.
2493.2.3 by Ian Clatworthy
changes requested in jameinel's review incorporated
184
        """
185
        if format is None:
3535.5.1 by John Arbash Meinel
cleanup a few imports to be lazily loaded.
186
            basename = os.path.basename(filename)
2805.7.2 by Ian Clatworthy
use basename, not full path, when checking for callgrind.out file prefix
187
            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
188
                format = "callgrind"
189
            else:
3535.5.1 by John Arbash Meinel
cleanup a few imports to be lazily loaded.
190
                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
191
                if len(ext) > 1:
192
                    format = ext[1:]
2493.2.3 by Ian Clatworthy
changes requested in jameinel's review incorporated
193
        outfile = open(filename, 'wb')
194
        try:
195
            if format == "callgrind":
196
                self.calltree(outfile)
197
            elif format == "txt":
198
                self.pprint(file=outfile)
199
            else:
200
                self.freeze()
201
                cPickle.dump(self, outfile, 2)
202
        finally:
203
            outfile.close()
204
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
205
206
class _CallTreeFilter(object):
2493.2.2 by Ian Clatworthy
Incorporate feedback from Robert Collins
207
    """Converter of a Stats object to input suitable for KCacheGrind.
208
209
    This code is taken from http://ddaa.net/blog/python/lsprof-calltree
210
    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
211
    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
212
    object is actually an external code object (with a filename, etc.) or
213
    a Python built-in.
214
    """
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
215
216
    def __init__(self, data):
217
        self.data = data
218
        self.out_file = None
219
220
    def output(self, out_file):
3943.8.1 by Marius Kruger
remove all trailing whitespace from bzr source
221
        self.out_file = out_file
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
222
        out_file.write('events: Ticks\n')
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
223
        self._print_summary()
224
        for entry in self.data:
225
            self._entry(entry)
226
227
    def _print_summary(self):
228
        max_cost = 0
229
        for entry in self.data:
230
            totaltime = int(entry.totaltime * 1000)
231
            max_cost = max(max_cost, totaltime)
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
232
        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
233
234
    def _entry(self, entry):
235
        out_file = self.out_file
236
        code = entry.code
237
        inlinetime = int(entry.inlinetime * 1000)
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
238
        #out_file.write('ob=%s\n' % (code.co_filename,))
239
        if isinstance(code, str):
240
            out_file.write('fi=~\n')
241
        else:
242
            out_file.write('fi=%s\n' % (code.co_filename,))
243
        out_file.write('fn=%s\n' % (label(code, True),))
244
        if isinstance(code, str):
2911.6.4 by Blake Winton
Fix test failures
245
            out_file.write('0  %s\n' % (inlinetime,))
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
246
        else:
247
            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
248
        # recursive calls are counted in entry.calls
249
        if entry.calls:
250
            calls = entry.calls
251
        else:
252
            calls = []
2493.2.1 by Ian Clatworthy
make profiling information easier to view and better documented
253
        if isinstance(code, str):
254
            lineno = 0
255
        else:
256
            lineno = code.co_firstlineno
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
257
        for subentry in calls:
2493.2.1 by Ian Clatworthy
make profiling information easier to view and better documented
258
            self._subentry(lineno, subentry)
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
259
        out_file.write('\n')
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
260
261
    def _subentry(self, lineno, subentry):
262
        out_file = self.out_file
263
        code = subentry.code
264
        totaltime = int(subentry.totaltime * 1000)
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
265
        #out_file.write('cob=%s\n' % (code.co_filename,))
266
        out_file.write('cfn=%s\n' % (label(code, True),))
2493.2.1 by Ian Clatworthy
make profiling information easier to view and better documented
267
        if isinstance(code, str):
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
268
            out_file.write('cfi=~\n')
269
            out_file.write('calls=%d 0\n' % (subentry.callcount,))
2493.2.1 by Ian Clatworthy
make profiling information easier to view and better documented
270
        else:
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
271
            out_file.write('cfi=%s\n' % (code.co_filename,))
272
            out_file.write('calls=%d %d\n' % (
273
                subentry.callcount, code.co_firstlineno))
274
        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
275
1185.33.86 by Martin Pool
Add additional module for lsprof.
276
_fn2mod = {}
277
1553.7.3 by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof
278
def label(code, calltree=False):
1185.33.86 by Martin Pool
Add additional module for lsprof.
279
    if isinstance(code, str):
280
        return code
281
    try:
282
        mname = _fn2mod[code.co_filename]
283
    except KeyError:
1711.2.124 by John Arbash Meinel
Use sys.modules.items() to prevent running into site.py problems
284
        for k, v in sys.modules.items():
1185.33.86 by Martin Pool
Add additional module for lsprof.
285
            if v is None:
286
                continue
1963.2.6 by Robey Pointer
pychecker is on crack; go back to using 'is None'.
287
            if getattr(v, '__file__', None) is None:
1185.33.86 by Martin Pool
Add additional module for lsprof.
288
                continue
289
            if not isinstance(v.__file__, str):
290
                continue
291
            if v.__file__.startswith(code.co_filename):
292
                mname = _fn2mod[code.co_filename] = k
293
                break
294
        else:
295
            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
296
    if calltree:
297
        return '%s %s:%d' % (code.co_name, mname, code.co_firstlineno)
298
    else:
299
        return '%s:%d(%s)' % (mname, code.co_firstlineno, code.co_name)
1185.33.86 by Martin Pool
Add additional module for lsprof.
300
301
302
if __name__ == '__main__':
303
    import os
304
    sys.argv = sys.argv[1:]
305
    if not sys.argv:
2911.6.1 by Blake Winton
Change 'print >> f,'s to 'f.write('s.
306
        sys.stderr.write("usage: lsprof.py <script> <arguments...>\n")
1185.33.86 by Martin Pool
Add additional module for lsprof.
307
        sys.exit(2)
308
    sys.path.insert(0, os.path.abspath(os.path.dirname(sys.argv[0])))
309
    stats = profile(execfile, sys.argv[0], globals(), locals())
310
    stats.sort()
311
    stats.pprint()