diff options
author | Fred Drake <fdrake@acm.org> | 1998-05-07 01:49:07 (GMT) |
---|---|---|
committer | Fred Drake <fdrake@acm.org> | 1998-05-07 01:49:07 (GMT) |
commit | cda63cc875f54b047018cad362aa23d5493b97f3 (patch) | |
tree | f43f888293bb4046a7622dffefd561b669e993c2 /Doc/libprofile.tex | |
parent | bbe33c559403c7e06642111c494bd32d9abe528f (diff) | |
download | cpython-cda63cc875f54b047018cad362aa23d5493b97f3.zip cpython-cda63cc875f54b047018cad362aa23d5493b97f3.tar.gz cpython-cda63cc875f54b047018cad362aa23d5493b97f3.tar.bz2 |
Relocating file to Doc/lib/
Diffstat (limited to 'Doc/libprofile.tex')
-rw-r--r-- | Doc/libprofile.tex | 767 |
1 files changed, 0 insertions, 767 deletions
diff --git a/Doc/libprofile.tex b/Doc/libprofile.tex deleted file mode 100644 index 61da988..0000000 --- a/Doc/libprofile.tex +++ /dev/null @@ -1,767 +0,0 @@ -\chapter{The Python Profiler} -\label{profile} - -Copyright \copyright{} 1994, by InfoSeek Corporation, all rights reserved. -\index{InfoSeek Corporation} - -Written by James Roskind\index{Roskind, James}.% -\footnote{ -Updated and converted to \LaTeX\ by Guido van Rossum. The references to -the old profiler are left in the text, although it no longer exists. -} - -Permission to use, copy, modify, and distribute this Python software -and its associated documentation for any purpose (subject to the -restriction in the following sentence) without fee is hereby granted, -provided that the above copyright notice appears in all copies, and -that both that copyright notice and this permission notice appear in -supporting documentation, and that the name of InfoSeek not be used in -advertising or publicity pertaining to distribution of the software -without specific, written prior permission. This permission is -explicitly restricted to the copying and modification of the software -to remain in Python, compiled Python, or other languages (such as C) -wherein the modified or derived code is exclusively imported into a -Python module. - -INFOSEEK CORPORATION DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS -SOFTWARE, INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY AND -FITNESS. IN NO EVENT SHALL INFOSEEK CORPORATION BE LIABLE FOR ANY -SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER -RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF -CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN -CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. - - -The profiler was written after only programming in Python for 3 weeks. -As a result, it is probably clumsy code, but I don't know for sure yet -'cause I'm a beginner :-). I did work hard to make the code run fast, -so that profiling would be a reasonable thing to do. I tried not to -repeat code fragments, but I'm sure I did some stuff in really awkward -ways at times. Please send suggestions for improvements to: -\email{jar@netscape.com}. I won't promise \emph{any} support. ...but -I'd appreciate the feedback. - - -\section{Introduction to the profiler} -\nodename{Profiler Introduction} - -A \dfn{profiler} is a program that describes the run time performance -of a program, providing a variety of statistics. This documentation -describes the profiler functionality provided in the modules -\module{profile} and \module{pstats}. This profiler provides -\dfn{deterministic profiling} of any Python programs. It also -provides a series of report generation tools to allow users to rapidly -examine the results of a profile operation. -\index{deterministic profiling} -\index{profiling, deterministic} - - -\section{How Is This Profiler Different From The Old Profiler?} -\nodename{Profiler Changes} - -(This section is of historical importance only; the old profiler -discussed here was last seen in Python 1.1.) - -The big changes from old profiling module are that you get more -information, and you pay less CPU time. It's not a trade-off, it's a -trade-up. - -To be specific: - -\begin{description} - -\item[Bugs removed:] -Local stack frame is no longer molested, execution time is now charged -to correct functions. - -\item[Accuracy increased:] -Profiler execution time is no longer charged to user's code, -calibration for platform is supported, file reads are not done \emph{by} -profiler \emph{during} profiling (and charged to user's code!). - -\item[Speed increased:] -Overhead CPU cost was reduced by more than a factor of two (perhaps a -factor of five), lightweight profiler module is all that must be -loaded, and the report generating module (\module{pstats}) is not needed -during profiling. - -\item[Recursive functions support:] -Cumulative times in recursive functions are correctly calculated; -recursive entries are counted. - -\item[Large growth in report generating UI:] -Distinct profiles runs can be added together forming a comprehensive -report; functions that import statistics take arbitrary lists of -files; sorting criteria is now based on keywords (instead of 4 integer -options); reports shows what functions were profiled as well as what -profile file was referenced; output format has been improved. - -\end{description} - - -\section{Instant Users Manual} - -This section is provided for users that ``don't want to read the -manual.'' It provides a very brief overview, and allows a user to -rapidly perform profiling on an existing application. - -To profile an application with a main entry point of \samp{foo()}, you -would add the following to your module: - -\begin{verbatim} -import profile -profile.run('foo()') -\end{verbatim} -% -The above action would cause \samp{foo()} to be run, and a series of -informative lines (the profile) to be printed. The above approach is -most useful when working with the interpreter. If you would like to -save the results of a profile into a file for later examination, you -can supply a file name as the second argument to the \function{run()} -function: - -\begin{verbatim} -import profile -profile.run('foo()', 'fooprof') -\end{verbatim} -% -The file \file{profile.py} can also be invoked as -a script to profile another script. For example: - -\begin{verbatim} -python /usr/local/lib/python1.5/profile.py myscript.py -\end{verbatim} - -When you wish to review the profile, you should use the methods in the -\module{pstats} module. Typically you would load the statistics data as -follows: - -\begin{verbatim} -import pstats -p = pstats.Stats('fooprof') -\end{verbatim} -% -The class \class{Stats} (the above code just created an instance of -this class) has a variety of methods for manipulating and printing the -data that was just read into \samp{p}. When you ran -\function{profile.run()} above, what was printed was the result of three -method calls: - -\begin{verbatim} -p.strip_dirs().sort_stats(-1).print_stats() -\end{verbatim} -% -The first method removed the extraneous path from all the module -names. The second method sorted all the entries according to the -standard module/line/name string that is printed (this is to comply -with the semantics of the old profiler). The third method printed out -all the statistics. You might try the following sort calls: - -\begin{verbatim} -p.sort_stats('name') -p.print_stats() -\end{verbatim} -% -The first call will actually sort the list by function name, and the -second call will print out the statistics. The following are some -interesting calls to experiment with: - -\begin{verbatim} -p.sort_stats('cumulative').print_stats(10) -\end{verbatim} -% -This sorts the profile by cumulative time in a function, and then only -prints the ten most significant lines. If you want to understand what -algorithms are taking time, the above line is what you would use. - -If you were looking to see what functions were looping a lot, and -taking a lot of time, you would do: - -\begin{verbatim} -p.sort_stats('time').print_stats(10) -\end{verbatim} -% -to sort according to time spent within each function, and then print -the statistics for the top ten functions. - -You might also try: - -\begin{verbatim} -p.sort_stats('file').print_stats('__init__') -\end{verbatim} -% -This will sort all the statistics by file name, and then print out -statistics for only the class init methods ('cause they are spelled -with \samp{__init__} in them). As one final example, you could try: - -\begin{verbatim} -p.sort_stats('time', 'cum').print_stats(.5, 'init') -\end{verbatim} -% -This line sorts statistics with a primary key of time, and a secondary -key of cumulative time, and then prints out some of the statistics. -To be specific, the list is first culled down to 50\% (re: \samp{.5}) -of its original size, then only lines containing \code{init} are -maintained, and that sub-sub-list is printed. - -If you wondered what functions called the above functions, you could -now (\samp{p} is still sorted according to the last criteria) do: - -\begin{verbatim} -p.print_callers(.5, 'init') -\end{verbatim} - -and you would get a list of callers for each of the listed functions. - -If you want more functionality, you're going to have to read the -manual, or guess what the following functions do: - -\begin{verbatim} -p.print_callees() -p.add('fooprof') -\end{verbatim} -% -\section{What Is Deterministic Profiling?} -\nodename{Deterministic Profiling} - -\dfn{Deterministic profiling} is meant to reflect the fact that all -\dfn{function call}, \dfn{function return}, and \dfn{exception} events -are monitored, and precise timings are made for the intervals between -these events (during which time the user's code is executing). In -contrast, \dfn{statistical profiling} (which is not done by this -module) randomly samples the effective instruction pointer, and -deduces where time is being spent. The latter technique traditionally -involves less overhead (as the code does not need to be instrumented), -but provides only relative indications of where time is being spent. - -In Python, since there is an interpreter active during execution, the -presence of instrumented code is not required to do deterministic -profiling. Python automatically provides a \dfn{hook} (optional -callback) for each event. In addition, the interpreted nature of -Python tends to add so much overhead to execution, that deterministic -profiling tends to only add small processing overhead in typical -applications. The result is that deterministic profiling is not that -expensive, yet provides extensive run time statistics about the -execution of a Python program. - -Call count statistics can be used to identify bugs in code (surprising -counts), and to identify possible inline-expansion points (high call -counts). Internal time statistics can be used to identify ``hot -loops'' that should be carefully optimized. Cumulative time -statistics should be used to identify high level errors in the -selection of algorithms. Note that the unusual handling of cumulative -times in this profiler allows statistics for recursive implementations -of algorithms to be directly compared to iterative implementations. - - -\section{Reference Manual} -\stmodindex{profile} -\label{module-profile} - - -The primary entry point for the profiler is the global function -\function{profile.run()}. It is typically used to create any profile -information. The reports are formatted and printed using methods of -the class \class{pstats.Stats}. The following is a description of all -of these standard entry points and functions. For a more in-depth -view of some of the code, consider reading the later section on -Profiler Extensions, which includes discussion of how to derive -``better'' profilers from the classes presented, or reading the source -code for these modules. - -\begin{funcdesc}{run}{string\optional{, filename\optional{, ...}}} - -This function takes a single argument that has can be passed to the -\keyword{exec} statement, and an optional file name. In all cases this -routine attempts to \keyword{exec} its first argument, and gather profiling -statistics from the execution. If no file name is present, then this -function automatically prints a simple profiling report, sorted by the -standard name string (file/line/function-name) that is presented in -each line. The following is a typical output from such a call: - -\begin{verbatim} - main() - 2706 function calls (2004 primitive calls) in 4.504 CPU seconds - -Ordered by: standard name - -ncalls tottime percall cumtime percall filename:lineno(function) - 2 0.006 0.003 0.953 0.477 pobject.py:75(save_objects) - 43/3 0.533 0.012 0.749 0.250 pobject.py:99(evaluate) - ... -\end{verbatim} - -The first line indicates that this profile was generated by the call:\\ -\code{profile.run('main()')}, and hence the exec'ed string is -\code{'main()'}. The second line indicates that 2706 calls were -monitored. Of those calls, 2004 were \dfn{primitive}. We define -\dfn{primitive} to mean that the call was not induced via recursion. -The next line: \code{Ordered by:\ standard name}, indicates that -the text string in the far right column was used to sort the output. -The column headings include: - -\begin{description} - -\item[ncalls ] -for the number of calls, - -\item[tottime ] -for the total time spent in the given function (and excluding time -made in calls to sub-functions), - -\item[percall ] -is the quotient of \code{tottime} divided by \code{ncalls} - -\item[cumtime ] -is the total time spent in this and all subfunctions (i.e., from -invocation till exit). This figure is accurate \emph{even} for recursive -functions. - -\item[percall ] -is the quotient of \code{cumtime} divided by primitive calls - -\item[filename:lineno(function) ] -provides the respective data of each function - -\end{description} - -When there are two numbers in the first column (e.g.: \samp{43/3}), -then the latter is the number of primitive calls, and the former is -the actual number of calls. Note that when the function does not -recurse, these two values are the same, and only the single figure is -printed. - -\end{funcdesc} - -Analysis of the profiler data is done using this class from the -\module{pstats} module: - -% now switch modules.... -\stmodindex{pstats} - -\begin{classdesc}{Stats}{filename\optional{, ...}} -This class constructor creates an instance of a ``statistics object'' -from a \var{filename} (or set of filenames). \class{Stats} objects are -manipulated by methods, in order to print useful reports. - -The file selected by the above constructor must have been created by -the corresponding version of \module{profile}. To be specific, there is -\emph{no} file compatibility guaranteed with future versions of this -profiler, and there is no compatibility with files produced by other -profilers (e.g., the old system profiler). - -If several files are provided, all the statistics for identical -functions will be coalesced, so that an overall view of several -processes can be considered in a single report. If additional files -need to be combined with data in an existing \class{Stats} object, the -\method{add()} method can be used. -\end{classdesc} - - -\subsection{The \module{Stats} Class} - -\setindexsubitem{(Stats method)} - -\begin{methoddesc}{strip_dirs}{} -This method for the \class{Stats} class removes all leading path -information from file names. It is very useful in reducing the size -of the printout to fit within (close to) 80 columns. This method -modifies the object, and the stripped information is lost. After -performing a strip operation, the object is considered to have its -entries in a ``random'' order, as it was just after object -initialization and loading. If \method{strip_dirs()} causes two -function names to be indistinguishable (i.e., they are on the same -line of the same filename, and have the same function name), then the -statistics for these two entries are accumulated into a single entry. -\end{methoddesc} - - -\begin{methoddesc}{add}{filename\optional{, ...}} -This method of the \class{Stats} class accumulates additional -profiling information into the current profiling object. Its -arguments should refer to filenames created by the corresponding -version of \function{profile.run()}. Statistics for identically named -(re: file, line, name) functions are automatically accumulated into -single function statistics. -\end{methoddesc} - -\begin{methoddesc}{sort_stats}{key\optional{, ...}} -This method modifies the \class{Stats} object by sorting it according -to the supplied criteria. The argument is typically a string -identifying the basis of a sort (example: \code{'time'} or -\code{'name'}). - -When more than one key is provided, then additional keys are used as -secondary criteria when the there is equality in all keys selected -before them. For example, \samp{sort_stats('name', 'file')} will sort -all the entries according to their function name, and resolve all ties -(identical function names) by sorting by file name. - -Abbreviations can be used for any key names, as long as the -abbreviation is unambiguous. The following are the keys currently -defined: - -\begin{tableii}{l|l}{code}{Valid Arg}{Meaning} - \lineii{'calls'}{call count} - \lineii{'cumulative'}{cumulative time} - \lineii{'file'}{file name} - \lineii{'module'}{file name} - \lineii{'pcalls'}{primitive call count} - \lineii{'line'}{line number} - \lineii{'name'}{function name} - \lineii{'nfl'}{name/file/line} - \lineii{'stdname'}{standard name} - \lineii{'time'}{internal time} -\end{tableii} - -Note that all sorts on statistics are in descending order (placing -most time consuming items first), where as name, file, and line number -searches are in ascending order (i.e., alphabetical). The subtle -distinction between \code{'nfl'} and \code{'stdname'} is that the -standard name is a sort of the name as printed, which means that the -embedded line numbers get compared in an odd way. For example, lines -3, 20, and 40 would (if the file names were the same) appear in the -string order 20, 3 and 40. In contrast, \code{'nfl'} does a numeric -compare of the line numbers. In fact, \code{sort_stats('nfl')} is the -same as \code{sort_stats('name', 'file', 'line')}. - -For compatibility with the old profiler, the numeric arguments -\code{-1}, \code{0}, \code{1}, and \code{2} are permitted. They are -interpreted as \code{'stdname'}, \code{'calls'}, \code{'time'}, and -\code{'cumulative'} respectively. If this old style format (numeric) -is used, only one sort key (the numeric key) will be used, and -additional arguments will be silently ignored. -\end{methoddesc} - - -\begin{methoddesc}{reverse_order}{} -This method for the \class{Stats} class reverses the ordering of the basic -list within the object. This method is provided primarily for -compatibility with the old profiler. Its utility is questionable -now that ascending vs descending order is properly selected based on -the sort key of choice. -\end{methoddesc} - -\begin{methoddesc}{print_stats}{restriction\optional{, ...}} -This method for the \class{Stats} class prints out a report as described -in the \function{profile.run()} definition. - -The order of the printing is based on the last \method{sort_stats()} -operation done on the object (subject to caveats in \method{add()} and -\method{strip_dirs()}. - -The arguments provided (if any) can be used to limit the list down to -the significant entries. Initially, the list is taken to be the -complete set of profiled functions. Each restriction is either an -integer (to select a count of lines), or a decimal fraction between -0.0 and 1.0 inclusive (to select a percentage of lines), or a regular -expression (to pattern match the standard name that is printed; as of -Python 1.5b1, this uses the Perl-style regular expression syntax -defined by the \module{re} module). If several restrictions are -provided, then they are applied sequentially. For example: - -\begin{verbatim} -print_stats(.1, 'foo:') -\end{verbatim} - -would first limit the printing to first 10\% of list, and then only -print functions that were part of filename \samp{.*foo:}. In -contrast, the command: - -\begin{verbatim} -print_stats('foo:', .1) -\end{verbatim} - -would limit the list to all functions having file names \samp{.*foo:}, -and then proceed to only print the first 10\% of them. -\end{methoddesc} - - -\begin{methoddesc}{print_callers}{restrictions\optional{, ...}} -This method for the \class{Stats} class prints a list of all functions -that called each function in the profiled database. The ordering is -identical to that provided by \method{print_stats()}, and the definition -of the restricting argument is also identical. For convenience, a -number is shown in parentheses after each caller to show how many -times this specific call was made. A second non-parenthesized number -is the cumulative time spent in the function at the right. -\end{methoddesc} - -\begin{methoddesc}{print_callees}{restrictions\optional{, ...}} -This method for the \class{Stats} class prints a list of all function -that were called by the indicated function. Aside from this reversal -of direction of calls (re: called vs was called by), the arguments and -ordering are identical to the \method{print_callers()} method. -\end{methoddesc} - -\begin{methoddesc}{ignore}{} -\deprecated{1.5.1}{This is not needed in modern versions of Python.% -\footnote{ -This was once necessary, when Python would print any unused expression -result that was not \code{None}. The method is still defined for -backward compatibility. -}} -\end{methoddesc} - - -\section{Limitations} - -There are two fundamental limitations on this profiler. The first is -that it relies on the Python interpreter to dispatch \dfn{call}, -\dfn{return}, and \dfn{exception} events. Compiled \C{} code does not -get interpreted, and hence is ``invisible'' to the profiler. All time -spent in \C{} code (including built-in functions) will be charged to the -Python function that invoked the \C{} code. If the \C{} code calls out -to some native Python code, then those calls will be profiled -properly. - -The second limitation has to do with accuracy of timing information. -There is a fundamental problem with deterministic profilers involving -accuracy. The most obvious restriction is that the underlying ``clock'' -is only ticking at a rate (typically) of about .001 seconds. Hence no -measurements will be more accurate that that underlying clock. If -enough measurements are taken, then the ``error'' will tend to average -out. Unfortunately, removing this first error induces a second source -of error... - -The second problem is that it ``takes a while'' from when an event is -dispatched until the profiler's call to get the time actually -\emph{gets} the state of the clock. Similarly, there is a certain lag -when exiting the profiler event handler from the time that the clock's -value was obtained (and then squirreled away), until the user's code -is once again executing. As a result, functions that are called many -times, or call many functions, will typically accumulate this error. -The error that accumulates in this fashion is typically less than the -accuracy of the clock (i.e., less than one clock tick), but it -\emph{can} accumulate and become very significant. This profiler -provides a means of calibrating itself for a given platform so that -this error can be probabilistically (i.e., on the average) removed. -After the profiler is calibrated, it will be more accurate (in a least -square sense), but it will sometimes produce negative numbers (when -call counts are exceptionally low, and the gods of probability work -against you :-). ) Do \emph{NOT} be alarmed by negative numbers in -the profile. They should \emph{only} appear if you have calibrated -your profiler, and the results are actually better than without -calibration. - - -\section{Calibration} - -The profiler class has a hard coded constant that is added to each -event handling time to compensate for the overhead of calling the time -function, and socking away the results. The following procedure can -be used to obtain this constant for a given platform (see discussion -in section Limitations above). - -\begin{verbatim} -import profile -pr = profile.Profile() -print pr.calibrate(100) -print pr.calibrate(100) -print pr.calibrate(100) -\end{verbatim} - -The argument to \method{calibrate()} is the number of times to try to -do the sample calls to get the CPU times. If your computer is -\emph{very} fast, you might have to do: - -\begin{verbatim} -pr.calibrate(1000) -\end{verbatim} - -or even: - -\begin{verbatim} -pr.calibrate(10000) -\end{verbatim} - -The object of this exercise is to get a fairly consistent result. -When you have a consistent answer, you are ready to use that number in -the source code. For a Sun Sparcstation 1000 running Solaris 2.3, the -magical number is about .00053. If you have a choice, you are better -off with a smaller constant, and your results will ``less often'' show -up as negative in profile statistics. - -The following shows how the trace_dispatch() method in the Profile -class should be modified to install the calibration constant on a Sun -Sparcstation 1000: - -\begin{verbatim} -def trace_dispatch(self, frame, event, arg): - t = self.timer() - 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 -\end{verbatim} - -Note that if there is no calibration constant, then the line -containing the callibration constant should simply say: - -\begin{verbatim} -t = t[0] + t[1] - self.t # no calibration constant -\end{verbatim} - -You can also achieve the same results using a derived class (and the -profiler will actually run equally fast!!), but the above method is -the simplest to use. I could have made the profiler ``self -calibrating'', but it would have made the initialization of the -profiler class slower, and would have required some \emph{very} fancy -coding, or else the use of a variable where the constant \samp{.00053} -was placed in the code shown. This is a \strong{VERY} critical -performance section, and there is no reason to use a variable lookup -at this point, when a constant can be used. - - -\section{Extensions --- Deriving Better Profilers} -\nodename{Profiler Extensions} - -The \class{Profile} class of module \module{profile} was written so that -derived classes could be developed to extend the profiler. Rather -than describing all the details of such an effort, I'll just present -the following two examples of derived classes that can be used to do -profiling. If the reader is an avid Python programmer, then it should -be possible to use these as a model and create similar (and perchance -better) profile classes. - -If all you want to do is change how the timer is called, or which -timer function is used, then the basic class has an option for that in -the constructor for the class. Consider passing the name of a -function to call into the constructor: - -\begin{verbatim} -pr = profile.Profile(your_time_func) -\end{verbatim} - -The resulting profiler will call \code{your_time_func()} instead of -\function{os.times()}. The function should return either a single number -or a list of numbers (like what \function{os.times()} returns). If the -function returns a single time number, or the list of returned numbers -has length 2, then you will get an especially fast version of the -dispatch routine. - -Be warned that you \emph{should} calibrate the profiler class for the -timer function that you choose. For most machines, a timer that -returns a lone integer value will provide the best results in terms of -low overhead during profiling. (\function{os.times()} is -\emph{pretty} bad, 'cause it returns a tuple of floating point values, -so all arithmetic is floating point in the profiler!). If you want to -substitute a better timer in the cleanest fashion, you should derive a -class, and simply put in the replacement dispatch method that better -handles your timer call, along with the appropriate calibration -constant :-). - - -\subsection{OldProfile Class} - -The following derived profiler simulates the old style profiler, -providing errant results on recursive functions. The reason for the -usefulness of this profiler is that it runs faster (i.e., less -overhead) than the old profiler. It still creates all the caller -stats, and is quite useful when there is \emph{no} recursion in the -user's code. It is also a lot more accurate than the old profiler, as -it does not charge all its overhead time to the user's code. - -\begin{verbatim} -class OldProfile(Profile): - - def trace_dispatch_exception(self, frame, t): - rt, rtt, rct, rfn, rframe, rcur = self.cur - if rcur and not rframe is frame: - return self.trace_dispatch_return(rframe, t) - return 0 - - def trace_dispatch_call(self, frame, t): - fn = `frame.f_code` - - self.cur = (t, 0, 0, fn, frame, self.cur) - if self.timings.has_key(fn): - tt, ct, callers = self.timings[fn] - self.timings[fn] = tt, ct, callers - else: - self.timings[fn] = 0, 0, {} - return 1 - - def trace_dispatch_return(self, frame, t): - 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 - - tt, ct, callers = self.timings[rfn] - if callers.has_key(pfn): - callers[pfn] = callers[pfn] + 1 - else: - callers[pfn] = 1 - self.timings[rfn] = tt+rtt, ct + sft, callers - - return 1 - - - def snapshot_stats(self): - self.stats = {} - for func in self.timings.keys(): - tt, ct, callers = self.timings[func] - nor_func = self.func_normalize(func) - nor_callers = {} - nc = 0 - for func_caller in callers.keys(): - nor_callers[self.func_normalize(func_caller)] = \ - callers[func_caller] - nc = nc + callers[func_caller] - self.stats[nor_func] = nc, nc, tt, ct, nor_callers -\end{verbatim} - -\subsection{HotProfile Class} - -This profiler is the fastest derived profile example. It does not -calculate caller-callee relationships, and does not calculate -cumulative time under a function. It only calculates time spent in a -function, so it runs very quickly (re: very low overhead). In truth, -the basic profiler is so fast, that is probably not worth the savings -to give up the data, but this class still provides a nice example. - -\begin{verbatim} -class HotProfile(Profile): - - def trace_dispatch_exception(self, frame, t): - rt, rtt, rfn, rframe, rcur = self.cur - if rcur and not rframe is frame: - return self.trace_dispatch_return(rframe, t) - return 0 - - def trace_dispatch_call(self, frame, t): - self.cur = (t, 0, frame, self.cur) - return 1 - - def trace_dispatch_return(self, frame, t): - rt, rtt, frame, rcur = self.cur - - rfn = `frame.f_code` - - pt, ptt, pframe, pcur = rcur - self.cur = pt, ptt+rt, pframe, pcur - - if self.timings.has_key(rfn): - nc, tt = self.timings[rfn] - self.timings[rfn] = nc + 1, rt + rtt + tt - else: - self.timings[rfn] = 1, rt + rtt - - return 1 - - - def snapshot_stats(self): - self.stats = {} - for func in self.timings.keys(): - nc, tt = self.timings[func] - nor_func = self.func_normalize(func) - self.stats[nor_func] = nc, nc, tt, 0, {} -\end{verbatim} |