diff options
Diffstat (limited to 'Lib')
| -rwxr-xr-x | Lib/profile.py | 103 |
1 files changed, 62 insertions, 41 deletions
diff --git a/Lib/profile.py b/Lib/profile.py index a9eb113..6c1edea 100755 --- a/Lib/profile.py +++ b/Lib/profile.py @@ -190,8 +190,7 @@ class Profile: def trace_dispatch(self, frame, event, arg): timer = self.timer t = timer() - t = t[0] + t[1] - self.t # No Calibration constant - # t = t[0] + t[1] - self.t - .00053 # Calibration constant + t = t[0] + t[1] - self.t # - .00053 calibration constant if self.dispatch[event](self, frame,t): t = timer() @@ -207,7 +206,7 @@ class Profile: def trace_dispatch_i(self, frame, event, arg): timer = self.timer - t = timer() - self.t # - 1 # calibration constant + t = timer() - self.t # - 16e-6 # calibration constant if self.dispatch[event](self, frame,t): self.t = timer() else: @@ -219,7 +218,7 @@ class Profile: def trace_dispatch_mac(self, frame, event, arg): timer = self.timer - t = timer()/60.0 - self.t # - 1 # Integer calibration constant + t = timer()/60.0 - self.t # - 1 # calibration constant if self.dispatch[event](self, frame,t): self.t = timer()/60.0 else: @@ -467,45 +466,67 @@ class Profile: # profiler very much, and the accuracy goes way up. #************************************************************** - def calibrate(self, m): - # Modified by Tim Peters + def calibrate(self, m, verbose=0): get_time = self.get_time - n = m - s = get_time() - while n: - self.simple() - n = n - 1 - f = get_time() - my_simple = f - s - #print "Simple =", my_simple, - - n = m - s = get_time() - while n: - self.instrumented() - n = n - 1 - f = get_time() - my_inst = f - s - # print "Instrumented =", my_inst - avg_cost = (my_inst - my_simple)/m - #print "Delta/call =", avg_cost, "(profiler fixup constant)" - return avg_cost - - # simulate a program with no profiler activity - def simple(self): - a = 1 - pass - - # simulate a program with call/return event processing - def instrumented(self): - a = 1 - self.profiler_simulation(a, a, a) - # simulate an event processing activity (from user's perspective) - def profiler_simulation(self, x, y, z): - t = self.timer() - ## t = t[0] + t[1] - self.ut = t + # Set up a test case to be run with and without profiling. Include + # lots of calls, because we're trying to quantify stopwatch overhead. + # Do not raise any exceptions, though, because we want to know + # exactly how many profile events are generated (one call event, + + # one return event, per Python-level call). + + def f1(n): + for i in range(n): + x = 1 + + def f(m, f1=f1): + for i in range(m): + f1(100) + + f(m) # warm up the cache + + # elapsed_noprofile <- time f(m) takes without profiling. + t0 = get_time() + f(m) + t1 = get_time() + elapsed_noprofile = t1 - t0 + if verbose: + print "elapsed time without profiling =", elapsed_noprofile + + # elapsed_profile <- time f(m) takes with profiling. The difference + # is profiling overhead, only some of which the profiler subtracts + # out on its own. + p = Profile() + t0 = get_time() + p.runctx('f(m)', globals(), locals()) + t1 = get_time() + elapsed_profile = t1 - t0 + if verbose: + print "elapsed time with profiling =", elapsed_profile + + # reported_time <- "CPU seconds" the profiler charged to f and f1. + total_calls = 0.0 + reported_time = 0.0 + for (filename, line, funcname), (cc, ns, tt, ct, callers) in \ + p.timings.items(): + if funcname in ("f", "f1"): + total_calls += cc + reported_time += tt + + if verbose: + print "'CPU seconds' profiler reported =", reported_time + print "total # calls =", total_calls + if total_calls != m + 1: + raise ValueError("internal error: total calls = %d" % total_calls) + + # reported_time - elapsed_noprofile = overhead the profiler wasn't + # able to measure. Divide by twice the number of calls (since there + # are two profiler events per call in this test) to get the hidden + # overhead per event. + mean = (reported_time - elapsed_noprofile) / 2.0 / total_calls + if verbose: + print "mean stopwatch overhead per profile event =", mean + return mean #**************************************************************************** def Stats(*args): |