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

[Tim Peters]

Update of /cvsroot/python/python/dist/src/Lib
In directory usw-pr-cvs1:/tmp/cvs-serv9148/python/Lib

Modified Files:
	profile.py 
Log Message:
Guido points out that the comments for self.cur[2] were subtly but
seriously wrong.  This started out by just fixing the docs, but then it
occurred to me that the doc confusion propagated into misleading vrbl names
too, so I also renamed those to match reality.  As a result, INO the time
computations are much easier to understand now (within the limitations of
vast quantities of 3-character names <wink>).


Index: profile.py
===================================================================
RCS file: /cvsroot/python/python/dist/src/Lib/profile.py,v
retrieving revision 1.37
retrieving revision 1.38
diff -C2 -d -r1.37 -r1.38
*** profile.py	2001/10/07 04:30:53	1.37
--- profile.py	2001/10/07 08:35:44	1.38
***************
*** 117,126 ****
             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
--- 117,126 ----
             timing data for the parent frame.
      [ 1] = Total time spent in this frame's function, excluding time in
!            subfunctions (this latter is tallied in cur[2]).
!     [ 2] = Total time spent in subfunctions, excluding time execute the
!            frame's function (this latter is tallied in cur[1]).
      [-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
***************
*** 240,249 ****
          return
  
  
      def trace_dispatch_exception(self, frame, t):
!         rt, rtt, rct, rfn, rframe, rcur = self.cur
          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
  
--- 240,255 ----
          return
  
+     # In the event handlers, the first 3 elements of self.cur are unpacked
+     # into vrbls w/ 3-letter names.  The last two characters are meant to be
+     # mnemonic:
+     #     _pt  self.cur[0] "parent time"   time to be charged to parent frame
+     #     _it  self.cur[1] "internal time" time spent directly in the function
+     #     _et  self.cur[2] "external time" time spent in subfunctions
  
      def trace_dispatch_exception(self, frame, t):
!         rpt, rit, ret, rfn, rframe, rcur = self.cur
          if (rframe is not frame) and rcur:
              return self.trace_dispatch_return(rframe, t)
!         self.cur = rpt, rit+t, ret, rfn, rframe, rcur
          return 1
  
***************
*** 251,255 ****
      def trace_dispatch_call(self, frame, t):
          if self.cur and frame.f_back is not self.cur[-2]:
!             rt, rtt, rct, rfn, rframe, rcur = self.cur
              if not isinstance(rframe, Profile.fake_frame):
                  assert rframe.f_back is frame.f_back, ("Bad call", rfn,
--- 257,261 ----
      def trace_dispatch_call(self, frame, t):
          if self.cur and frame.f_back is not self.cur[-2]:
!             rpt, rit, ret, rfn, rframe, rcur = self.cur
              if not isinstance(rframe, Profile.fake_frame):
                  assert rframe.f_back is frame.f_back, ("Bad call", rfn,
***************
*** 276,294 ****
              self.trace_dispatch_return(self.cur[-2], 0)
  
!         # Prefix "r" means part of the Returning or exiting frame
!         # Prefix "p" means part of the Previous or older frame
  
!         rt, rtt, rct, rfn, frame, rcur = self.cur
!         rtt = rtt + t
!         sft = rtt + rct
  
!         pt, ptt, pct, pfn, pframe, pcur = rcur
!         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
              cc = cc + 1
          if callers.has_key(pfn):
              callers[pfn] = callers[pfn] + 1  # hack: gather more
--- 282,305 ----
              self.trace_dispatch_return(self.cur[-2], 0)
  
!         # Prefix "r" means part of the Returning or exiting frame.
!         # Prefix "p" means part of the Previous or Parent or older frame.
  
!         rpt, rit, ret, rfn, frame, rcur = self.cur
!         rit = rit + t
!         frame_total = rit + ret
  
!         ppt, pit, pet, pfn, pframe, pcur = rcur
!         self.cur = ppt, pit + rpt, pet + frame_total, pfn, pframe, pcur
  
          timings = self.timings
          cc, ns, tt, ct, callers = timings[rfn]
          if not ns:
!             # This is the only occurrence of the function on the stack.
!             # Else this is a (directly or indirectly) recursive call, and
!             # its cumulative time will get updated when the topmost call to
!             # it returns.
!             ct = ct + frame_total
              cc = cc + 1
+ 
          if callers.has_key(pfn):
              callers[pfn] = callers[pfn] + 1  # hack: gather more
***************
*** 298,302 ****
          else:
              callers[pfn] = 1
!         timings[rfn] = cc, ns - 1, tt+rtt, ct, callers
  
          return 1
--- 309,314 ----
          else:
              callers[pfn] = 1
! 
!         timings[rfn] = cc, ns - 1, tt + rit, ct, callers
  
          return 1