traverseda
/
cpython
1
0
Fork 0
Code Issues Pull Requests Releases Wiki Activity

Performance improvements to the profiler: 

Ensure that all the default timers are called as functions, not an
expensive method wrapper around a variety of different functions.

Agressively avoid dictionary lookups.

Modify the dispatch scheme (Profile.trace_dispatch_*(), where * is not
'call', 'exception' or 'return') so that the callables dispatched to
are simple functions and not bound methods -- this reduces the number
of layers of Python call machinery that gets touched.

Remove a couple of duplicate imports from the "if __name__ == ..."
section.

This closes SF patch #430948.
This commit is contained in:
Fred Drake 2001-06-08 04:25:24 +00:00
parent 13b8bc5478
commit edb5ffb2c1
1 changed files with 93 additions and 57 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

150
Lib/profile.py
View File

@ -89,6 +89,16 @@ def help():
print 'along the Python search path'
if os.name == "mac":
def _get_time_mac(timer=MacOS.GetTicks):
return timer() / 60.0
if hasattr(os, "times"):
def _get_time_times(timer=os.times):
t = timer()
return t[0] + t[1]
class Profile:
"""Profiler class.
@ -132,62 +142,60 @@ class Profile:
self.cur = None
self.cmd = ""
self.dispatch = { \
'call' : self.trace_dispatch_call, \
'return' : self.trace_dispatch_return, \
'exception': self.trace_dispatch_exception, \
}
if not timer:
if os.name == 'mac':
import MacOS
self.timer = MacOS.GetTicks
self.dispatcher = self.trace_dispatch_mac
self.get_time = self.get_time_mac
self.get_time = _get_time_mac
elif hasattr(time, 'clock'):
self.timer = time.clock
self.timer = self.get_time = time.clock
self.dispatcher = self.trace_dispatch_i
elif hasattr(os, 'times'):
self.timer = os.times
self.dispatcher = self.trace_dispatch
self.get_time = _get_time_times
else:
self.timer = time.time
self.timer = self.get_time = time.time
self.dispatcher = self.trace_dispatch_i
else:
self.timer = timer
t = self.timer() # test out timer function
try:
if len(t) == 2:
length = len(t)
except TypeError:
self.get_time = timer
self.dispatcher = self.trace_dispatch_i
else:
if length == 2:
self.dispatcher = self.trace_dispatch
else:
self.dispatcher = self.trace_dispatch_l
except TypeError:
self.dispatcher = self.trace_dispatch_i
# This get_time() implementation needs to be defined
# here to capture the passed-in timer in the parameter
# list (for performance). Note that we can't assume
# the timer() result contains two values in all
# cases.
def get_time_timer(timer=timer,
reduce=reduce, reducer=operator.add):
return reduce(reducer, timer(), 0)
self.get_time = get_time_timer
self.t = self.get_time()
self.simulate_call('profiler')
def get_time(self): # slow simulation of method to acquire time
t = self.timer()
if type(t) == type(()) or type(t) == type([]):
t = reduce(lambda x,y: x+y, t, 0)
return t
def get_time_mac(self):
return self.timer()/60.0
# Heavily optimized dispatch routine for os.times() timer
def trace_dispatch(self, frame, event, arg):
t = self.timer()
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
if self.dispatch[event](frame,t):
t = self.timer()
if self.dispatch[event](self, frame,t):
t = timer()
self.t = t[0] + t[1]
else:
r = self.timer()
r = timer()
self.t = r[0] + r[1] - t # put back unrecorded delta
return
@ -196,33 +204,37 @@ class Profile:
# Dispatch routine for best timer program (return = scalar integer)
def trace_dispatch_i(self, frame, event, arg):
t = self.timer() - self.t # - 1 # Integer calibration constant
if self.dispatch[event](frame,t):
self.t = self.timer()
timer = self.timer
t = timer() - self.t # - 1 # Integer calibration constant
if self.dispatch[event](self, frame,t):
self.t = timer()
else:
self.t = self.timer() - t # put back unrecorded delta
self.t = timer() - t # put back unrecorded delta
return
# Dispatch routine for macintosh (timer returns time in ticks of 1/60th second)
# Dispatch routine for macintosh (timer returns time in ticks of
# 1/60th second)
def trace_dispatch_mac(self, frame, event, arg):
t = self.timer()/60.0 - self.t # - 1 # Integer calibration constant
if self.dispatch[event](frame,t):
self.t = self.timer()/60.0
timer = self.timer
t = timer()/60.0 - self.t # - 1 # Integer calibration constant
if self.dispatch[event](self, frame,t):
self.t = timer()/60.0
else:
self.t = self.timer()/60.0 - t # put back unrecorded delta
self.t = timer()/60.0 - t # put back unrecorded delta
return
# SLOW generic dispatch routine for timer returning lists of numbers
def trace_dispatch_l(self, frame, event, arg):
t = self.get_time() - self.t
get_time = self.get_time
t = get_time() - self.t
if self.dispatch[event](frame,t):
self.t = self.get_time()
if self.dispatch[event](self, frame,t):
self.t = get_time()
else:
self.t = self.get_time()-t # put back unrecorded delta
self.t = get_time() - t # put back unrecorded delta
return
@ -237,11 +249,12 @@ class Profile:
fcode = frame.f_code
fn = (fcode.co_filename, fcode.co_firstlineno, fcode.co_name)
self.cur = (t, 0, 0, fn, frame, self.cur)
if self.timings.has_key(fn):
cc, ns, tt, ct, callers = self.timings[fn]
self.timings[fn] = cc, ns + 1, tt, ct, callers
timings = self.timings
if timings.has_key(fn):
cc, ns, tt, ct, callers = timings[fn]
timings[fn] = cc, ns + 1, tt, ct, callers
else:
self.timings[fn] = 0, 0, 0, 0, {}
timings[fn] = 0, 0, 0, 0, {}
return 1
def trace_dispatch_return(self, frame, t):
@ -257,7 +270,8 @@ class Profile:
pt, ptt, pct, pfn, pframe, pcur = rcur
self.cur = pt, ptt+rt, pct+sft, pfn, pframe, pcur
cc, ns, tt, ct, callers = self.timings[rfn]
timings = self.timings
cc, ns, tt, ct, callers = timings[rfn]
if not ns:
ct = ct + sft
cc = cc + 1
@ -268,10 +282,18 @@ class Profile:
# courtesy of this call.
else:
callers[pfn] = 1
self.timings[rfn] = cc, ns - 1, tt+rtt, ct, callers
timings[rfn] = cc, ns - 1, tt+rtt, ct, callers
return 1
dispatch = {
"call": trace_dispatch_call,
"exception": trace_dispatch_exception,
"return": trace_dispatch_return,
}
# The next few function play with self.cmd. By carefully preloading
# our parallel stack, we can force the profiled result to include
# an arbitrary string as the name of the calling function.
@ -305,20 +327,21 @@ class Profile:
else:
pframe = None
frame = self.fake_frame(code, pframe)
a = self.dispatch['call'](frame, 0)
a = self.dispatch['call'](self, frame, 0)
return
# collect stats from pending stack, including getting final
# timings for self.cmd frame.
def simulate_cmd_complete(self):
t = self.get_time() - self.t
get_time = self.get_time
t = get_time() - self.t
while self.cur[-1]:
# We *can* cause assertion errors here if
# dispatch_trace_return checks for a frame match!
a = self.dispatch['return'](self.cur[-2], t)
a = self.dispatch['return'](self, self.cur[-2], t)
t = 0
self.t = self.get_time() - t
self.t = get_time() - t
def print_stats(self):
@ -365,11 +388,11 @@ class Profile:
return self
# This method is more useful to profile a single function call.
def runcall(self, func, *args):
def runcall(self, func, *args, **kw):
self.set_cmd(`func`)
sys.setprofile(self.dispatcher)
try:
return apply(func, args)
return apply(func, args, kw)
finally:
sys.setprofile(None)
@ -419,21 +442,22 @@ class Profile:
def calibrate(self, m):
# Modified by Tim Peters
get_time = self.get_time
n = m
s = self.get_time()
s = get_time()
while n:
self.simple()
n = n - 1
f = self.get_time()
f = get_time()
my_simple = f - s
#print "Simple =", my_simple,
n = m
s = self.get_time()
s = get_time()
while n:
self.instrumented()
n = n - 1
f = self.get_time()
f = get_time()
my_inst = f - s
# print "Instrumented =", my_inst
avg_cost = (my_inst - my_simple)/m
@ -503,6 +527,13 @@ class OldProfile(Profile):
return 1
dispatch = {
"call": trace_dispatch_call,
"exception": trace_dispatch_exception,
"return": trace_dispatch_return,
}
def snapshot_stats(self):
self.stats = {}
for func in self.timings.keys():
@ -549,6 +580,13 @@ class HotProfile(Profile):
return 1
dispatch = {
"call": trace_dispatch_call,
"exception": trace_dispatch_exception,
"return": trace_dispatch_return,
}
def snapshot_stats(self):
self.stats = {}
for func in self.timings.keys():
@ -564,8 +602,6 @@ def Stats(*args):
# When invoked as main program, invoke the profiler on a script
if __name__ == '__main__':
import sys
import os
if not sys.argv[1:]:
print "usage: profile.py scriptfile [arg] ..."
sys.exit(2)