← 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: 2005-09-19 08:02:41 UTC
  • Revision ID: mbp@sourcefrog.net-20050919080241-d9460223db8f7d90
- rename to Revision.parent_ids to avoid confusion with old usage
  where Revision.parents held objects rather than strings\t

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()