11
11
from _lsprof import Profiler, profiler_entry
14
17
__all__ = ['profile', 'Stats']
22
def _thread_profile(f, *args, **kwds):
23
# we lose the first profile point for a new thread in order to trampoline
24
# a new Profile object into place
26
thr = thread.get_ident()
27
_g_threadmap[thr] = p = Profiler()
28
# this overrides our sys.setprofile hook:
29
p.enable(subcalls=True, builtins=True)
16
32
def profile(f, *args, **kwds):
17
"""Run a function profile.
19
Exceptions are not caught: If you need stats even when exceptions are to be
20
raised, pass in a closure that will catch the exceptions and transform them
21
appropriately for your driver function.
23
:return: The functions return value and a stats object.
25
profiler = BzrProfiler()
36
p.enable(subcalls=True)
37
threading.setprofile(_thread_profile)
38
# Note: The except clause is needed below so that profiling data still
39
# gets dumped even when exceptions are encountered. The except clause code
40
# is taken straight from run_bzr_catch_errrors() in commands.py and ought
41
# to be kept in sync with it.
28
ret = f(*args, **kwds)
44
ret = f(*args, **kwds)
45
except (KeyboardInterrupt, Exception), e:
47
bzrlib.trace.report_exception(sys.exc_info(), sys.stderr)
30
stats = profiler.stop()
34
class BzrProfiler(object):
35
"""Bzr utility wrapper around Profiler.
37
For most uses the module level 'profile()' function will be suitable.
38
However profiling when a simple wrapped function isn't available may
39
be easier to accomplish using this class.
41
To use it, create a BzrProfiler and call start() on it. Some arbitrary
42
time later call stop() to stop profiling and retrieve the statistics
43
from the code executed in the interim.
49
This hooks into threading and will record all calls made until
52
self._g_threadmap = {}
54
self.p.enable(subcalls=True)
55
threading.setprofile(self._thread_profile)
60
This unhooks from threading and cleans up the profiler, returning
61
the gathered Stats object.
63
:return: A bzrlib.lsprof.Stats object.
66
for pp in self._g_threadmap.values():
51
for pp in _g_threadmap.values():
68
53
threading.setprofile(None)
72
for tid, pp in self._g_threadmap.items():
73
threads[tid] = Stats(pp.getstats(), {})
74
self._g_threadmap = None
75
return Stats(p.getstats(), threads)
77
def _thread_profile(self, f, *args, **kwds):
78
# we lose the first profile point for a new thread in order to
79
# trampoline a new Profile object into place
80
thr = thread.get_ident()
81
self._g_threadmap[thr] = p = Profiler()
82
# this overrides our sys.setprofile hook:
83
p.enable(subcalls=True, builtins=True)
56
for tid, pp in _g_threadmap.items():
57
threads[tid] = Stats(pp.getstats(), {})
59
return ret, Stats(p.getstats(), threads)
86
62
class Stats(object):
201
177
for entry in self.data:
202
178
totaltime = int(entry.totaltime * 1000)
203
179
max_cost = max(max_cost, totaltime)
204
self.out_file.write('summary: %d\n' % (max_cost,))
180
print >> self.out_file, 'summary: %d' % (max_cost,)
206
182
def _entry(self, entry):
207
183
out_file = self.out_file
208
184
code = entry.code
209
185
inlinetime = int(entry.inlinetime * 1000)
210
#out_file.write('ob=%s\n' % (code.co_filename,))
211
if isinstance(code, str):
212
out_file.write('fi=~\n')
214
out_file.write('fi=%s\n' % (code.co_filename,))
215
out_file.write('fn=%s\n' % (label(code, True),))
216
if isinstance(code, str):
217
out_file.write('0 %s\n' % (inlinetime,))
219
out_file.write('%d %d\n' % (code.co_firstlineno, inlinetime))
186
#print >> out_file, 'ob=%s' % (code.co_filename,)
187
if isinstance(code, str):
188
print >> out_file, 'fi=~'
190
print >> out_file, 'fi=%s' % (code.co_filename,)
191
print >> out_file, 'fn=%s' % (label(code, True),)
192
if isinstance(code, str):
193
print >> out_file, '0 ', inlinetime
195
print >> out_file, '%d %d' % (code.co_firstlineno, inlinetime)
220
196
# recursive calls are counted in entry.calls
222
198
calls = entry.calls
228
204
lineno = code.co_firstlineno
229
205
for subentry in calls:
230
206
self._subentry(lineno, subentry)
233
209
def _subentry(self, lineno, subentry):
234
210
out_file = self.out_file
235
211
code = subentry.code
236
212
totaltime = int(subentry.totaltime * 1000)
237
#out_file.write('cob=%s\n' % (code.co_filename,))
238
out_file.write('cfn=%s\n' % (label(code, True),))
213
#print >> out_file, 'cob=%s' % (code.co_filename,)
214
print >> out_file, 'cfn=%s' % (label(code, True),)
239
215
if isinstance(code, str):
240
out_file.write('cfi=~\n')
241
out_file.write('calls=%d 0\n' % (subentry.callcount,))
216
print >> out_file, 'cfi=~'
217
print >> out_file, 'calls=%d 0' % (subentry.callcount,)
243
out_file.write('cfi=%s\n' % (code.co_filename,))
244
out_file.write('calls=%d %d\n' % (
245
subentry.callcount, code.co_firstlineno))
246
out_file.write('%d %d\n' % (lineno, totaltime))
219
print >> out_file, 'cfi=%s' % (code.co_filename,)
220
print >> out_file, 'calls=%d %d' % (
221
subentry.callcount, code.co_firstlineno)
222
print >> out_file, '%d %d' % (lineno, totaltime)