Sysquake Pro – Table of Contents
Sysquake for LaTeX – Table of Contents
Profiler
profile
Install, remove, or display a function profile.
Syntax
profile fun
profile report
profile done
profile function fun
profile off
profile on
profile reset
profile('report', format)
Description
The purpose of the profiler is to measure the amount of time spent executing each line of code of a function. This helps in evaluating where effort should be put in order to optimize the code. With LME, a single function can be profiled at any given time. Command profile manages all aspects related to profiling, from specifying which function is to be profiled to displaying the results and resuming normal operations.
The time measured for each line includes time spent executing subfunctions called from that line. Only the cumulative times are collected; lines of code in loops are likely to have a larger impact on the overall execution time.
The profile accuracy is limited mainly by two factors:
- The resolution of the timer, which is typically between 1e-9 and 1e-6 second. This has obviously a larger effect on lines executed quickly. Lines which contain scalar assignments or statements like if and for may completely escape from the timing.
- The time overhead to perform the timing and add the data. Here again, its effect is more dramatic with fast lines.
To profile a function, one usually proceeds in four steps:
- Setup
- profile fun sets up profiling for function fun. Room in memory is allocated and initialized for collecting the cumulative time of execution for each line in fun.
- Function execution
- Each execution of the function adds to the profile data. Since the relative execution times are usually what is really interesting, you may want to execute the function several times to reduce fluctuations due to rounding errors. Time spent outside the function (such as the time you spend typing the commands at the command-line interface) is not included.
- Profile report
- profile report displays a report for the function being profiled. The default format is a listing of all lines with the line number, the cumulative time spent for the line in seconds, its percentage with respect to the time spent in the whole function, and the source code of the line. You can continue executing the function and creating new reports; times are cumulative (but see profile reset and profile off below).
- End
- profile done releases the data structures set up with profile fun.
Other options are available. profile off suspends profiling, and profile on resumes it. When profiling is suspended, calls to the profiled function are not taken into account.
profile reset resets all the times and resumes profiling if it was suspended.
profile function fun is equivalent to profile fun, but it may also be used to profile functions with the same name as one of the options which have a special meaning for profile, like report or done.
profile('report',format) produces a report with a special format specified by the string format. This string is similar to the format argument of sprintf; it is reused for each line of the profiled function. Its characters are output literally, except for sequences which begin with a percent character, whose meaning is given in the table below.
| Char. | Meaning |
|---|---|
| %% | single % |
| %l | line number |
| %t | cumulative time |
| %p | percentage of the total time |
| %s | source code of the line |
Like with sprintf, precision numbers may be inserted between the percent sign and the letter; for instance, %8.3t displays the cumulative time in a column of 8 characters with a fractional part of 3 digits. The percentage is displayed only if it is greater than 1 %; otherwise, it is replaced (together with the percent character which may follow it) with spaces. The default format is '%4l%9.3t%6.1p%% %s\n'.
Example
We shall profile function logspace from library stdlib (the source code of this function has been revised since the profiling was done).
use stdlib profile logspace x = logspace(1,10); profile report 13 0.000 function r = logspace(x1, x2, n) 14 0.000 15 0.000 14.8% if nargin < 3 16 0.000 5.8% n = 100; 17 0.000 2.2% end 18 0.000 77.1% r = exp(log(x1)+log(x2/x1)*(0:n-1)/(n-1));
While the times spent for all lines are smaller than half a millisecond, the resolution is fine enough to permit relative timing of each line. The function header does not correspond to any code and is not timed. To improve the accuracy of the timing, we repeat the execution 10000 times.
for i=1:10000; x = logspace(1,10); end profile report 13 0.000 function r = logspace(x1, x2, n) 14 0.000 15 0.055 8.9% if nargin < 3 16 0.057 9.2% n = 100; 17 0.047 7.6% end 18 0.458 74.3% r = exp(log(x1)+log(x2/x1)*(0:n-1)/(n-1));
Finally, here is a report with a different format: the first column is the percentage as an integer, a space and the percent sign, followed by spaces and the source code:
profile('report', '%3.0p %% %s\n')
function r = logspace(x1, x2, n)
9 % if nargin < 3
9 % n = 100;
8 % end
74 % r = exp(log(x1) + log(x2/x1) * (0:n-1) / (n-1));