← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/lsprof.py

  • Committer: Martin Pool
  • Date: 2010-09-03 09:14:12 UTC
  • mto: This revision was merged to the branch mainline in revision 5417.
  • Revision ID: mbp@sourcefrog.net-20100903091412-1a40klgfg8c6k3xj
Split out user interaction developer guide to a separate file

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/lsprof.py
 
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
 
 
6
import cPickle
 
7
import os
 
8
import sys
 
9
import thread
 
10
import threading
 
11
from _lsprof import Profiler, profiler_entry
 
12
 
 
13
from bzrlib import errors
 
14
 
 
15
__all__ = ['profile', 'Stats']
 
16
 
 
17
def profile(f, *args, **kwds):
 
18
    """Run a function profile.
 
19
 
 
20
    Exceptions are not caught: If you need stats even when exceptions are to be
 
21
    raised, pass in a closure that will catch the exceptions and transform them
 
22
    appropriately for your driver function.
 
23
 
 
24
    Important caveat: only one profile can execute at a time. See BzrProfiler
 
25
    for details.
 
26
 
 
27
    :return: The functions return value and a stats object.
 
28
    """
 
29
    profiler = BzrProfiler()
 
30
    profiler.start()
 
31
    try:
 
32
        ret = f(*args, **kwds)
 
33
    finally:
 
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.
 
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.
 
55
    """
 
56
 
 
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
 
 
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()
 
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
 
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
        """
 
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()
 
104
 
 
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)
 
112
 
 
113
 
 
114
class Stats(object):
 
115
    """XXX docstring"""
 
116
 
 
117
    def __init__(self, data, threads):
 
118
        self.data = data
 
119
        self.threads = threads
 
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:])
 
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:])
 
167
        for s in self.threads.values():
 
168
            s.freeze()
 
169
 
 
170
    def calltree(self, file):
 
171
        """Output profiling data in calltree format (for KCacheGrind)."""
 
172
        _CallTreeFilter(self.data).output(file)
 
173
 
 
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
 
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.
 
184
        """
 
185
        if format is None:
 
186
            basename = os.path.basename(filename)
 
187
            if basename.startswith('callgrind.out'):
 
188
                format = "callgrind"
 
189
            else:
 
190
                ext = os.path.splitext(filename)[1]
 
191
                if len(ext) > 1:
 
192
                    format = ext[1:]
 
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
 
 
205
 
 
206
class _CallTreeFilter(object):
 
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
 
211
    isinstance(code, str) needs to be used at times to determine if the code
 
212
    object is actually an external code object (with a filename, etc.) or
 
213
    a Python built-in.
 
214
    """
 
215
 
 
216
    def __init__(self, data):
 
217
        self.data = data
 
218
        self.out_file = None
 
219
 
 
220
    def output(self, out_file):
 
221
        self.out_file = out_file
 
222
        out_file.write('events: Ticks\n')
 
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)
 
232
        self.out_file.write('summary: %d\n' % (max_cost,))
 
233
 
 
234
    def _entry(self, entry):
 
235
        out_file = self.out_file
 
236
        code = entry.code
 
237
        inlinetime = int(entry.inlinetime * 1000)
 
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):
 
245
            out_file.write('0  %s\n' % (inlinetime,))
 
246
        else:
 
247
            out_file.write('%d %d\n' % (code.co_firstlineno, inlinetime))
 
248
        # recursive calls are counted in entry.calls
 
249
        if entry.calls:
 
250
            calls = entry.calls
 
251
        else:
 
252
            calls = []
 
253
        if isinstance(code, str):
 
254
            lineno = 0
 
255
        else:
 
256
            lineno = code.co_firstlineno
 
257
        for subentry in calls:
 
258
            self._subentry(lineno, subentry)
 
259
        out_file.write('\n')
 
260
 
 
261
    def _subentry(self, lineno, subentry):
 
262
        out_file = self.out_file
 
263
        code = subentry.code
 
264
        totaltime = int(subentry.totaltime * 1000)
 
265
        #out_file.write('cob=%s\n' % (code.co_filename,))
 
266
        out_file.write('cfn=%s\n' % (label(code, True),))
 
267
        if isinstance(code, str):
 
268
            out_file.write('cfi=~\n')
 
269
            out_file.write('calls=%d 0\n' % (subentry.callcount,))
 
270
        else:
 
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))
 
275
 
 
276
_fn2mod = {}
 
277
 
 
278
def label(code, calltree=False):
 
279
    if isinstance(code, str):
 
280
        return code
 
281
    try:
 
282
        mname = _fn2mod[code.co_filename]
 
283
    except KeyError:
 
284
        for k, v in sys.modules.items():
 
285
            if v is None:
 
286
                continue
 
287
            if getattr(v, '__file__', None) is None:
 
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
 
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)
 
300
 
 
301
 
 
302
if __name__ == '__main__':
 
303
    import os
 
304
    sys.argv = sys.argv[1:]
 
305
    if not sys.argv:
 
306
        sys.stderr.write("usage: lsprof.py <script> <arguments...>\n")
 
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()