[Python-checkins] CVS: python/dist/src/Lib profile.py,1.27,1.28
Fred L. Drake
fdrake@users.sourceforge.net
Thu, 07 Jun 2001 21:25:26 -0700
Update of /cvsroot/python/python/dist/src/Lib
In directory usw-pr-cvs1:/tmp/cvs-serv26018
Modified Files:
profile.py
Log Message:
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.
Index: profile.py
===================================================================
RCS file: /cvsroot/python/python/dist/src/Lib/profile.py,v
retrieving revision 1.27
retrieving revision 1.28
diff -C2 -r1.27 -r1.28
*** profile.py 2001/03/14 20:01:19 1.27
--- profile.py 2001/06/08 04:25:24 1.28
***************
*** 90,93 ****
--- 90,103 ----
+ 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.
***************
*** 133,142 ****
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':
--- 143,146 ----
***************
*** 144,156 ****
self.timer = MacOS.GetTicks
self.dispatcher = self.trace_dispatch_mac
! self.get_time = self.get_time_mac
elif hasattr(time, 'clock'):
! self.timer = time.clock
self.dispatcher = self.trace_dispatch_i
elif hasattr(os, 'times'):
self.timer = os.times
self.dispatcher = self.trace_dispatch
else:
! self.timer = time.time
self.dispatcher = self.trace_dispatch_i
else:
--- 148,161 ----
self.timer = MacOS.GetTicks
self.dispatcher = self.trace_dispatch_mac
! self.get_time = _get_time_mac
elif hasattr(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 = self.get_time = time.time
self.dispatcher = self.trace_dispatch_i
else:
***************
*** 158,192 ****
t = self.timer() # test out timer function
try:
! if len(t) == 2:
self.dispatcher = self.trace_dispatch
else:
self.dispatcher = self.trace_dispatch_l
! except TypeError:
! self.dispatcher = self.trace_dispatch_i
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()
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()
self.t = t[0] + t[1]
else:
! r = self.timer()
self.t = r[0] + r[1] - t # put back unrecorded delta
return
--- 163,200 ----
t = self.timer() # test out timer function
try:
! 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
! # 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')
# Heavily optimized dispatch routine for os.times() timer
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
! if self.dispatch[event](self, frame,t):
! t = timer()
self.t = t[0] + t[1]
else:
! r = timer()
self.t = r[0] + r[1] - t # put back unrecorded delta
return
***************
*** 197,215 ****
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()
else:
! self.t = self.timer() - t # put back unrecorded delta
return
! # 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
else:
! self.t = self.timer()/60.0 - t # put back unrecorded delta
return
--- 205,226 ----
def trace_dispatch_i(self, frame, event, arg):
! timer = self.timer
! t = timer() - self.t # - 1 # Integer calibration constant
! if self.dispatch[event](self, frame,t):
! self.t = timer()
else:
! self.t = timer() - t # put back unrecorded delta
return
! # Dispatch routine for macintosh (timer returns time in ticks of
! # 1/60th second)
def trace_dispatch_mac(self, frame, event, arg):
! 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 = timer()/60.0 - t # put back unrecorded delta
return
***************
*** 218,227 ****
def trace_dispatch_l(self, frame, event, arg):
! t = self.get_time() - self.t
! if self.dispatch[event](frame,t):
! self.t = self.get_time()
else:
! self.t = self.get_time()-t # put back unrecorded delta
return
--- 229,239 ----
def trace_dispatch_l(self, frame, event, arg):
! get_time = self.get_time
! t = get_time() - self.t
! if self.dispatch[event](self, frame,t):
! self.t = get_time()
else:
! self.t = get_time() - t # put back unrecorded delta
return
***************
*** 238,246 ****
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
else:
! self.timings[fn] = 0, 0, 0, 0, {}
return 1
--- 250,259 ----
fn = (fcode.co_filename, fcode.co_firstlineno, fcode.co_name)
self.cur = (t, 0, 0, fn, frame, self.cur)
! timings = self.timings
! if timings.has_key(fn):
! cc, ns, tt, ct, callers = timings[fn]
! timings[fn] = cc, ns + 1, tt, ct, callers
else:
! timings[fn] = 0, 0, 0, 0, {}
return 1
***************
*** 258,262 ****
self.cur = pt, ptt+rt, pct+sft, pfn, pframe, pcur
! cc, ns, tt, ct, callers = self.timings[rfn]
if not ns:
ct = ct + sft
--- 271,276 ----
self.cur = pt, ptt+rt, pct+sft, pfn, pframe, pcur
! timings = self.timings
! cc, ns, tt, ct, callers = timings[rfn]
if not ns:
ct = ct + sft
***************
*** 269,276 ****
else:
callers[pfn] = 1
! self.timings[rfn] = cc, ns - 1, tt+rtt, ct, callers
return 1
# The next few function play with self.cmd. By carefully preloading
# our parallel stack, we can force the profiled result to include
--- 283,298 ----
else:
callers[pfn] = 1
! 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
***************
*** 306,310 ****
pframe = None
frame = self.fake_frame(code, pframe)
! a = self.dispatch['call'](frame, 0)
return
--- 328,332 ----
pframe = None
frame = self.fake_frame(code, pframe)
! a = self.dispatch['call'](self, frame, 0)
return
***************
*** 313,323 ****
def simulate_cmd_complete(self):
! t = self.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)
t = 0
! self.t = self.get_time() - t
--- 335,346 ----
def simulate_cmd_complete(self):
! 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, self.cur[-2], t)
t = 0
! self.t = get_time() - t
***************
*** 366,374 ****
# This method is more useful to profile a single function call.
! def runcall(self, func, *args):
self.set_cmd(`func`)
sys.setprofile(self.dispatcher)
try:
! return apply(func, args)
finally:
sys.setprofile(None)
--- 389,397 ----
# This method is more useful to profile a single function call.
! def runcall(self, func, *args, **kw):
self.set_cmd(`func`)
sys.setprofile(self.dispatcher)
try:
! return apply(func, args, kw)
finally:
sys.setprofile(None)
***************
*** 420,438 ****
def calibrate(self, m):
# Modified by Tim Peters
n = m
! s = self.get_time()
while n:
self.simple()
n = n - 1
! f = self.get_time()
my_simple = f - s
#print "Simple =", my_simple,
n = m
! s = self.get_time()
while n:
self.instrumented()
n = n - 1
! f = self.get_time()
my_inst = f - s
# print "Instrumented =", my_inst
--- 443,462 ----
def calibrate(self, m):
# Modified by Tim Peters
+ 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
***************
*** 504,507 ****
--- 528,538 ----
+ dispatch = {
+ "call": trace_dispatch_call,
+ "exception": trace_dispatch_exception,
+ "return": trace_dispatch_return,
+ }
+
+
def snapshot_stats(self):
self.stats = {}
***************
*** 550,553 ****
--- 581,591 ----
+ dispatch = {
+ "call": trace_dispatch_call,
+ "exception": trace_dispatch_exception,
+ "return": trace_dispatch_return,
+ }
+
+
def snapshot_stats(self):
self.stats = {}
***************
*** 565,570 ****
# 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] ..."
--- 603,606 ----