11
11
from _lsprof import Profiler, profiler_entry
13
from bzrlib import errors
15
13
__all__ = ['profile', 'Stats']
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
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)
17
28
def profile(f, *args, **kwds):
18
"""Run a function profile.
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.
24
Important caveat: only one profile can execute at a time. See BzrProfiler
27
:return: The functions return value and a stats object.
29
profiler = BzrProfiler()
32
p.enable(subcalls=True)
33
threading.setprofile(_thread_profile)
32
35
ret = f(*args, **kwds)
34
stats = profiler.stop()
38
class BzrProfiler(object):
39
"""Bzr utility wrapper around Profiler.
38
for pp in _g_threadmap.values():
40
threading.setprofile(None)
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.
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.
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.
58
"""Serialise rather than failing to profile concurrent profile requests."""
60
profiler_lock = threading.Lock()
61
"""Global lock used to serialise profiles."""
66
This hooks into threading and will record all calls made until
69
self._g_threadmap = {}
71
permitted = self.__class__.profiler_lock.acquire(
72
self.__class__.profiler_block)
74
raise errors.InternalBzrError(msg="Already profiling something")
76
self.p.enable(subcalls=True)
77
threading.setprofile(self._thread_profile)
79
self.__class__.profiler_lock.release()
85
This unhooks from threading and cleans up the profiler, returning
86
the gathered Stats object.
88
:return: A bzrlib.lsprof.Stats object.
92
for pp in self._g_threadmap.values():
94
threading.setprofile(None)
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)
103
self.__class__.profiler_lock.release()
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)
43
for tid, pp in _g_threadmap.items():
44
threads[tid] = Stats(pp.getstats(), {})
46
return ret, Stats(p.getstats(), threads)
114
49
class Stats(object):
178
113
:param format: 'txt' for a text representation;
179
114
'callgrind' for calltree format;
180
115
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.
116
that the format to use is to be found from the extension of
185
119
if format is None:
186
basename = os.path.basename(filename)
187
if basename.startswith('callgrind.out'):
190
ext = os.path.splitext(filename)[1]
120
ext = os.path.splitext(filename)[1]
193
123
outfile = open(filename, 'wb')
195
125
if format == "callgrind":
229
159
for entry in self.data:
230
160
totaltime = int(entry.totaltime * 1000)
231
161
max_cost = max(max_cost, totaltime)
232
self.out_file.write('summary: %d\n' % (max_cost,))
162
print >> self.out_file, 'summary: %d' % (max_cost,)
234
164
def _entry(self, entry):
235
165
out_file = self.out_file
236
166
code = entry.code
237
167
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')
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,))
247
out_file.write('%d %d\n' % (code.co_firstlineno, inlinetime))
168
#print >> out_file, 'ob=%s' % (code.co_filename,)
169
if isinstance(code, str):
170
print >> out_file, 'fi=~'
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
177
print >> out_file, '%d %d' % (code.co_firstlineno, inlinetime)
248
178
# recursive calls are counted in entry.calls
250
180
calls = entry.calls
256
186
lineno = code.co_firstlineno
257
187
for subentry in calls:
258
188
self._subentry(lineno, subentry)
261
191
def _subentry(self, lineno, subentry):
262
192
out_file = self.out_file
263
193
code = subentry.code
264
194
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),))
195
#print >> out_file, 'cob=%s' % (code.co_filename,)
196
print >> out_file, 'cfn=%s' % (label(code, True),)
267
197
if isinstance(code, str):
268
out_file.write('cfi=~\n')
269
out_file.write('calls=%d 0\n' % (subentry.callcount,))
198
print >> out_file, 'cfi=~'
199
print >> out_file, 'calls=%d 0' % (subentry.callcount,)
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))
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)