|
Allegro CL version 11.0 |
function, profiler package
Arguments:
This function stops a currently running profile and deletes all associated data, or deletes any unsaved current profile data if the profiler has been stopped. It is unusual to call this function. An example of when it might be useful is when an error occurs while code is being profiled so you find yourself profiling your debugging rather than the code of interest.
Specifically this function does the following:
If there is a profile running and collecting data, prof:cancel-current-profile stops data collection and deletes all collected profile data (including deleting all associated temporary files if any). Because all collected data is deleted, it is not necessary to stop the profiler with prof:stop-profiler and no analysis (with prof:show-call-graph or prof:show-flat-profile) can be done.
If the profiler has run but has stopped collecting data (perhaps with prof:stop-profiler) but no analysis (with prof:show-call-graph or prof:show-flat-profile) has yet been done, calling prof:cancel-current-profile deletes all collected profile data so there is no longer any data to analyze.
If the profiler has collected data and that data has been analyzed (with prof:show-call-graph or prof:show-flat-profile) but the data has not been saved, calling prof:cancel-current-profile deletes all current profile data so further analysis is not possible.
If the profiler is not running and the data from the previous run, if any, has been saved (with, say, save-named-profile), calling prof:cancel-current-profile effectively does nothing.
prof:cancel-current-profile does not affect profile data saved with save-named-profile.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: name
Deletes the profile named name and returns true if it existed. If a profile named name does not exist, nothing is done and nil
is returned.
See runtime-analizer.html for general information on profiling and the runtime analyzer.
function, profiler package
Arguments: name &key profile verbose start end current-profile
Use of this function is deprecated. While it still works as described, users should instead use disassemble which has been enhanced with a :profile argument.
There is an example using cl:disassemble to see profile data in the section A disassembly with profiling example in runtime-analizer.html.
This function prints to *standard-output* a disassembly of the function denoted by name. In the disassembly, each instruction is annotated with actual hits on that instruction, plus a percentage of the total hits in the function. Since the hits are from a statistical sampling, an estimate can be made as to where in the function time is being spent (the more hits, the better the estimate).
A hit that occurs just after (we define just after for various platforms below) an instruction that does a call probably means that the function was not itself executing but had called another function at the time of the hit. A hit that occurs any other place means the function was actually executing at the time.
By just after above, we mean different things for different architectures:
On Windows, the hit is on the instruction after the jsr, call, or bctrl instruction, respectively.
On Sparcs, the hit occurs exactly at the jmpl instruction.
name must evaluate to a symbol or a compiled function object or a string. A symbol or compiled function object identifies a Lisp function. A string identifies a C function. The disassembler will disassemble C functions on most platforms. Note that you must use the string that appears in a runtime analyzer output (such as a call graph or a flat profile).
The profile keyword argument specifies the profile to examine. Its value must be a name of a profile (see save-named-profile) or a profile object (see find-named-profile). The value :current
is also accepted and is the default. It indicates the current profile (the most recent run and stopped but not saved and named profile).
The verbose keyword argument controls whether or not messages about the progress of the analysis are printed to *standard-output*. The messages will be printed if the value is true and they will not be printed if the value is nil
. The value defaults to nil
. (Note that in the default, both the messages and the result are printed to *standard-output* so if you rebind *standard-output* to be a stream open to a file, the messages will be printed to the file as well.)
The start and end keyword arguments are passed to disassemble. Allegro CL enhances cl:disassemble by adding these arguments, which resemble the start and end arguments to sequence functions. Both values, if specified, should be non-negative integers indicating the pc-offset where printing of disassembled code should start and stop, but there are many details. See the description of the Allegro CL implementation of disassemble in implementation.html.
Use of the current-profile keyword argument is deprecated and will cause a warning to be signaled. User profile instead. If supplied, its value must be a profile saved by save-named-profile (profiles saved by the deprecated function save-current-profile will also work).
This function returns nil
.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: name
Returns a profile named name, if available, otherwise returns nil
. If name is :current
, then the current profile is returned, but only if the profile is already analyzed (by, say, applying show-flat-profile or prof:show-call-graph).
See runtime-analizer.html for general information on profiling and the runtime analyzer.
function, profiler package
Arguments: &key profile current-profile
Returns an alist of all functions that have been counted along with their call counts, sorted in descending order of counts.
The profile keyword argument specifies the profile to examine. Its value must be a name of a profile (see save-named-profile) or a profile object (see find-named-profile). The value :current
is also accepted and is the default. It indicates the current profile (the most recent run and stopped profile).
Use of the current-profile keyword argument is deprecated and will cause a warning to be signaled. Use profile instead. If supplied, its value must be a profile saved by save-named-profile or the name of such a profile (see find-named-profile). Profiles saved by the deprecated function save-current-profile will also work).
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: &key verbose profile current-profile
This function will print to *standard-output* the status of the current data collection. If the runtime analysis was invoked with the with-profiling macro, the form to be analyzed is also printed.
This function returns one of the following possible values:
The profile keyword argument specifies the profile to examine. Its value must be a name of a profile (see save-named-profile) or a profile object (see find-named-profile). The value :current
is also accepted and is the default. It indicates the current profile (the most recent run and stopped but not saved and named profile).
Use of the current-profile keyword argument is deprecated and will cause a warning to be signaled. Use profile instead. If supplied, its value must be a profile saved by save-named-profile or the name of such a profile (see find-named-profile). Profiles saved by the deprecated function save-current-profile will also work).
The verbose keyword argument, if true (default is t
), causes additional information about runtime analysis to be printed. If you specify it as nil
, only the appropriate keyword (from the list above) is returned and nothing additional is printed.
A finalized analysis (profiler-status returns :analyzed
) can be saved using save-named-profile.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments:
This function returns nil
after resetting to their initial values the values of the following runtime analyzer display control variables:
reset-profiler-display-defaults does not modify the value of *outline-max-indentation*.
The related function show-all sets those variables to zero or nil
(as appropriate) so that all profile data is displayed by functions like show-flat-profile and prof:show-call-graph. That function and the one described on this page basically toggle between showing all data and the default subset of data.
See runtime-analizer.html for general information on the runtime analyzer.
macro, profiler package
Arguments: variable
Use of this function is deprecated. Use save-named-profile instead.
This macro saves the contents of the current runtime analysis into the named variable (which is not evaluated). A runtime analysis must be in the :analyzed
state (as returned by profiler-status) to be saved.
profiler-status returns :analyzed
after prof:show-call-graph or show-flat-profile have been run at least once on collected data. The following results in data being saved and made the value of the symbol foo:
(prof:with-profiling (:type :time) <forms>)
(prof:show-flat-profile)
(prof:save-current-profile foo)
Saving a runtime analysis with save-current-profile allows you to analyze the data at your leisure, running other analyses in the meantime. The keyword argument current-profile to show-call-graph and show-flat-profile can take a saved analysis instead of the default (which is the currently running or last run analysis) and display results using that profile.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: name
Returns the current profile after saving it with the name name. The profile can be saved (and thus named) while running (you are asked if you want the profile stopped and if you answer y
it is stopped). If the profile is already stopped, it is saved. It is not necessary to analyze the profile (with, say, show-call-graph or show-flat-profile) before saving a stopped profile.
cl-user(3): (prof:start-profiler)
:sampling
cl-user(4): (dotimes (i 10000) (* i i))
nil
;; Trying to save a profile while a profile has been started
;; and not stopped will cause the user to be asked what should
;; be done:
;;
cl-user(5): (prof:save-named-profile 'foo)
The previous time profile is still in progress. Do you want to stop
it? [y or n] n
;;
;; 'n' means do not abort the running profile
;;
The time profiler is currently running. Thus, a new profile was not
initiated.
Warning: The current profile has not been saved.
nil
;; This time we do abort the running profile:
;;
cl-user(6): (prof:save-named-profile 'foo)
The previous time profile is still in progress. Do you want to stop
it? [y or n] y
#<time profile foo>
cl-user(7): (prof:find-named-profile 'foo)
#<time profile foo>
t
;; Once a profile is stopped and saved, there is no :current profile:
;;
cl-user(8): (prof:find-named-profile :current)
nil
cl-user(9): (prof:start-profiler)
:sampling
cl-user(10): (dotimes (i 10000) (* i i))
nil
cl-user(11): (prof:stop-profiler)
:saved
;;
;; The just stopped profile is the :current profile.
;;
cl-user(12): (prof:find-named-profile :current)
#<time profile current>
;; We can save it with a name ('bar' in this case):
;;
cl-user(13): (prof:save-named-profile 'bar)
#<time profile bar>
;; Here is its status. In this simple example intended to show
;; functions being used, not real profile information was collected.
;;
cl-user(14): (prof:profiler-status :profile (prof:find-named-profile 'bar))
Named profile bar:
The time profiler is stopped and 1 samples were collected.
Use profiler:show-flat-profile, profiler:show-call-graph,
profiler:disassemble-profile or, if you are running the IDE, select the menu
item Run/Runtime Analyzer Results Dialog to see the results.
cl-user(15): (prof:show-flat-profile)
Sampling stopped after 1 samples taken for the time profiler.
Sample represents .0 seconds of user+system CPU time.
Times below 1.0% will be suppressed.
% % self total self total Function
Time Cum. secs secs calls ms/call ms/call name
100.0 100.0 0.0 0.0 ... dotimes
;; Functions like PROF:SHOW-FLAT-PROFILE, SHOW-CALL-GRAPH
;; and CL:DISASSEMBLE will find a profile when a name is supplied
;; as the value of the :PROFILE argument. At the beginning of this
;; example, we saved a profile named FOO:
;;
cl-user(16): (prof:show-flat-profile :profile 'foo)
Sampling stopped after 1 samples taken for the time profiler.
Sample represents .0 seconds of user+system CPU time.
Times below 1.0% will be suppressed.
% % self total self total Function
Time Cum. secs secs calls ms/call ms/call name
100.0 100.0 0.0 0.0 "sigprocmask"
cl-user(17):
See runtime-analizer.html for general information on profiling and the runtime analyzer.
function, profiler package
Arguments:
This function returns zero after setting the following runtime analyzer display control variables to the values indicated:
nil
.nil
.nil
.show-all does not modify the value of *outline-max-indentation*.
The related function reset-profiler-display-defaults sets those variables to their initial (default) values so data about operators and packages that are perhaps not of interest and data about operators that took very little actual time are suppressed in the output of functions like show-flat-profile and show-call-graph. That function and the one described on this page basically toggle between showing the default subset of data and all data.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: &key profile count current-profile
Prints (to *standard-output*) the top count functions and their call-counts from the runtime analysis specified by the profile keyword argument. count defaults to 50.
The profile keyword argument specifies the profile to examine. Its value must be a name of a profile (see save-named-profile) or a profile object (see find-named-profile). The value :current
is also accepted and is the default. It indicates the current profile (the most recent run and stopped but not saved and named profile).
Use of the current-profile keyword argument is deprecated and will cause a warning to be signaled. Use profile instead. save-named-profile (profiles saved by the deprecated function save-current-profile will also work).
See also list-call-counts.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: &key name stream profile verbose current-profile
This function prints a call-graph for the profile data collected to the stream specified by the stream keyword argument. The default value of the :stream argument is standard-output.
The name keyword argument, if provided, specifies the function for which information is requested. If the name keyword argument is not specified or is specified nil
, information on all functions will be printed. The value of the name keyword argument should be a symbol (that is the argument must evaluate to a symbol) or a compiled function object if you want information on a Lisp function. The value should be a string if you want information on a C function or a Lisp runtime system function.
The profile keyword argument specifies the profile to examine. Its value must be a name of a profile (see save-named-profile) or a profile object (see find-named-profile). The value :current
is also accepted and is the default. It indicates the current profile (the most recent run and stopped but not yet saved and named profile).
The verbose keyword argument controls whether or not messages about the progress of the analysis are printed to standard-output. The messages will be printed if the value is true and they will not be printed if the value is nil
. The value defaults to nil
. (Note that in the default, both the messages and the result are printed to standard-output so if you rebind standard-output to be a stream open to a file, the messages will be printed to the file as well.)
Use of the current-profile keyword argument is deprecated and will cause a warning to be signaled. Use profile instead. If supplied, its value must be a profile saved by save-named-profile or the name of such a profile (see find-named-profile). Profiles saved by the deprecated function save-current-profile will also work).
This function returns no value.
If the profiler is still running when this function is called, then profiling will be stopped and analysis and display of the results will occur. The status of that profile (as returned by profiler-status) will then be :analyzed
.
See runtime-analizer.html for general information on profiling and the runtime analyzer.
function, profiler package
Arguments: &key stream profile verbose current-profile
This function prints a flat analysis based on the most recently collected runtime analyzer data to the output stream specified by the stream keyword argument. The default value of the stream keyword argument is *standard-output*.
The profile keyword argument specifies the profile to examine. Its value must be a name of a profile (see save-named-profile) or a profile object (see find-named-profile). The value :current
is also accepted and is the default. It indicates the current profile (the most recent run and stopped but not saved and named profile).
The verbose keyword argument controls whether or not messages about the progress of the analysis are printed to standard-output. The messages will be printed if the value is true and they will not be printed if the value is nil
. The value defaults to nil
. (Note that in the default, both the messages and the result are printed to standard-output so if you rebind standard-output to be a stream open to a file, the messages will be printed to the file as well.)
Use of the current-profile keyword argument is deprecated and will cause a warning to be signaled. User profile instead. If supplied, its value must be a profile saved by save-named-profile or the name of such a profile (see find-named-profile). Profiles saved by the deprecated function save-current-profile will also work).
This function returns no value.
If data is still being collected when this function is called, data collection will be stopped, then analysis and display of the results will occur. After show-flat-profile has been applied to the data, the status of that runtime analysis (as returned by profiler-status) becomes :analyzed
if it was not already in that state.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: &key name stream profile verbose
This function returns no value.
Called for side-effect, this function produces a raw outline view of the selected profile and prints it to the stream (defaulting to *standard-output*). The profile defaults to the current profile, and can be specified as either a profile object or the name of a named-profile.
The name keyword argument, if provided, specifies the function for which information is requested. If the name keyword argument is not specified or is specified nil
, information on all functions will be printed. The value of the name keyword argument can be a symbol or a compiled function object if you want information on a Lisp function. The value can also be a string if you want information on a C function or a Lisp runtime system function. The value can also be an integer which corresponds to a sequence number as described next.
Before the first call to this function, nodes in the profile graph have identity and names, but are not sequenced. Whenever this function is called and produces an outline, the nodes are sequenced, beginning at 0 for the selected node (or a dummy node named "start" if no node is selected) and continuing downward to all selected child nodes recursively in a directed tree graph with no cycles. A node is selected based on whether its usage is above the *significance-threshold* or not - if the node falls below that threshold, it is not selected nor is it counted.
The outline is printed one node per line, in an indented format that makes it easy to see the node hierarchy. The indentation mostly consists of spaces, to keep the clutter down, but is punctuated with vertical bars, slashes, plus signs, and backslashes to form a visual bracketing mechanism that allows human readability of the hierarchy. There is a complete example here in runtime-analizer.html. We repeat just the outline output so we can discuss what is displayed.
cl-user(6): (prof:show-outline-profile)
100.00 "start" 0
100.00 "cont_setstack" 1
100.00 "startup_lisp" 2
100.00 "start_reborn_lisp" 3
100.00 "first_lisp_thread" 4
100.00 excl::lisp-thread-start 5
100.00 excl::run-initial-thread 6
100.00 excl::setup-required-thread-bindings 7
100.00 excl::thread-reset-catcher 8
100.00 excl::thread-bind-and-call 9
100.00 #<Runtime Function Object (:runsys "lisp_apply")> 10
100.00 excl::start-lisp-execution 11
100.00 tpl:start-interactive-top-level 12
100.00 #<Runtime Function Object (:runsys "lisp_apply")> 13
100.00 tpl:top-level-read-eval-print-loop 14
100.00 tpl::top-level-read-eval-print-loop1 15
100.00 excl::read-eval-print-loop 16
100.00 tpl::read-eval-print-one-command 17
100.00 eval 18
100.00 (:anonymous-lambda 17) 19
100.00 prof::prof-a-funcall 20
100.00 (:internal (:anonymous-lambda 17) 0) 21
100.00 foo 22
/37.10 bam 23
| 17.76 excl::*_2op 24
+27.69 #<Runtime Function Object (:runsys "lisp_apply")> 25
|/9.78 bar 26
|| 6.55 excl::*_2op 27
|\1.35 "funcall_check" 28
\20.62 bas 29
11.89 excl::*_2op 30
On each line three fields are printed:
The total weight of this node. Note that this is not the same as the total weight of all nodes with this same function, but is instead the total weight (including children) of this particular instance of the function within the profile tree. The weight of the node will always include all time spent in a single invocation of the node's function, but it may also include time spent in multiple calls to the same function, if at the time of the hit the stack looks the same to the profiler (there is no way to tell the difference in this case).
The node's name. It may be a function spec (a symbol or a list) which represents the name of the function, or a string, which represents a C or runsys entry point. The printing of the name is controlled by print-escape - when true, package names are printed for fspecs and strings are delimited with double-quotes, and when nil space is saved by not printing package names or string quotes.
The sequence number. This is a temporary integer assigned to the node in ascending order (after the children in the tree are sorted in descending order of weight), and this integer can be used to identify the node in any functions that accept a name argument (e.g. this function itself, show-call-graph, disassemble, disassemble-profile, and print-function-meta-info. Note that whenever this function is called the tree graph is re-sequenced, so if the name argument is specified with any non-zero positive integer, its node will become the new root of the outline and will start at 0. See the end of the example here in runtime-analizer.html where it shows how using a stale sequence number results in an error.
Not all nodes are necessarily printed. If the hierarchy goes too deep, and the columns extend too far to the right, some nodes (lines) will be elided, and a message will be printed to that effect. The maximum number of columns indented is controlled by the variable *outline-max-indentation* - if a line must be indented farther than that value it is elided. Note that the indentation limit does not control the maximum line length directly; names are never cut off and thus may run arbitrarily long in the outline output.
Note in the example above that nodes sequenced from 22 (bam) through 29 (bas) have some markings prior to the total weight field of each line. These markings form connections between callees of particular callers. Looking at one in particular, which roughly looks like this:
foo
/ bam
|
+ "lisp_apply"
|
|
|
\ bas
This ASCII art is meant to bracket all callees of foo, which has sequence 22. The callees are bam (which is just after the /
), the "lisp_apply" runsys function (which is just after the +
), and bas (just after the \
). Bracketing is not used when there is only one callee. The inner bracketing in the example is one which calls out the two callees of the "lisp_apply" runsys function: bar and "funcall_check". Note that excl::*_2op is the only callee of bar, and thus does not have any bracketing annotation.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: &key type start-sampling-p count count-list except-processes interpret-closures verbose
This function starts the collection of runtime analyzer data. Data collection is stopped with a call to stop-profiler. The macro with-profiling wraps its body in a call to start-profiler at the start and a call to stop-profiler at the end.
If there is an unsaved, unanalyzed profile, you are asked by start-profiler if you want to save or discard that profile before proceeding with the new profile. You can cancel (delete) the current profile and all associated data with cancel-current-profile (you might do this if, for example, an unexpected error occurred in the code you are profiling), save it with save-named-profile, or analyze it with show-flat-profile or show-call-graph. Once any of these actions are taken, start-profiler will start without interruption, but note further analysis of the old profile data is not possible unless it was saved first.
When started, the runtime analyzer creates two new files in a temporary location for saving sample data and initializes the runtime analyzer data structures. These files are removed after analysis. See Further points, including information on temporary files in runtime-analizer.html.
The type keyword argument specifies the type of profile data to be collected. The choices are
:time
: collect CPU time data (but not space data):real-time
: collect real time data (but not space data):space
: collect space data (but not time data):count-only
: collect call-count data but no time or space dataYou can collect either time data or space data but not both in a single run, but you can have call-counting data collected while collecting either time or space data. Or you can have call-counting data only collected. So the choices are:
time only: type should be :time
or :real-time
and both count and count-list should be nil
or unspecified.
time and call-counting: type should be :time
or :real-time
and either count or count-list (or both) should be non-nil
. (Appropriate non-nil
values of count and count-list are given below.)
space only: type should be :space
and both count and count-list should be nil
or unspecified.
space and call-counting: type should be :space
and either count or count-list (or both) should be non-nil
. (Appropriate non-nil
values of count and count-list are given below.)
call-counting only: type should be :count-only
and either count or count-list (or both) should be non-nil
. (Appropriate non-nil
values of count and count-list are given below.)
If no value is specified for type, it defaults to :count-only
if either count or count-list (or both) are non-nil
and it defaults to :time
if both count or count-list are nil
or unspecified.
The count and count-list arguments control whether call-counting information should be collected during the run. Call count information is collected if either argument is true. Both default to nil
.
count can be a positive integer or t. If it is a positive integer, a hash table with that many entries is created. If it is t, a hash table of 1000 entries is created. The table is filled with function objects specified by count-list, if any. New function objects (beyond what is specified in count-list) are added to the table as the associated function is called until the table is filled. No information is collected on function objects called for the first time after the table is filled.
count-list, if specified, should be a list of function objects (not symbols -- thus elements should be #'foo rather than foo). The hash table mentioned in the description of count just above is filled with the elements of count-list, in order, until the hash table is filled or the list is exhausted. Specifying a value for this variable ensures that functions you are interested in are call-counted. Note that if the length of the list is greater than the value of count, only the first count elements are entered in the hash table; the rest are ignored. If count-list has a true value but no value is specified for count, count defaults to 1000 (even if the length of count-list is greater than 1000).
If the start-sampling-p keyword argument is true or is not supplied then sampling is started immediately. If it is specified nil
, sampling is not started until start-sampling is called. The functions start-sampling and stop-sampling can be used to control the gathering of samples while the runtime analyzer is running. The default value of this argument is t.
The except-processes keyword argument should be a list of processes or nil
. This argument causes the runtime analyzer to not record data about the processes listed in this argument. Use of this argument is a good way to narrow down the extent of an analysis, if multiprocessing is being used. (In earlier releases, there was an except-stack-groups argument, which applied to certain platforms. That argument is no longer supported and a value provided for it is assumed to be a value for except-processes. A warning is signaled if except-stack-groups is specified.)
The interpret-closures argument controls the handling of closures. When interpret-closures is nil
(the default) the closures are not saved and analyzed separately. When true, closures are saved and analyzed as separate profile entries, even though they may use the same template function. A function specialization called prof:closure
has been added. This is valid whenever an analyzed profile exists and identifies the closures which the runtime analyzer has seen.
The specialization is (prof:closure n)
where n is a small integer enumerating the closures in the profile. This allows the user to grab the closure object and to do a disassemble on it without having to know what symbol holds its fdefinition
(which is sometimes very hard). The Allegro CL implementation of disassemble is described in disassemble in implementation.html. The profile argument, when specified, causes profiling information to be included in the disassembly.
When flat analyses and call-graphs are reported, closures are identified by (prof:closure n)
, followed by the printed representation of the closure object itself.
Note that if you use the Emacs-Lisp interface or the IDE (on Windows), you are using multiprocessing. The :processes top-level command lists active processes. The Process Browser in Allegro Composer (on UNIX) and the one displayed with View | Processes in the IDE (on Windows) also list processes and provide a graphic interface to include or exclude a process from profiling.
The verbose argument, if true (default is nil
), causes messages about what the profiler is doing to be printed to *standard-output* during data collection.
Data can be collected for only one analysis at a time. Calling this function while data is already being collected will signal an error.
A CPU time profile takes samples while the program is running and bases its results on the CPU time used during the profile. A real time profile takes samples whether or not the program is consuming CPU time. The difference can be seen by profiling a call to sleep. The CPU time profile records nothing (no hits -- some runs may have a hit or two) since almost no CPU time was used. The real time profiler recorded the full 20 seconds.
cl-user(2): (prof:with-profiling (:type :time)
(dotimes (i 10) (sleep 2)))
nil
cl-user(3): (prof:show-flat-profile)
No samples have been collected for the specified time profiler.
cl-user(4): (prof:with-profiling (:type :real-time)
(dotimes (i 10) (sleep 2)))
nil
cl-user(5): (prof:show-flat-profile)
Sampling stopped after 2000 samples taken for the real-time profiler.
Sample represents 20.0 seconds of real time (out of a total of .1).
Real Times below 1.0% will be suppressed.
% % self total self total Function
Real Time Cum. secs secs calls ms/call ms/call name
100.0 100.0 20.0 20.0 "__select"
cl-user(6):
The real time results in non-SMP Lisps are reasonably intuitive. In the example about, sleep is called 10 time for 2 seconds each and the result is roughly 20 seconds total time. In SMP Lisps, the results are more complicated because the total time combines time for all running threads. Consider the following example:
;; This example is run in an SMP Lisp
;;
cl-user(1): (require :smp-utilities)
; Fast loading /net/penn/acl/duane/sacl91/src/code/smp-utilities.fasl
t
cl-user(2): (defvar *bar* (mp:make-barrier 11))
*bar*
cl-user(3): (compile
(defun sleepit ()
(dotimes (i 5) (sleep 2))
(mp:barrier-pass-through *bar*)))
sleepit
nil
nil
cl-user(4): (progn (prof::with-profiling (:type :real-time)
(progn
(dotimes (i 10)
(mp::process-run-function
(format nil "test~d" i) #'sleepit))
(mp::barrier-wait *bar*)))
(prof:show-flat-profile))
Sampling stopped after 10878 samples taken for the real-time profiler.
Sample represents 108.8 seconds of real time (out of a total of 10.0).
Real Times below 1.0% will be suppressed.
% % self total self total Function Real Time Cum. secs secs calls ms/call ms/call name
99.9 99.9 108.7 108.7 "sem_wait"
cl-user(5):
In this case the real-time shown is for the almost 110 seconds spent in the 10 created threads plus the 1 master thread. This is a feature. To be honest, we are not sure this is the best way to do things but the issue of what real time means when multiple processors are being used is a complicated one and this is our current method.
The macro with-profiling starts and stops a profing run while executing the code specified as the body of the macro calling form. See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: &key verbose
If data is not already being collected when this function is called, data collection is started. It is not an error to call this function while data is being collected. It is an error to call this function when the runtime analyzer has not been started (see start-profiler and with-profiling).
The verbose argument, if true (default is nil
), causes status messages to be printed to standard-output during the analysis.
Sampling can be suspended with stop-sampling.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: &key verbose
This function stops runtime analyzer data collection, which was typically started with start-profiler. The macro with-profiling wraps its body with a call to start-profiler at the beginning and a call to stop-profiler at the end.
Once data collection is stopped, no more data can be collected and the data collected can be analyzed. (Do not confuse this function with stop-sampling, which suspends data collection.)
The verbose argument, if true (default is nil
), causes a brief message to be printed to *standard-output* about the collection of data.
See runtime-analizer.html for general information on the runtime analyzer.
function, profiler package
Arguments: &key verbose
If collection of sampling data is not already suspended when this function is called, collection is suspended. It is not an error to call this function while data collection is suspended. It is an error to call this function when data collection has not been started. Data collection can be resumed by calling start-sampling.
The verbose argument, if true (default is nil
), causes status messages to be printed to *standard-output* during the profile.
See runtime-analizer.html for general information on the runtime analyzer.
macro, profiler package
Arguments: (&key type except-processes count count-list verbose start-sampling-p interpret-closures) &body body
This macro collects runtime analyzer data for the execution of body by starting data collection, executing body, and then stopping data collection. This call to this macro:
(with-profiling (:type :time [other args]) body)
is equivalent to the following code sequence with the exception that the macro returns the result of the body.
(start-profiler :type :time [other args specified to with-profiling])
<body>
(stop-profiler)
The type keyword argument specifies the type or profile to conduct (time, space, call-counting). The values can be :time
, :real-time
, :space
, or :count-only
. Call counts are done (perhaps in addition to time or space) if either count or count-list are non-nil
. See start-profiler for a complete description of the choices and for proper values for count and count-list if you wish to have calls counted.
The keyword arguments (except-processes, count, count-list, verbose, start-sampling-p, and interpret-closures) are the same as the equivalent arguments to start-profiler and are described on that page. See also stop-profiler.
The body argument must be a form or sequence of forms. The system will collect data until the last form in body has been evaluated. Then data collection will stop.
This macro returns the value returned by the body.
If there is an unsaved, unanalyzed profile, you are asked by with-profiling if you want to save or discard that profile before proceeding with the new profile. You can cancel (delete) the current profile with cancel-current-profile, (you might do this if, for example, an unexpected error occurred in the code you are profiling), save it with save-named-profile, or analyze it with show-flat-profile or show-call-graph. Once any of these actions are taken, with-profiling will start without interruption, but note further analysis of the old profile data is not possible unless it was saved first.
See runtime-analizer.html for general information on the runtime analyzer.
macro, profiler package
Arguments: (&key verbose) &body body
Calling this macro is equivalent to the following code sequence, with the exception that the macro returns the result of the body.
(start-sampling)
<body>
(stop-sampling)
The verbose argument, if true (default is nil
), causes status messages to be printed to *standard-output* during the data collection.
The body argument must be one or more forms. The system will sample until the last form in body has been evaluated, then sampling will stop. This macro returns the result of the body.
See runtime-analizer.html for general information on the runtime analyzer.
Copyright (c) Franz Inc. Lafayette, CA., USA. All rights reserved.
|
Allegro CL version 11.0 |