Commit | Line | Data |
---|---|---|
920dae64 AT |
1 | #! /usr/bin/env python |
2 | # | |
3 | # Class for profiling python code. rev 1.0 6/2/94 | |
4 | # | |
5 | # Based on prior profile module by Sjoerd Mullender... | |
6 | # which was hacked somewhat by: Guido van Rossum | |
7 | # | |
8 | # See profile.doc for more information | |
9 | ||
10 | """Class for profiling Python code.""" | |
11 | ||
12 | # Copyright 1994, by InfoSeek Corporation, all rights reserved. | |
13 | # Written by James Roskind | |
14 | # | |
15 | # Permission to use, copy, modify, and distribute this Python software | |
16 | # and its associated documentation for any purpose (subject to the | |
17 | # restriction in the following sentence) without fee is hereby granted, | |
18 | # provided that the above copyright notice appears in all copies, and | |
19 | # that both that copyright notice and this permission notice appear in | |
20 | # supporting documentation, and that the name of InfoSeek not be used in | |
21 | # advertising or publicity pertaining to distribution of the software | |
22 | # without specific, written prior permission. This permission is | |
23 | # explicitly restricted to the copying and modification of the software | |
24 | # to remain in Python, compiled Python, or other languages (such as C) | |
25 | # wherein the modified or derived code is exclusively imported into a | |
26 | # Python module. | |
27 | # | |
28 | # INFOSEEK CORPORATION DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS | |
29 | # SOFTWARE, INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY AND | |
30 | # FITNESS. IN NO EVENT SHALL INFOSEEK CORPORATION BE LIABLE FOR ANY | |
31 | # SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER | |
32 | # RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF | |
33 | # CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN | |
34 | # CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. | |
35 | ||
36 | ||
37 | ||
38 | import sys | |
39 | import os | |
40 | import time | |
41 | import marshal | |
42 | from optparse import OptionParser | |
43 | ||
44 | __all__ = ["run", "runctx", "help", "Profile"] | |
45 | ||
46 | # Sample timer for use with | |
47 | #i_count = 0 | |
48 | #def integer_timer(): | |
49 | # global i_count | |
50 | # i_count = i_count + 1 | |
51 | # return i_count | |
52 | #itimes = integer_timer # replace with C coded timer returning integers | |
53 | ||
54 | #************************************************************************** | |
55 | # The following are the static member functions for the profiler class | |
56 | # Note that an instance of Profile() is *not* needed to call them. | |
57 | #************************************************************************** | |
58 | ||
59 | def run(statement, filename=None, sort=-1): | |
60 | """Run statement under profiler optionally saving results in filename | |
61 | ||
62 | This function takes a single argument that can be passed to the | |
63 | "exec" statement, and an optional file name. In all cases this | |
64 | routine attempts to "exec" its first argument and gather profiling | |
65 | statistics from the execution. If no file name is present, then this | |
66 | function automatically prints a simple profiling report, sorted by the | |
67 | standard name string (file/line/function-name) that is presented in | |
68 | each line. | |
69 | """ | |
70 | prof = Profile() | |
71 | try: | |
72 | prof = prof.run(statement) | |
73 | except SystemExit: | |
74 | pass | |
75 | if filename is not None: | |
76 | prof.dump_stats(filename) | |
77 | else: | |
78 | return prof.print_stats(sort) | |
79 | ||
80 | def runctx(statement, globals, locals, filename=None): | |
81 | """Run statement under profiler, supplying your own globals and locals, | |
82 | optionally saving results in filename. | |
83 | ||
84 | statement and filename have the same semantics as profile.run | |
85 | """ | |
86 | prof = Profile() | |
87 | try: | |
88 | prof = prof.runctx(statement, globals, locals) | |
89 | except SystemExit: | |
90 | pass | |
91 | ||
92 | if filename is not None: | |
93 | prof.dump_stats(filename) | |
94 | else: | |
95 | return prof.print_stats() | |
96 | ||
97 | # print help | |
98 | def help(): | |
99 | for dirname in sys.path: | |
100 | fullname = os.path.join(dirname, 'profile.doc') | |
101 | if os.path.exists(fullname): | |
102 | sts = os.system('${PAGER-more} ' + fullname) | |
103 | if sts: print '*** Pager exit status:', sts | |
104 | break | |
105 | else: | |
106 | print 'Sorry, can\'t find the help file "profile.doc"', | |
107 | print 'along the Python search path.' | |
108 | ||
109 | ||
110 | if os.name == "mac": | |
111 | import MacOS | |
112 | def _get_time_mac(timer=MacOS.GetTicks): | |
113 | return timer() / 60.0 | |
114 | ||
115 | if hasattr(os, "times"): | |
116 | def _get_time_times(timer=os.times): | |
117 | t = timer() | |
118 | return t[0] + t[1] | |
119 | ||
120 | ||
121 | class Profile: | |
122 | """Profiler class. | |
123 | ||
124 | self.cur is always a tuple. Each such tuple corresponds to a stack | |
125 | frame that is currently active (self.cur[-2]). The following are the | |
126 | definitions of its members. We use this external "parallel stack" to | |
127 | avoid contaminating the program that we are profiling. (old profiler | |
128 | used to write into the frames local dictionary!!) Derived classes | |
129 | can change the definition of some entries, as long as they leave | |
130 | [-2:] intact (frame and previous tuple). In case an internal error is | |
131 | detected, the -3 element is used as the function name. | |
132 | ||
133 | [ 0] = Time that needs to be charged to the parent frame's function. | |
134 | It is used so that a function call will not have to access the | |
135 | timing data for the parent frame. | |
136 | [ 1] = Total time spent in this frame's function, excluding time in | |
137 | subfunctions (this latter is tallied in cur[2]). | |
138 | [ 2] = Total time spent in subfunctions, excluding time executing the | |
139 | frame's function (this latter is tallied in cur[1]). | |
140 | [-3] = Name of the function that corresponds to this frame. | |
141 | [-2] = Actual frame that we correspond to (used to sync exception handling). | |
142 | [-1] = Our parent 6-tuple (corresponds to frame.f_back). | |
143 | ||
144 | Timing data for each function is stored as a 5-tuple in the dictionary | |
145 | self.timings[]. The index is always the name stored in self.cur[-3]. | |
146 | The following are the definitions of the members: | |
147 | ||
148 | [0] = The number of times this function was called, not counting direct | |
149 | or indirect recursion, | |
150 | [1] = Number of times this function appears on the stack, minus one | |
151 | [2] = Total time spent internal to this function | |
152 | [3] = Cumulative time that this function was present on the stack. In | |
153 | non-recursive functions, this is the total execution time from start | |
154 | to finish of each invocation of a function, including time spent in | |
155 | all subfunctions. | |
156 | [4] = A dictionary indicating for each function name, the number of times | |
157 | it was called by us. | |
158 | """ | |
159 | ||
160 | bias = 0 # calibration constant | |
161 | ||
162 | def __init__(self, timer=None, bias=None): | |
163 | self.timings = {} | |
164 | self.cur = None | |
165 | self.cmd = "" | |
166 | self.c_func_name = "" | |
167 | ||
168 | if bias is None: | |
169 | bias = self.bias | |
170 | self.bias = bias # Materialize in local dict for lookup speed. | |
171 | ||
172 | if timer is None: | |
173 | if os.name == 'mac': | |
174 | self.timer = MacOS.GetTicks | |
175 | self.dispatcher = self.trace_dispatch_mac | |
176 | self.get_time = _get_time_mac | |
177 | elif hasattr(time, 'clock'): | |
178 | self.timer = self.get_time = time.clock | |
179 | self.dispatcher = self.trace_dispatch_i | |
180 | elif hasattr(os, 'times'): | |
181 | self.timer = os.times | |
182 | self.dispatcher = self.trace_dispatch | |
183 | self.get_time = _get_time_times | |
184 | else: | |
185 | self.timer = self.get_time = time.time | |
186 | self.dispatcher = self.trace_dispatch_i | |
187 | else: | |
188 | self.timer = timer | |
189 | t = self.timer() # test out timer function | |
190 | try: | |
191 | length = len(t) | |
192 | except TypeError: | |
193 | self.get_time = timer | |
194 | self.dispatcher = self.trace_dispatch_i | |
195 | else: | |
196 | if length == 2: | |
197 | self.dispatcher = self.trace_dispatch | |
198 | else: | |
199 | self.dispatcher = self.trace_dispatch_l | |
200 | # This get_time() implementation needs to be defined | |
201 | # here to capture the passed-in timer in the parameter | |
202 | # list (for performance). Note that we can't assume | |
203 | # the timer() result contains two values in all | |
204 | # cases. | |
205 | def get_time_timer(timer=timer, sum=sum): | |
206 | return sum(timer()) | |
207 | self.get_time = get_time_timer | |
208 | self.t = self.get_time() | |
209 | self.simulate_call('profiler') | |
210 | ||
211 | # Heavily optimized dispatch routine for os.times() timer | |
212 | ||
213 | def trace_dispatch(self, frame, event, arg): | |
214 | timer = self.timer | |
215 | t = timer() | |
216 | t = t[0] + t[1] - self.t - self.bias | |
217 | ||
218 | if event == "c_call": | |
219 | self.c_func_name = arg.__name__ | |
220 | ||
221 | if self.dispatch[event](self, frame,t): | |
222 | t = timer() | |
223 | self.t = t[0] + t[1] | |
224 | else: | |
225 | r = timer() | |
226 | self.t = r[0] + r[1] - t # put back unrecorded delta | |
227 | ||
228 | # Dispatch routine for best timer program (return = scalar, fastest if | |
229 | # an integer but float works too -- and time.clock() relies on that). | |
230 | ||
231 | def trace_dispatch_i(self, frame, event, arg): | |
232 | timer = self.timer | |
233 | t = timer() - self.t - self.bias | |
234 | ||
235 | if event == "c_call": | |
236 | self.c_func_name = arg.__name__ | |
237 | ||
238 | if self.dispatch[event](self, frame, t): | |
239 | self.t = timer() | |
240 | else: | |
241 | self.t = timer() - t # put back unrecorded delta | |
242 | ||
243 | # Dispatch routine for macintosh (timer returns time in ticks of | |
244 | # 1/60th second) | |
245 | ||
246 | def trace_dispatch_mac(self, frame, event, arg): | |
247 | timer = self.timer | |
248 | t = timer()/60.0 - self.t - self.bias | |
249 | ||
250 | if event == "c_call": | |
251 | self.c_func_name = arg.__name__ | |
252 | ||
253 | if self.dispatch[event](self, frame, t): | |
254 | self.t = timer()/60.0 | |
255 | else: | |
256 | self.t = timer()/60.0 - t # put back unrecorded delta | |
257 | ||
258 | # SLOW generic dispatch routine for timer returning lists of numbers | |
259 | ||
260 | def trace_dispatch_l(self, frame, event, arg): | |
261 | get_time = self.get_time | |
262 | t = get_time() - self.t - self.bias | |
263 | ||
264 | if event == "c_call": | |
265 | self.c_func_name = arg.__name__ | |
266 | ||
267 | if self.dispatch[event](self, frame, t): | |
268 | self.t = get_time() | |
269 | else: | |
270 | self.t = get_time() - t # put back unrecorded delta | |
271 | ||
272 | # In the event handlers, the first 3 elements of self.cur are unpacked | |
273 | # into vrbls w/ 3-letter names. The last two characters are meant to be | |
274 | # mnemonic: | |
275 | # _pt self.cur[0] "parent time" time to be charged to parent frame | |
276 | # _it self.cur[1] "internal time" time spent directly in the function | |
277 | # _et self.cur[2] "external time" time spent in subfunctions | |
278 | ||
279 | def trace_dispatch_exception(self, frame, t): | |
280 | rpt, rit, ret, rfn, rframe, rcur = self.cur | |
281 | if (rframe is not frame) and rcur: | |
282 | return self.trace_dispatch_return(rframe, t) | |
283 | self.cur = rpt, rit+t, ret, rfn, rframe, rcur | |
284 | return 1 | |
285 | ||
286 | ||
287 | def trace_dispatch_call(self, frame, t): | |
288 | if self.cur and frame.f_back is not self.cur[-2]: | |
289 | rpt, rit, ret, rfn, rframe, rcur = self.cur | |
290 | if not isinstance(rframe, Profile.fake_frame): | |
291 | assert rframe.f_back is frame.f_back, ("Bad call", rfn, | |
292 | rframe, rframe.f_back, | |
293 | frame, frame.f_back) | |
294 | self.trace_dispatch_return(rframe, 0) | |
295 | assert (self.cur is None or \ | |
296 | frame.f_back is self.cur[-2]), ("Bad call", | |
297 | self.cur[-3]) | |
298 | fcode = frame.f_code | |
299 | fn = (fcode.co_filename, fcode.co_firstlineno, fcode.co_name) | |
300 | self.cur = (t, 0, 0, fn, frame, self.cur) | |
301 | timings = self.timings | |
302 | if fn in timings: | |
303 | cc, ns, tt, ct, callers = timings[fn] | |
304 | timings[fn] = cc, ns + 1, tt, ct, callers | |
305 | else: | |
306 | timings[fn] = 0, 0, 0, 0, {} | |
307 | return 1 | |
308 | ||
309 | def trace_dispatch_c_call (self, frame, t): | |
310 | fn = ("", 0, self.c_func_name) | |
311 | self.cur = (t, 0, 0, fn, frame, self.cur) | |
312 | timings = self.timings | |
313 | if timings.has_key(fn): | |
314 | cc, ns, tt, ct, callers = timings[fn] | |
315 | timings[fn] = cc, ns+1, tt, ct, callers | |
316 | else: | |
317 | timings[fn] = 0, 0, 0, 0, {} | |
318 | return 1 | |
319 | ||
320 | def trace_dispatch_return(self, frame, t): | |
321 | if frame is not self.cur[-2]: | |
322 | assert frame is self.cur[-2].f_back, ("Bad return", self.cur[-3]) | |
323 | self.trace_dispatch_return(self.cur[-2], 0) | |
324 | ||
325 | # Prefix "r" means part of the Returning or exiting frame. | |
326 | # Prefix "p" means part of the Previous or Parent or older frame. | |
327 | ||
328 | rpt, rit, ret, rfn, frame, rcur = self.cur | |
329 | rit = rit + t | |
330 | frame_total = rit + ret | |
331 | ||
332 | ppt, pit, pet, pfn, pframe, pcur = rcur | |
333 | self.cur = ppt, pit + rpt, pet + frame_total, pfn, pframe, pcur | |
334 | ||
335 | timings = self.timings | |
336 | cc, ns, tt, ct, callers = timings[rfn] | |
337 | if not ns: | |
338 | # This is the only occurrence of the function on the stack. | |
339 | # Else this is a (directly or indirectly) recursive call, and | |
340 | # its cumulative time will get updated when the topmost call to | |
341 | # it returns. | |
342 | ct = ct + frame_total | |
343 | cc = cc + 1 | |
344 | ||
345 | if pfn in callers: | |
346 | callers[pfn] = callers[pfn] + 1 # hack: gather more | |
347 | # stats such as the amount of time added to ct courtesy | |
348 | # of this specific call, and the contribution to cc | |
349 | # courtesy of this call. | |
350 | else: | |
351 | callers[pfn] = 1 | |
352 | ||
353 | timings[rfn] = cc, ns - 1, tt + rit, ct, callers | |
354 | ||
355 | return 1 | |
356 | ||
357 | ||
358 | dispatch = { | |
359 | "call": trace_dispatch_call, | |
360 | "exception": trace_dispatch_exception, | |
361 | "return": trace_dispatch_return, | |
362 | "c_call": trace_dispatch_c_call, | |
363 | "c_exception": trace_dispatch_return, # the C function returned | |
364 | "c_return": trace_dispatch_return, | |
365 | } | |
366 | ||
367 | ||
368 | # The next few functions play with self.cmd. By carefully preloading | |
369 | # our parallel stack, we can force the profiled result to include | |
370 | # an arbitrary string as the name of the calling function. | |
371 | # We use self.cmd as that string, and the resulting stats look | |
372 | # very nice :-). | |
373 | ||
374 | def set_cmd(self, cmd): | |
375 | if self.cur[-1]: return # already set | |
376 | self.cmd = cmd | |
377 | self.simulate_call(cmd) | |
378 | ||
379 | class fake_code: | |
380 | def __init__(self, filename, line, name): | |
381 | self.co_filename = filename | |
382 | self.co_line = line | |
383 | self.co_name = name | |
384 | self.co_firstlineno = 0 | |
385 | ||
386 | def __repr__(self): | |
387 | return repr((self.co_filename, self.co_line, self.co_name)) | |
388 | ||
389 | class fake_frame: | |
390 | def __init__(self, code, prior): | |
391 | self.f_code = code | |
392 | self.f_back = prior | |
393 | ||
394 | def simulate_call(self, name): | |
395 | code = self.fake_code('profile', 0, name) | |
396 | if self.cur: | |
397 | pframe = self.cur[-2] | |
398 | else: | |
399 | pframe = None | |
400 | frame = self.fake_frame(code, pframe) | |
401 | self.dispatch['call'](self, frame, 0) | |
402 | ||
403 | # collect stats from pending stack, including getting final | |
404 | # timings for self.cmd frame. | |
405 | ||
406 | def simulate_cmd_complete(self): | |
407 | get_time = self.get_time | |
408 | t = get_time() - self.t | |
409 | while self.cur[-1]: | |
410 | # We *can* cause assertion errors here if | |
411 | # dispatch_trace_return checks for a frame match! | |
412 | self.dispatch['return'](self, self.cur[-2], t) | |
413 | t = 0 | |
414 | self.t = get_time() - t | |
415 | ||
416 | ||
417 | def print_stats(self, sort=-1): | |
418 | import pstats | |
419 | pstats.Stats(self).strip_dirs().sort_stats(sort). \ | |
420 | print_stats() | |
421 | ||
422 | def dump_stats(self, file): | |
423 | f = open(file, 'wb') | |
424 | self.create_stats() | |
425 | marshal.dump(self.stats, f) | |
426 | f.close() | |
427 | ||
428 | def create_stats(self): | |
429 | self.simulate_cmd_complete() | |
430 | self.snapshot_stats() | |
431 | ||
432 | def snapshot_stats(self): | |
433 | self.stats = {} | |
434 | for func, (cc, ns, tt, ct, callers) in self.timings.iteritems(): | |
435 | callers = callers.copy() | |
436 | nc = 0 | |
437 | for callcnt in callers.itervalues(): | |
438 | nc += callcnt | |
439 | self.stats[func] = cc, nc, tt, ct, callers | |
440 | ||
441 | ||
442 | # The following two methods can be called by clients to use | |
443 | # a profiler to profile a statement, given as a string. | |
444 | ||
445 | def run(self, cmd): | |
446 | import __main__ | |
447 | dict = __main__.__dict__ | |
448 | return self.runctx(cmd, dict, dict) | |
449 | ||
450 | def runctx(self, cmd, globals, locals): | |
451 | self.set_cmd(cmd) | |
452 | sys.setprofile(self.dispatcher) | |
453 | try: | |
454 | exec cmd in globals, locals | |
455 | finally: | |
456 | sys.setprofile(None) | |
457 | return self | |
458 | ||
459 | # This method is more useful to profile a single function call. | |
460 | def runcall(self, func, *args, **kw): | |
461 | self.set_cmd(repr(func)) | |
462 | sys.setprofile(self.dispatcher) | |
463 | try: | |
464 | return func(*args, **kw) | |
465 | finally: | |
466 | sys.setprofile(None) | |
467 | ||
468 | ||
469 | #****************************************************************** | |
470 | # The following calculates the overhead for using a profiler. The | |
471 | # problem is that it takes a fair amount of time for the profiler | |
472 | # to stop the stopwatch (from the time it receives an event). | |
473 | # Similarly, there is a delay from the time that the profiler | |
474 | # re-starts the stopwatch before the user's code really gets to | |
475 | # continue. The following code tries to measure the difference on | |
476 | # a per-event basis. | |
477 | # | |
478 | # Note that this difference is only significant if there are a lot of | |
479 | # events, and relatively little user code per event. For example, | |
480 | # code with small functions will typically benefit from having the | |
481 | # profiler calibrated for the current platform. This *could* be | |
482 | # done on the fly during init() time, but it is not worth the | |
483 | # effort. Also note that if too large a value specified, then | |
484 | # execution time on some functions will actually appear as a | |
485 | # negative number. It is *normal* for some functions (with very | |
486 | # low call counts) to have such negative stats, even if the | |
487 | # calibration figure is "correct." | |
488 | # | |
489 | # One alternative to profile-time calibration adjustments (i.e., | |
490 | # adding in the magic little delta during each event) is to track | |
491 | # more carefully the number of events (and cumulatively, the number | |
492 | # of events during sub functions) that are seen. If this were | |
493 | # done, then the arithmetic could be done after the fact (i.e., at | |
494 | # display time). Currently, we track only call/return events. | |
495 | # These values can be deduced by examining the callees and callers | |
496 | # vectors for each functions. Hence we *can* almost correct the | |
497 | # internal time figure at print time (note that we currently don't | |
498 | # track exception event processing counts). Unfortunately, there | |
499 | # is currently no similar information for cumulative sub-function | |
500 | # time. It would not be hard to "get all this info" at profiler | |
501 | # time. Specifically, we would have to extend the tuples to keep | |
502 | # counts of this in each frame, and then extend the defs of timing | |
503 | # tuples to include the significant two figures. I'm a bit fearful | |
504 | # that this additional feature will slow the heavily optimized | |
505 | # event/time ratio (i.e., the profiler would run slower, fur a very | |
506 | # low "value added" feature.) | |
507 | #************************************************************** | |
508 | ||
509 | def calibrate(self, m, verbose=0): | |
510 | if self.__class__ is not Profile: | |
511 | raise TypeError("Subclasses must override .calibrate().") | |
512 | ||
513 | saved_bias = self.bias | |
514 | self.bias = 0 | |
515 | try: | |
516 | return self._calibrate_inner(m, verbose) | |
517 | finally: | |
518 | self.bias = saved_bias | |
519 | ||
520 | def _calibrate_inner(self, m, verbose): | |
521 | get_time = self.get_time | |
522 | ||
523 | # Set up a test case to be run with and without profiling. Include | |
524 | # lots of calls, because we're trying to quantify stopwatch overhead. | |
525 | # Do not raise any exceptions, though, because we want to know | |
526 | # exactly how many profile events are generated (one call event, + | |
527 | # one return event, per Python-level call). | |
528 | ||
529 | def f1(n): | |
530 | for i in range(n): | |
531 | x = 1 | |
532 | ||
533 | def f(m, f1=f1): | |
534 | for i in range(m): | |
535 | f1(100) | |
536 | ||
537 | f(m) # warm up the cache | |
538 | ||
539 | # elapsed_noprofile <- time f(m) takes without profiling. | |
540 | t0 = get_time() | |
541 | f(m) | |
542 | t1 = get_time() | |
543 | elapsed_noprofile = t1 - t0 | |
544 | if verbose: | |
545 | print "elapsed time without profiling =", elapsed_noprofile | |
546 | ||
547 | # elapsed_profile <- time f(m) takes with profiling. The difference | |
548 | # is profiling overhead, only some of which the profiler subtracts | |
549 | # out on its own. | |
550 | p = Profile() | |
551 | t0 = get_time() | |
552 | p.runctx('f(m)', globals(), locals()) | |
553 | t1 = get_time() | |
554 | elapsed_profile = t1 - t0 | |
555 | if verbose: | |
556 | print "elapsed time with profiling =", elapsed_profile | |
557 | ||
558 | # reported_time <- "CPU seconds" the profiler charged to f and f1. | |
559 | total_calls = 0.0 | |
560 | reported_time = 0.0 | |
561 | for (filename, line, funcname), (cc, ns, tt, ct, callers) in \ | |
562 | p.timings.items(): | |
563 | if funcname in ("f", "f1"): | |
564 | total_calls += cc | |
565 | reported_time += tt | |
566 | ||
567 | if verbose: | |
568 | print "'CPU seconds' profiler reported =", reported_time | |
569 | print "total # calls =", total_calls | |
570 | if total_calls != m + 1: | |
571 | raise ValueError("internal error: total calls = %d" % total_calls) | |
572 | ||
573 | # reported_time - elapsed_noprofile = overhead the profiler wasn't | |
574 | # able to measure. Divide by twice the number of calls (since there | |
575 | # are two profiler events per call in this test) to get the hidden | |
576 | # overhead per event. | |
577 | mean = (reported_time - elapsed_noprofile) / 2.0 / total_calls | |
578 | if verbose: | |
579 | print "mean stopwatch overhead per profile event =", mean | |
580 | return mean | |
581 | ||
582 | #**************************************************************************** | |
583 | def Stats(*args): | |
584 | print 'Report generating functions are in the "pstats" module\a' | |
585 | ||
586 | ||
587 | # When invoked as main program, invoke the profiler on a script | |
588 | if __name__ == '__main__': | |
589 | usage = "profile.py [-o output_file_path] [-s sort] scriptfile [arg] ..." | |
590 | if not sys.argv[1:]: | |
591 | print "Usage: ", usage | |
592 | sys.exit(2) | |
593 | ||
594 | class ProfileParser(OptionParser): | |
595 | def __init__(self, usage): | |
596 | OptionParser.__init__(self) | |
597 | self.usage = usage | |
598 | ||
599 | parser = ProfileParser(usage) | |
600 | parser.allow_interspersed_args = False | |
601 | parser.add_option('-o', '--outfile', dest="outfile", | |
602 | help="Save stats to <outfile>", default=None) | |
603 | parser.add_option('-s', '--sort', dest="sort", | |
604 | help="Sort order when printing to stdout, based on pstats.Stats class", default=-1) | |
605 | ||
606 | (options, args) = parser.parse_args() | |
607 | sys.argv[:] = args | |
608 | ||
609 | if (len(sys.argv) > 0): | |
610 | sys.path.insert(0, os.path.dirname(sys.argv[0])) | |
611 | run('execfile(%r)' % (sys.argv[0],), options.outfile, options.sort) | |
612 | else: | |
613 | print "Usage: ", usage |