[Python-checkins] CVS: python/dist/src/Lib profile.py,1.32,1.33

2001年10月03日 17:58:26 -0700

Update of /cvsroot/python/python/dist/src/Lib
In directory usw-pr-cvs1:/tmp/cvs-serv14852
Modified Files:
	profile.py 
Log Message:
Hopefully fix the profiler right. Add a test suite that checks that
it deals correctly with some anomalous cases; according to this test
suite I've fixed it right.
The anomalous cases had to do with 'exception' events: these aren't
generated when they would be most helpful, and the profiler has to
work hard to recover the right information. The problems occur when C
code (such as hasattr(), which is used as the example here) calls back
into Python code and clears an exception raised by that Python code.
Consider this example:
 def foo():
 hasattr(obj, "bar")
Where obj is an instance from a class like this:
 class C:
 def __getattr__(self, name):
 raise AttributeError
The profiler sees the following sequence of events:
 call (foo)
 call (__getattr__)
 exception (in __getattr__)
 return (from foo)
Previously, the profiler would assume the return event returned from
__getattr__. An if statement checking for this condition and raising
an exception was commented out... This version does the right thing.
Index: profile.py
===================================================================
RCS file: /cvsroot/python/python/dist/src/Lib/profile.py,v
retrieving revision 1.32
retrieving revision 1.33
diff -C2 -d -r1.32 -r1.33
*** profile.py	2001年10月03日 21:12:32	1.32
--- profile.py	2001年10月04日 00:58:24	1.33
***************
*** 110,125 ****
 used to write into the frames local dictionary!!) Derived classes
 can change the definition of some entries, as long as they leave
! [-2:] intact.

! [ 0] = Time that needs to be charged to the parent frame's function.
! It is used so that a function call will not have to access the
! timing data for the parent frame.
! [ 1] = Total time spent in this frame's function, excluding time in
! subfunctions
! [ 2] = Cumulative time spent in this frame's function, including time in
! all subfunctions to this frame.
! [-3] = Name of the function that corresponds to this frame.
! [-2] = Actual frame that we correspond to (used to sync exception handling)
! [-1] = Our parent 6-tuple (corresponds to frame.f_back)

 Timing data for each function is stored as a 5-tuple in the dictionary
--- 110,125 ----
 used to write into the frames local dictionary!!) Derived classes
 can change the definition of some entries, as long as they leave
! [3:] intact.

! [0] = Time that needs to be charged to the parent frame's function.
! It is used so that a function call will not have to access the
! timing data for the parent frame.
! [1] = Total time spent in this frame's function, excluding time in
! subfunctions
! [2] = Cumulative time spent in this frame's function, including time in
! all subfunctions to this frame (but excluding this frame!).
! [3] = Name of the function that corresponds to this frame.
! [4] = Actual frame that we correspond to (used to sync exception handling)
! [5] = Our parent 6-tuple (corresponds to frame.f_back)

 Timing data for each function is stored as a 5-tuple in the dictionary
***************
*** 244,251 ****
 if (rframe is not frame) and rcur:
 return self.trace_dispatch_return(rframe, t)
! return 0

 def trace_dispatch_call(self, frame, t):
 fcode = frame.f_code
 fn = (fcode.co_filename, fcode.co_firstlineno, fcode.co_name)
--- 244,262 ----
 if (rframe is not frame) and rcur:
 return self.trace_dispatch_return(rframe, t)
! self.cur = rt, rtt+t, rct, rfn, rframe, rcur
! return 1

 def trace_dispatch_call(self, frame, t):
+ if self.cur and frame.f_back is not self.cur[4]:
+ rt, rtt, rct, rfn, rframe, rcur = self.cur
+ if not isinstance(rframe, Profile.fake_frame):
+ if rframe.f_back is not frame.f_back:
+ print rframe, rframe.f_back
+ print frame, frame.f_back
+ raise "Bad call", self.cur[3]
+ self.trace_dispatch_return(rframe, 0)
+ if self.cur and frame.f_back is not self.cur[4]:
+ raise "Bad call[2]", self.cur[3]
 fcode = frame.f_code
 fn = (fcode.co_filename, fcode.co_firstlineno, fcode.co_name)
***************
*** 260,264 ****

 def trace_dispatch_return(self, frame, t):
! # if not frame is self.cur[-2]: raise "Bad return", self.cur[3]

 # Prefix "r" means part of the Returning or exiting frame
--- 271,279 ----

 def trace_dispatch_return(self, frame, t):
! if frame is not self.cur[4]:
! if frame is self.cur[4].f_back:
! self.trace_dispatch_return(self.cur[4], 0)
! else:
! raise "Bad return", self.cur[3]

 # Prefix "r" means part of the Returning or exiting frame
***************
*** 303,307 ****

 def set_cmd(self, cmd):
! if self.cur[-1]: return # already set
 self.cmd = cmd
 self.simulate_call(cmd)
--- 318,322 ----

 def set_cmd(self, cmd):
! if self.cur[5]: return # already set
 self.cmd = cmd
 self.simulate_call(cmd)
***************
*** 325,329 ****
 code = self.fake_code('profile', 0, name)
 if self.cur:
! pframe = self.cur[-2]
 else:
 pframe = None
--- 340,344 ----
 code = self.fake_code('profile', 0, name)
 if self.cur:
! pframe = self.cur[4]
 else:
 pframe = None
***************
*** 338,345 ****
 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
--- 353,360 ----
 get_time = self.get_time
 t = get_time() - self.t
! while self.cur[5]:
 # We *can* cause assertion errors here if
 # dispatch_trace_return checks for a frame match!
! a = self.dispatch['return'](self, self.cur[4], t)
 t = 0
 self.t = get_time() - t