A brand new implementation of Profile.calibrate(). This measures an
actual run of the profiler, instead of timing a simplified simulation of part of what the profiler does. It computes a constant about 60% higher on my Win98SE box than the old method, and the new constant appears much more realistic. Deleted the undocumented simple(), instrumented(), and profiler_simulation() methods (which existed only to support the previous calibration method).
This commit is contained in:
Tim Peters
parent
342d8f7780
commit
cce092d046
|
|
@ -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
|
||||
# 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).
|
||||
|
||||
# simulate a program with no profiler activity
|
||||
def simple(self):
|
||||
a = 1
|
||||
pass
|
||||
def f1(n):
|
||||
for i in range(n):
|
||||
x = 1
|
||||
|
||||
# simulate a program with call/return event processing
|
||||
def instrumented(self):
|
||||
a = 1
|
||||
self.profiler_simulation(a, a, a)
|
||||
def f(m, f1=f1):
|
||||
for i in range(m):
|
||||
f1(100)
|
||||
|
||||
# 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
|
||||
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):
|
||||
|
|
|
|||
|
|
@ -47,6 +47,10 @@ Library
|
|||
that's a worthy goal we intend to meet via a different approach (but
|
||||
without losing information).
|
||||
|
||||
- Profile.calibrate() has a new implementation that should deliver
|
||||
a better system-specific calibration constant. Calibration must still
|
||||
be done manually (see the docs for the profile module).
|
||||
|
||||
- quopri's encode and decode methods take an optional header parameter,
|
||||
which indicates whether output is intended for the header 'Q' encoding.
|
||||
|
||||
|
|
|
|||
Loading…
Reference in New Issue