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 |
||
2493.2.3
by Ian Clatworthy
changes requested in jameinel's review incorporated |
6 |
import cPickle |
7 |
import os |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
8 |
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 |
9 |
import thread |
10 |
import threading |
|
1773.4.1
by Martin Pool
Add pyflakes makefile target; fix many warnings |
11 |
from _lsprof import Profiler, profiler_entry |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
12 |
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
13 |
from bzrlib import errors |
2805.7.4
by Ian Clatworthy
incorporate feedback from lifeless |
14 |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
15 |
__all__ = ['profile', 'Stats'] |
16 |
||
17 |
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) |
18 |
"""Run a function profile.
|
3943.8.1
by Marius Kruger
remove all trailing whitespace from bzr source |
19 |
|
4084.6.1
by Robert Collins
Refactor profiling exception handling to restore clear layers - command handling in commands.py, profiling in lsprof.py. |
20 |
Exceptions are not caught: If you need stats even when exceptions are to be
|
4641.3.2
by Robert Collins
lsprof support. |
21 |
raised, pass in a closure that will catch the exceptions and transform them
|
22 |
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. |
23 |
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
24 |
Important caveat: only one profile can execute at a time. See BzrProfiler
|
25 |
for details.
|
|
26 |
||
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) |
27 |
:return: The functions return value and a stats object.
|
28 |
"""
|
|
4641.3.2
by Robert Collins
lsprof support. |
29 |
profiler = BzrProfiler() |
30 |
profiler.start() |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
31 |
try: |
4084.6.1
by Robert Collins
Refactor profiling exception handling to restore clear layers - command handling in commands.py, profiling in lsprof.py. |
32 |
ret = f(*args, **kwds) |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
33 |
finally: |
4641.3.2
by Robert Collins
lsprof support. |
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.
|
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
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.
|
|
4641.3.2
by Robert Collins
lsprof support. |
55 |
"""
|
56 |
||
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
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 |
||
4641.3.2
by Robert Collins
lsprof support. |
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() |
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
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
|
|
4641.3.2
by Robert Collins
lsprof support. |
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 |
"""
|
|
5331.1.1
by Robert Collins
``bzrlib.lsprof.profile`` will no longer silently generate bad threaded |
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() |
|
3943.8.1
by Marius Kruger
remove all trailing whitespace from bzr source |
104 |
|
4641.3.2
by Robert Collins
lsprof support. |
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) |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
112 |
|
113 |
||
114 |
class Stats(object): |
|
5432.2.1
by John C Barstow
Provide missing docstrings for bzrlib.lsprof |
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 |
"""
|
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
121 |
|
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 |
122 |
def __init__(self, data, threads): |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
123 |
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 |
124 |
self.threads = threads |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
125 |
|
126 |
def sort(self, crit="inlinetime"): |
|
5432.2.1
by John C Barstow
Provide missing docstrings for bzrlib.lsprof |
127 |
"""Sort the data by the supplied critera.
|
128 |
||
129 |
:param crit: the data attribute used as the sort key."""
|
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
130 |
if crit not in profiler_entry.__dict__: |
131 |
raise ValueError, "Can't sort by %s" % crit |
|
132 |
self.data.sort(lambda b, a: cmp(getattr(a, crit), |
|
133 |
getattr(b, crit))) |
|
134 |
for e in self.data: |
|
135 |
if e.calls: |
|
136 |
e.calls.sort(lambda b, a: cmp(getattr(a, crit), |
|
137 |
getattr(b, crit))) |
|
138 |
||
139 |
def pprint(self, top=None, file=None): |
|
5432.2.1
by John C Barstow
Provide missing docstrings for bzrlib.lsprof |
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."""
|
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
146 |
if file is None: |
147 |
file = sys.stdout |
|
148 |
d = self.data |
|
149 |
if top is not None: |
|
150 |
d = d[:top] |
|
151 |
cols = "% 12s %12s %11.4f %11.4f %s\n" |
|
152 |
hcols = "% 12s %12s %12s %12s %s\n" |
|
153 |
cols2 = "+%12s %12s %11.4f %11.4f + %s\n" |
|
154 |
file.write(hcols % ("CallCount", "Recursive", "Total(ms)", |
|
155 |
"Inline(ms)", "module:lineno(function)")) |
|
156 |
for e in d: |
|
157 |
file.write(cols % (e.callcount, e.reccallcount, e.totaltime, |
|
158 |
e.inlinetime, label(e.code))) |
|
159 |
if e.calls: |
|
160 |
for se in e.calls: |
|
161 |
file.write(cols % ("+%s" % se.callcount, se.reccallcount, |
|
162 |
se.totaltime, se.inlinetime, |
|
163 |
"+%s" % label(se.code))) |
|
164 |
||
165 |
def freeze(self): |
|
166 |
"""Replace all references to code objects with string
|
|
167 |
descriptions; this makes it possible to pickle the instance."""
|
|
168 |
||
169 |
# this code is probably rather ickier than it needs to be!
|
|
170 |
for i in range(len(self.data)): |
|
171 |
e = self.data[i] |
|
172 |
if not isinstance(e.code, str): |
|
173 |
self.data[i] = type(e)((label(e.code),) + e[1:]) |
|
1706.2.7
by Robey Pointer
pull over some changes from the original lsprof |
174 |
if e.calls: |
175 |
for j in range(len(e.calls)): |
|
176 |
se = e.calls[j] |
|
177 |
if not isinstance(se.code, str): |
|
178 |
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 |
179 |
for s in self.threads.values(): |
180 |
s.freeze() |
|
181 |
||
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
182 |
def calltree(self, file): |
183 |
"""Output profiling data in calltree format (for KCacheGrind)."""
|
|
184 |
_CallTreeFilter(self.data).output(file) |
|
185 |
||
2493.2.3
by Ian Clatworthy
changes requested in jameinel's review incorporated |
186 |
def save(self, filename, format=None): |
187 |
"""Save profiling data to a file.
|
|
188 |
||
189 |
:param filename: the name of the output file
|
|
190 |
:param format: 'txt' for a text representation;
|
|
191 |
'callgrind' for calltree format;
|
|
192 |
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 |
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.
|
|
2493.2.3
by Ian Clatworthy
changes requested in jameinel's review incorporated |
196 |
"""
|
197 |
if format is None: |
|
3535.5.1
by John Arbash Meinel
cleanup a few imports to be lazily loaded. |
198 |
basename = os.path.basename(filename) |
2805.7.2
by Ian Clatworthy
use basename, not full path, when checking for callgrind.out file prefix |
199 |
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 |
200 |
format = "callgrind" |
201 |
else: |
|
3535.5.1
by John Arbash Meinel
cleanup a few imports to be lazily loaded. |
202 |
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 |
203 |
if len(ext) > 1: |
204 |
format = ext[1:] |
|
2493.2.3
by Ian Clatworthy
changes requested in jameinel's review incorporated |
205 |
outfile = open(filename, 'wb') |
206 |
try: |
|
207 |
if format == "callgrind": |
|
208 |
self.calltree(outfile) |
|
209 |
elif format == "txt": |
|
210 |
self.pprint(file=outfile) |
|
211 |
else: |
|
212 |
self.freeze() |
|
213 |
cPickle.dump(self, outfile, 2) |
|
214 |
finally: |
|
215 |
outfile.close() |
|
216 |
||
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
217 |
|
218 |
class _CallTreeFilter(object): |
|
2493.2.2
by Ian Clatworthy
Incorporate feedback from Robert Collins |
219 |
"""Converter of a Stats object to input suitable for KCacheGrind.
|
220 |
||
221 |
This code is taken from http://ddaa.net/blog/python/lsprof-calltree
|
|
222 |
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 |
223 |
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 |
224 |
object is actually an external code object (with a filename, etc.) or
|
225 |
a Python built-in.
|
|
226 |
"""
|
|
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
227 |
|
228 |
def __init__(self, data): |
|
229 |
self.data = data |
|
230 |
self.out_file = None |
|
231 |
||
232 |
def output(self, out_file): |
|
3943.8.1
by Marius Kruger
remove all trailing whitespace from bzr source |
233 |
self.out_file = out_file |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
234 |
out_file.write('events: Ticks\n') |
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
235 |
self._print_summary() |
236 |
for entry in self.data: |
|
237 |
self._entry(entry) |
|
238 |
||
239 |
def _print_summary(self): |
|
240 |
max_cost = 0 |
|
241 |
for entry in self.data: |
|
242 |
totaltime = int(entry.totaltime * 1000) |
|
243 |
max_cost = max(max_cost, totaltime) |
|
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
244 |
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 |
245 |
|
246 |
def _entry(self, entry): |
|
247 |
out_file = self.out_file |
|
248 |
code = entry.code |
|
249 |
inlinetime = int(entry.inlinetime * 1000) |
|
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
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): |
|
2911.6.4
by Blake Winton
Fix test failures |
257 |
out_file.write('0 %s\n' % (inlinetime,)) |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
258 |
else: |
259 |
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 |
260 |
# recursive calls are counted in entry.calls
|
261 |
if entry.calls: |
|
262 |
calls = entry.calls |
|
263 |
else: |
|
264 |
calls = [] |
|
2493.2.1
by Ian Clatworthy
make profiling information easier to view and better documented |
265 |
if isinstance(code, str): |
266 |
lineno = 0 |
|
267 |
else: |
|
268 |
lineno = code.co_firstlineno |
|
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
269 |
for subentry in calls: |
2493.2.1
by Ian Clatworthy
make profiling information easier to view and better documented |
270 |
self._subentry(lineno, subentry) |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
271 |
out_file.write('\n') |
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
272 |
|
273 |
def _subentry(self, lineno, subentry): |
|
274 |
out_file = self.out_file |
|
275 |
code = subentry.code |
|
276 |
totaltime = int(subentry.totaltime * 1000) |
|
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
277 |
#out_file.write('cob=%s\n' % (code.co_filename,))
|
278 |
out_file.write('cfn=%s\n' % (label(code, True),)) |
|
2493.2.1
by Ian Clatworthy
make profiling information easier to view and better documented |
279 |
if isinstance(code, str): |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
280 |
out_file.write('cfi=~\n') |
281 |
out_file.write('calls=%d 0\n' % (subentry.callcount,)) |
|
2493.2.1
by Ian Clatworthy
make profiling information easier to view and better documented |
282 |
else: |
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
283 |
out_file.write('cfi=%s\n' % (code.co_filename,)) |
284 |
out_file.write('calls=%d %d\n' % ( |
|
285 |
subentry.callcount, code.co_firstlineno)) |
|
286 |
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 |
287 |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
288 |
_fn2mod = {} |
289 |
||
1553.7.3
by Robey Pointer
patch from ddaa to add kcachegrind output-format support to lsprof |
290 |
def label(code, calltree=False): |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
291 |
if isinstance(code, str): |
292 |
return code |
|
293 |
try: |
|
294 |
mname = _fn2mod[code.co_filename] |
|
295 |
except KeyError: |
|
1711.2.124
by John Arbash Meinel
Use sys.modules.items() to prevent running into site.py problems |
296 |
for k, v in sys.modules.items(): |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
297 |
if v is None: |
298 |
continue
|
|
1963.2.6
by Robey Pointer
pychecker is on crack; go back to using 'is None'. |
299 |
if getattr(v, '__file__', None) is None: |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
300 |
continue
|
301 |
if not isinstance(v.__file__, str): |
|
302 |
continue
|
|
303 |
if v.__file__.startswith(code.co_filename): |
|
304 |
mname = _fn2mod[code.co_filename] = k |
|
305 |
break
|
|
306 |
else: |
|
307 |
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 |
308 |
if calltree: |
309 |
return '%s %s:%d' % (code.co_name, mname, code.co_firstlineno) |
|
310 |
else: |
|
311 |
return '%s:%d(%s)' % (mname, code.co_firstlineno, code.co_name) |
|
1185.33.86
by Martin Pool
Add additional module for lsprof. |
312 |
|
313 |
||
314 |
if __name__ == '__main__': |
|
315 |
import os |
|
316 |
sys.argv = sys.argv[1:] |
|
317 |
if not sys.argv: |
|
2911.6.1
by Blake Winton
Change 'print >> f,'s to 'f.write('s. |
318 |
sys.stderr.write("usage: lsprof.py <script> <arguments...>\n") |
1185.33.86
by Martin Pool
Add additional module for lsprof. |
319 |
sys.exit(2) |
320 |
sys.path.insert(0, os.path.abspath(os.path.dirname(sys.argv[0]))) |
|
321 |
stats = profile(execfile, sys.argv[0], globals(), locals()) |
|
322 |
stats.sort() |
|
323 |
stats.pprint() |