1185.33.86
by Martin Pool
Add additional module for lsprof. |
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 |
||
6379.6.3
by Jelmer Vernooij
Use absolute_import. |
6 |
from __future__ import absolute_import |
7 |
||
2493.2.3
by Ian Clatworthy
changes requested in jameinel's review incorporated |
8 |
import cPickle |
9 |
import os |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
10 |
import sys |
1553.7.2
by Robey Pointer
add threading support -- each thread created during an lsprof session gets its own profile object, and the Stats objects are attached to a 'threads' member of the final Stats object |
11 |
import thread |
12 |
import threading |
|
1773.4.1
by Martin Pool
Add pyflakes makefile target; fix many warnings |
13 |
from _lsprof import Profiler, profiler_entry |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
14 |
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
15 |
from bzrlib import errors |
2805.7.4
by Ian Clatworthy
incorporate feedback from lifeless |
16 |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
17 |
__all__ = ['profile', 'Stats'] |
18 |
||
19 |
def profile(f, *args, **kwds): |
|
3696.3.5
by Robert Collins
Streamline _walkdirs_utf8 for utf8 file systems, reducing time to traverse a mozilla tree from 1s to .6 seconds. (Robert Collins) |
20 |
"""Run a function profile.
|
3943.8.1
by Marius Kruger
remove all trailing whitespace from bzr source |
21 |
|
4084.6.1
by Robert Collins
Refactor profiling exception handling to restore clear layers - command handling in commands.py, profiling in lsprof.py. |
22 |
Exceptions are not caught: If you need stats even when exceptions are to be
|
4641.3.2
by Robert Collins
lsprof support. |
23 |
raised, pass in a closure that will catch the exceptions and transform them
|
24 |
appropriately for your driver function.
|
|
4084.6.1
by Robert Collins
Refactor profiling exception handling to restore clear layers - command handling in commands.py, profiling in lsprof.py. |
25 |
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
26 |
Important caveat: only one profile can execute at a time. See BzrProfiler
|
27 |
for details.
|
|
28 |
||
3696.3.5
by Robert Collins
Streamline _walkdirs_utf8 for utf8 file systems, reducing time to traverse a mozilla tree from 1s to .6 seconds. (Robert Collins) |
29 |
:return: The functions return value and a stats object.
|
30 |
"""
|
|
4641.3.2
by Robert Collins
lsprof support. |
31 |
profiler = BzrProfiler() |
32 |
profiler.start() |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
33 |
try: |
4084.6.1
by Robert Collins
Refactor profiling exception handling to restore clear layers - command handling in commands.py, profiling in lsprof.py. |
34 |
ret = f(*args, **kwds) |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
35 |
finally: |
4641.3.2
by Robert Collins
lsprof support. |
36 |
stats = profiler.stop() |
37 |
return ret, stats |
|
38 |
||
39 |
||
40 |
class BzrProfiler(object): |
|
41 |
"""Bzr utility wrapper around Profiler.
|
|
42 |
|
|
43 |
For most uses the module level 'profile()' function will be suitable.
|
|
44 |
However profiling when a simple wrapped function isn't available may
|
|
45 |
be easier to accomplish using this class.
|
|
46 |
||
47 |
To use it, create a BzrProfiler and call start() on it. Some arbitrary
|
|
48 |
time later call stop() to stop profiling and retrieve the statistics
|
|
49 |
from the code executed in the interim.
|
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
50 |
|
51 |
Note that profiling involves a threading.Lock around the actual profiling.
|
|
52 |
This is needed because profiling involves global manipulation of the python
|
|
53 |
interpreter state. As such you cannot perform multiple profiles at once.
|
|
54 |
Trying to do so will lock out the second profiler unless the global
|
|
55 |
bzrlib.lsprof.BzrProfiler.profiler_block is set to 0. Setting it to 0 will
|
|
56 |
cause profiling to fail rather than blocking.
|
|
4641.3.2
by Robert Collins
lsprof support. |
57 |
"""
|
58 |
||
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
59 |
profiler_block = 1 |
60 |
"""Serialise rather than failing to profile concurrent profile requests."""
|
|
61 |
||
62 |
profiler_lock = threading.Lock() |
|
63 |
"""Global lock used to serialise profiles."""
|
|
64 |
||
4641.3.2
by Robert Collins
lsprof support. |
65 |
def start(self): |
66 |
"""Start profiling.
|
|
67 |
|
|
68 |
This hooks into threading and will record all calls made until
|
|
69 |
stop() is called.
|
|
70 |
"""
|
|
71 |
self._g_threadmap = {} |
|
72 |
self.p = Profiler() |
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
73 |
permitted = self.__class__.profiler_lock.acquire( |
74 |
self.__class__.profiler_block) |
|
75 |
if not permitted: |
|
76 |
raise errors.InternalBzrError(msg="Already profiling something") |
|
77 |
try: |
|
78 |
self.p.enable(subcalls=True) |
|
79 |
threading.setprofile(self._thread_profile) |
|
80 |
except: |
|
81 |
self.__class__.profiler_lock.release() |
|
82 |
raise
|
|
4641.3.2
by Robert Collins
lsprof support. |
83 |
|
84 |
def stop(self): |
|
85 |
"""Stop profiling.
|
|
86 |
||
87 |
This unhooks from threading and cleans up the profiler, returning
|
|
88 |
the gathered Stats object.
|
|
89 |
||
90 |
:return: A bzrlib.lsprof.Stats object.
|
|
91 |
"""
|
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
92 |
try: |
93 |
self.p.disable() |
|
94 |
for pp in self._g_threadmap.values(): |
|
95 |
pp.disable() |
|
96 |
threading.setprofile(None) |
|
97 |
p = self.p |
|
98 |
self.p = None |
|
99 |
threads = {} |
|
100 |
for tid, pp in self._g_threadmap.items(): |
|
101 |
threads[tid] = Stats(pp.getstats(), {}) |
|
102 |
self._g_threadmap = None |
|
103 |
return Stats(p.getstats(), threads) |
|
104 |
finally: |
|
105 |
self.__class__.profiler_lock.release() |
|
3943.8.1
by Marius Kruger
remove all trailing whitespace from bzr source |
106 |
|
4641.3.2
by Robert Collins
lsprof support. |
107 |
def _thread_profile(self, f, *args, **kwds): |
108 |
# we lose the first profile point for a new thread in order to
|
|
109 |
# trampoline a new Profile object into place
|
|
110 |
thr = thread.get_ident() |
|
111 |
self._g_threadmap[thr] = p = Profiler() |
|
112 |
# this overrides our sys.setprofile hook:
|
|
113 |
p.enable(subcalls=True, builtins=True) |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
114 |
|
115 |
||
116 |
class Stats(object): |
|
5432.2.1
by John C Barstow
Provide missing docstrings for bzrlib.lsprof |
117 |
"""Wrapper around the collected data.
|
118 |
||
119 |
A Stats instance is created when the profiler finishes. Normal
|
|
120 |
usage is to use save() to write out the data to a file, or pprint()
|
|
121 |
to write human-readable information to the command line.
|
|
122 |
"""
|
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
123 |
|
1553.7.2
by Robey Pointer
add threading support -- each thread created during an lsprof session gets its own profile object, and the Stats objects are attached to a 'threads' member of the final Stats object |
124 |
def __init__(self, data, threads): |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
125 |
self.data = data |
1553.7.2
by Robey Pointer
add threading support -- each thread created during an lsprof session gets its own profile object, and the Stats objects are attached to a 'threads' member of the final Stats object |
126 |
self.threads = threads |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
127 |
|
128 |
def sort(self, crit="inlinetime"): |
|
5432.2.1
by John C Barstow
Provide missing docstrings for bzrlib.lsprof |
129 |
"""Sort the data by the supplied critera.
|
130 |
||
131 |
:param crit: the data attribute used as the sort key."""
|
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
132 |
if crit not in profiler_entry.__dict__: |
133 |
raise ValueError, "Can't sort by %s" % crit |
|
134 |
self.data.sort(lambda b, a: cmp(getattr(a, crit), |
|
135 |
getattr(b, crit))) |
|
136 |
for e in self.data: |
|
137 |
if e.calls: |
|
138 |
e.calls.sort(lambda b, a: cmp(getattr(a, crit), |
|
139 |
getattr(b, crit))) |
|
140 |
||
141 |
def pprint(self, top=None, file=None): |
|
5432.2.1
by John C Barstow
Provide missing docstrings for bzrlib.lsprof |
142 |
"""Pretty-print the data as plain text for human consumption.
|
143 |
||
144 |
:param top: only output the top n entries.
|
|
145 |
The default value of None means output all data.
|
|
146 |
:param file: the output file; if None, output will
|
|
147 |
default to stdout."""
|
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
148 |
if file is None: |
149 |
file = sys.stdout |
|
150 |
d = self.data |
|
151 |
if top is not None: |
|
152 |
d = d[:top] |
|
153 |
cols = "% 12s %12s %11.4f %11.4f %s\n" |
|
154 |
hcols = "% 12s %12s %12s %12s %s\n" |
|
155 |
cols2 = "+%12s %12s %11.4f %11.4f + %s\n" |
|
156 |
file.write(hcols % ("CallCount", "Recursive", "Total(ms)", |
|
157 |
"Inline(ms)", "module:lineno(function)")) |
|
158 |
for e in d: |
|
159 |
file.write(cols % (e.callcount, e.reccallcount, e.totaltime, |
|
160 |
e.inlinetime, label(e.code))) |
|
161 |
if e.calls: |
|
162 |
for se in e.calls: |
|
163 |
file.write(cols % ("+%s" % se.callcount, se.reccallcount, |
|
164 |
se.totaltime, se.inlinetime, |
|
165 |
"+%s" % label(se.code))) |
|
166 |
||
167 |
def freeze(self): |
|
168 |
"""Replace all references to code objects with string
|
|
169 |
descriptions; this makes it possible to pickle the instance."""
|
|
170 |
||
171 |
# this code is probably rather ickier than it needs to be!
|
|
172 |
for i in range(len(self.data)): |
|
173 |
e = self.data[i] |
|
174 |
if not isinstance(e.code, str): |
|
175 |
self.data[i] = type(e)((label(e.code),) + e[1:]) |
|
1706.2.7
by Robey Pointer
pull over some changes from the original lsprof |
176 |
if e.calls: |
177 |
for j in range(len(e.calls)): |
|
178 |
se = e.calls[j] |
|
179 |
if not isinstance(se.code, str): |
|
180 |
e.calls[j] = type(se)((label(se.code),) + se[1:]) |
|
1553.7.2
by Robey Pointer
add threading support -- each thread created during an lsprof session gets its own profile object, and the Stats objects are attached to a 'threads' member of the final Stats object |
181 |
for s in self.threads.values(): |
182 |
s.freeze() |
|
183 |
||
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
184 |
def calltree(self, file): |
185 |
"""Output profiling data in calltree format (for KCacheGrind)."""
|
|
186 |
_CallTreeFilter(self.data).output(file) |
|
187 |
||
2493.2.3
by Ian Clatworthy
changes requested in jameinel's review incorporated |
188 |
def save(self, filename, format=None): |
189 |
"""Save profiling data to a file.
|
|
190 |
||
191 |
:param filename: the name of the output file
|
|
192 |
:param format: 'txt' for a text representation;
|
|
193 |
'callgrind' for calltree format;
|
|
194 |
otherwise a pickled Python object. A format of None indicates
|
|
2654.2.2
by Ian Clatworthy
Put all format detection stuff in one spot as requested by John Arbash Meinel |
195 |
that the format to use is to be found from the filename. If
|
196 |
the name starts with callgrind.out, callgrind format is used
|
|
197 |
otherwise the format is given by the filename extension.
|
|
2493.2.3
by Ian Clatworthy
changes requested in jameinel's review incorporated |
198 |
"""
|
199 |
if format is None: |
|
3535.5.1
by John Arbash Meinel
cleanup a few imports to be lazily loaded. |
200 |
basename = os.path.basename(filename) |
2805.7.2
by Ian Clatworthy
use basename, not full path, when checking for callgrind.out file prefix |
201 |
if basename.startswith('callgrind.out'): |
2654.2.2
by Ian Clatworthy
Put all format detection stuff in one spot as requested by John Arbash Meinel |
202 |
format = "callgrind" |
203 |
else: |
|
3535.5.1
by John Arbash Meinel
cleanup a few imports to be lazily loaded. |
204 |
ext = os.path.splitext(filename)[1] |
2654.2.2
by Ian Clatworthy
Put all format detection stuff in one spot as requested by John Arbash Meinel |
205 |
if len(ext) > 1: |
206 |
format = ext[1:] |
|
2493.2.3
by Ian Clatworthy
changes requested in jameinel's review incorporated |
207 |
outfile = open(filename, 'wb') |
208 |
try: |
|
209 |
if format == "callgrind": |
|
210 |
self.calltree(outfile) |
|
211 |
elif format == "txt": |
|
212 |
self.pprint(file=outfile) |
|
213 |
else: |
|
214 |
self.freeze() |
|
215 |
cPickle.dump(self, outfile, 2) |
|
216 |
finally: |
|
217 |
outfile.close() |
|
218 |
||
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
219 |
|
220 |
class _CallTreeFilter(object): |
|
2493.2.2
by Ian Clatworthy
Incorporate feedback from Robert Collins |
221 |
"""Converter of a Stats object to input suitable for KCacheGrind.
|
222 |
||
223 |
This code is taken from http://ddaa.net/blog/python/lsprof-calltree
|
|
224 |
with the changes made by J.P. Calderone and Itamar applied. Note that
|
|
3943.8.1
by Marius Kruger
remove all trailing whitespace from bzr source |
225 |
isinstance(code, str) needs to be used at times to determine if the code
|
2493.2.2
by Ian Clatworthy
Incorporate feedback from Robert Collins |
226 |
object is actually an external code object (with a filename, etc.) or
|
227 |
a Python built-in.
|
|
228 |
"""
|
|
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
229 |
|
230 |
def __init__(self, data): |
|
231 |
self.data = data |
|
232 |
self.out_file = None |
|
233 |
||
234 |
def output(self, out_file): |
|
3943.8.1
by Marius Kruger
remove all trailing whitespace from bzr source |
235 |
self.out_file = out_file |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
236 |
out_file.write('events: Ticks\n') |
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
237 |
self._print_summary() |
238 |
for entry in self.data: |
|
239 |
self._entry(entry) |
|
240 |
||
241 |
def _print_summary(self): |
|
242 |
max_cost = 0 |
|
243 |
for entry in self.data: |
|
244 |
totaltime = int(entry.totaltime * 1000) |
|
245 |
max_cost = max(max_cost, totaltime) |
|
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
246 |
self.out_file.write('summary: %d\n' % (max_cost,)) |
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
247 |
|
248 |
def _entry(self, entry): |
|
249 |
out_file = self.out_file |
|
250 |
code = entry.code |
|
251 |
inlinetime = int(entry.inlinetime * 1000) |
|
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
252 |
#out_file.write('ob=%s\n' % (code.co_filename,))
|
253 |
if isinstance(code, str): |
|
254 |
out_file.write('fi=~\n') |
|
255 |
else: |
|
256 |
out_file.write('fi=%s\n' % (code.co_filename,)) |
|
257 |
out_file.write('fn=%s\n' % (label(code, True),)) |
|
258 |
if isinstance(code, str): |
|
2911.6.4
by Blake Winton
Fix test failures |
259 |
out_file.write('0 %s\n' % (inlinetime,)) |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
260 |
else: |
261 |
out_file.write('%d %d\n' % (code.co_firstlineno, inlinetime)) |
|
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
262 |
# recursive calls are counted in entry.calls
|
263 |
if entry.calls: |
|
264 |
calls = entry.calls |
|
265 |
else: |
|
266 |
calls = [] |
|
2493.2.1
by Ian Clatworthy
make profiling information easier to view and better documented |
267 |
if isinstance(code, str): |
268 |
lineno = 0 |
|
269 |
else: |
|
270 |
lineno = code.co_firstlineno |
|
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
271 |
for subentry in calls: |
2493.2.1
by Ian Clatworthy
make profiling information easier to view and better documented |
272 |
self._subentry(lineno, subentry) |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
273 |
out_file.write('\n') |
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
274 |
|
275 |
def _subentry(self, lineno, subentry): |
|
276 |
out_file = self.out_file |
|
277 |
code = subentry.code |
|
278 |
totaltime = int(subentry.totaltime * 1000) |
|
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
279 |
#out_file.write('cob=%s\n' % (code.co_filename,))
|
2493.2.1
by Ian Clatworthy
make profiling information easier to view and better documented |
280 |
if isinstance(code, str): |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
281 |
out_file.write('cfi=~\n') |
5783.1.1
by John Arbash Meinel
Fix bug #758695, correctly order the 'cfn' vs 'cfi' in callgrind output. |
282 |
out_file.write('cfn=%s\n' % (label(code, True),)) |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
283 |
out_file.write('calls=%d 0\n' % (subentry.callcount,)) |
2493.2.1
by Ian Clatworthy
make profiling information easier to view and better documented |
284 |
else: |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
285 |
out_file.write('cfi=%s\n' % (code.co_filename,)) |
5783.1.1
by John Arbash Meinel
Fix bug #758695, correctly order the 'cfn' vs 'cfi' in callgrind output. |
286 |
out_file.write('cfn=%s\n' % (label(code, True),)) |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
287 |
out_file.write('calls=%d %d\n' % ( |
288 |
subentry.callcount, code.co_firstlineno)) |
|
289 |
out_file.write('%d %d\n' % (lineno, totaltime)) |
|
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
290 |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
291 |
_fn2mod = {} |
292 |
||
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
293 |
def label(code, calltree=False): |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
294 |
if isinstance(code, str): |
295 |
return code |
|
296 |
try: |
|
297 |
mname = _fn2mod[code.co_filename] |
|
298 |
except KeyError: |
|
1711.2.124
by John Arbash Meinel
Use sys.modules.items() to prevent running into site.py problems |
299 |
for k, v in sys.modules.items(): |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
300 |
if v is None: |
301 |
continue
|
|
1963.2.6
by Robey Pointer
pychecker is on crack; go back to using 'is None'. |
302 |
if getattr(v, '__file__', None) is None: |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
303 |
continue
|
304 |
if not isinstance(v.__file__, str): |
|
305 |
continue
|
|
306 |
if v.__file__.startswith(code.co_filename): |
|
307 |
mname = _fn2mod[code.co_filename] = k |
|
308 |
break
|
|
309 |
else: |
|
310 |
mname = _fn2mod[code.co_filename] = '<%s>'%code.co_filename |
|
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
311 |
if calltree: |
312 |
return '%s %s:%d' % (code.co_name, mname, code.co_firstlineno) |
|
313 |
else: |
|
314 |
return '%s:%d(%s)' % (mname, code.co_firstlineno, code.co_name) |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
315 |
|
316 |
||
317 |
if __name__ == '__main__': |
|
318 |
import os |
|
319 |
sys.argv = sys.argv[1:] |
|
320 |
if not sys.argv: |
|
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
321 |
sys.stderr.write("usage: lsprof.py <script> <arguments...>\n") |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
322 |
sys.exit(2) |
323 |
sys.path.insert(0, os.path.abspath(os.path.dirname(sys.argv[0]))) |
|
324 |
stats = profile(execfile, sys.argv[0], globals(), locals()) |
|
325 |
stats.sort() |
|
326 |
stats.pprint() |