← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/lsprof.py

  • Committer: Martin Packman
  • Date: 2011-12-23 19:38:22 UTC
  • mto: This revision was merged to the branch mainline in revision 6405.
  • Revision ID: martin.packman@canonical.com-20111223193822-hesheea4o8aqwexv
Accept and document passing the medium rather than transport for smart connections

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/lsprof.py
10
10
import threading
11
11
from _lsprof import Profiler, profiler_entry
12
12
 
 
13
from bzrlib import errors
 
14
 
13
15
__all__ = ['profile', 'Stats']
14
16
 
15
 
_g_threadmap = {}
16
 
 
17
 
 
18
 
def _thread_profile(f, *args, **kwds):
19
 
    # we lose the first profile point for a new thread in order to trampoline
20
 
    # a new Profile object into place
21
 
    global _g_threadmap
22
 
    thr = thread.get_ident()
23
 
    _g_threadmap[thr] = p = Profiler()
24
 
    # this overrides our sys.setprofile hook:
25
 
    p.enable(subcalls=True, builtins=True)
26
 
 
27
 
 
28
17
def profile(f, *args, **kwds):
29
 
    """XXX docstring"""
30
 
    global _g_threadmap
31
 
    p = Profiler()
32
 
    p.enable(subcalls=True)
33
 
    threading.setprofile(_thread_profile)
 
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()
34
31
    try:
35
32
        ret = f(*args, **kwds)
36
33
    finally:
37
 
        p.disable()
38
 
        for pp in _g_threadmap.values():
39
 
            pp.disable()
40
 
        threading.setprofile(None)
 
34
        stats = profiler.stop()
 
35
    return ret, stats
 
36
 
 
37
 
 
38
class BzrProfiler(object):
 
39
    """Bzr utility wrapper around Profiler.
41
40
    
42
 
    threads = {}
43
 
    for tid, pp in _g_threadmap.items():
44
 
        threads[tid] = Stats(pp.getstats(), {})
45
 
    _g_threadmap = {}
46
 
    return ret, Stats(p.getstats(), threads)
 
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)
47
112
 
48
113
 
49
114
class Stats(object):
50
 
    """XXX docstring"""
 
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
    """
51
121
 
52
122
    def __init__(self, data, threads):
53
123
        self.data = data
54
124
        self.threads = threads
55
125
 
56
126
    def sort(self, crit="inlinetime"):
57
 
        """XXX docstring"""
 
127
        """Sort the data by the supplied critera.
 
128
 
 
129
        :param crit: the data attribute used as the sort key."""
58
130
        if crit not in profiler_entry.__dict__:
59
131
            raise ValueError, "Can't sort by %s" % crit
60
132
        self.data.sort(lambda b, a: cmp(getattr(a, crit),
65
137
                                              getattr(b, crit)))
66
138
 
67
139
    def pprint(self, top=None, file=None):
68
 
        """XXX docstring"""
 
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."""
69
146
        if file is None:
70
147
            file = sys.stdout
71
148
        d = self.data
113
190
        :param format: 'txt' for a text representation;
114
191
            'callgrind' for calltree format;
115
192
            otherwise a pickled Python object. A format of None indicates
116
 
            that the format to use is to be found from the extension of
117
 
            filename.
 
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.
118
196
        """
119
197
        if format is None:
120
 
            ext = os.path.splitext(filename)[1]
121
 
            if len(ext) > 1:
122
 
                format = ext[1:]
 
198
            basename = os.path.basename(filename)
 
199
            if basename.startswith('callgrind.out'):
 
200
                format = "callgrind"
 
201
            else:
 
202
                ext = os.path.splitext(filename)[1]
 
203
                if len(ext) > 1:
 
204
                    format = ext[1:]
123
205
        outfile = open(filename, 'wb')
124
206
        try:
125
207
            if format == "callgrind":
138
220
 
139
221
    This code is taken from http://ddaa.net/blog/python/lsprof-calltree
140
222
    with the changes made by J.P. Calderone and Itamar applied. Note that
141
 
    isinstance(code, str) needs to be used at times to determine if the code 
 
223
    isinstance(code, str) needs to be used at times to determine if the code
142
224
    object is actually an external code object (with a filename, etc.) or
143
225
    a Python built-in.
144
226
    """
148
230
        self.out_file = None
149
231
 
150
232
    def output(self, out_file):
151
 
        self.out_file = out_file        
152
 
        print >> out_file, 'events: Ticks'
 
233
        self.out_file = out_file
 
234
        out_file.write('events: Ticks\n')
153
235
        self._print_summary()
154
236
        for entry in self.data:
155
237
            self._entry(entry)
159
241
        for entry in self.data:
160
242
            totaltime = int(entry.totaltime * 1000)
161
243
            max_cost = max(max_cost, totaltime)
162
 
        print >> self.out_file, 'summary: %d' % (max_cost,)
 
244
        self.out_file.write('summary: %d\n' % (max_cost,))
163
245
 
164
246
    def _entry(self, entry):
165
247
        out_file = self.out_file
166
248
        code = entry.code
167
249
        inlinetime = int(entry.inlinetime * 1000)
168
 
        #print >> out_file, 'ob=%s' % (code.co_filename,)
169
 
        if isinstance(code, str):
170
 
            print >> out_file, 'fi=~'
171
 
        else:
172
 
            print >> out_file, 'fi=%s' % (code.co_filename,)
173
 
        print >> out_file, 'fn=%s' % (label(code, True),)
174
 
        if isinstance(code, str):
175
 
            print >> out_file, '0 ', inlinetime
176
 
        else:
177
 
            print >> out_file, '%d %d' % (code.co_firstlineno, inlinetime)
 
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):
 
257
            out_file.write('0  %s\n' % (inlinetime,))
 
258
        else:
 
259
            out_file.write('%d %d\n' % (code.co_firstlineno, inlinetime))
178
260
        # recursive calls are counted in entry.calls
179
261
        if entry.calls:
180
262
            calls = entry.calls
186
268
            lineno = code.co_firstlineno
187
269
        for subentry in calls:
188
270
            self._subentry(lineno, subentry)
189
 
        print >> out_file
 
271
        out_file.write('\n')
190
272
 
191
273
    def _subentry(self, lineno, subentry):
192
274
        out_file = self.out_file
193
275
        code = subentry.code
194
276
        totaltime = int(subentry.totaltime * 1000)
195
 
        #print >> out_file, 'cob=%s' % (code.co_filename,)
196
 
        print >> out_file, 'cfn=%s' % (label(code, True),)
 
277
        #out_file.write('cob=%s\n' % (code.co_filename,))
197
278
        if isinstance(code, str):
198
 
            print >> out_file, 'cfi=~'
199
 
            print >> out_file, 'calls=%d 0' % (subentry.callcount,)
 
279
            out_file.write('cfi=~\n')
 
280
            out_file.write('cfn=%s\n' % (label(code, True),))
 
281
            out_file.write('calls=%d 0\n' % (subentry.callcount,))
200
282
        else:
201
 
            print >> out_file, 'cfi=%s' % (code.co_filename,)
202
 
            print >> out_file, 'calls=%d %d' % (
203
 
                subentry.callcount, code.co_firstlineno)
204
 
        print >> out_file, '%d %d' % (lineno, totaltime)
 
283
            out_file.write('cfi=%s\n' % (code.co_filename,))
 
284
            out_file.write('cfn=%s\n' % (label(code, True),))
 
285
            out_file.write('calls=%d %d\n' % (
 
286
                subentry.callcount, code.co_firstlineno))
 
287
        out_file.write('%d %d\n' % (lineno, totaltime))
205
288
 
206
289
_fn2mod = {}
207
290
 
233
316
    import os
234
317
    sys.argv = sys.argv[1:]
235
318
    if not sys.argv:
236
 
        print >> sys.stderr, "usage: lsprof.py <script> <arguments...>"
 
319
        sys.stderr.write("usage: lsprof.py <script> <arguments...>\n")
237
320
        sys.exit(2)
238
321
    sys.path.insert(0, os.path.abspath(os.path.dirname(sys.argv[0])))
239
322
    stats = profile(execfile, sys.argv[0], globals(), locals())