Writing Fast Matlab Code #2: Profile
The Profiler
Matlab 5.0 (R10) and newer versions include a tool called the profiler that helps identify bottlenecks in a program. Use it with the profile command:
profile on % Turn the profiler on profile off %Turn it back off profile clear %Clear profile statistics profile report %View the results from the profiler
For example, consider profiling the following function:
function result = example1(Count) for k = 1:Count result(k) = sin(k/50); if result(k) < −0.9 result(k) = gammaln(k); end
To analyze the efficiency this function, first enable and clear the profiler, run the function, and then view the profile report:
profile on profile clear example1(5000); profile report
There is a slight parsing overhead when running code for the first time; run the test code twice and time the second run. The profiler report command shows a report. Depending on the system, profiler results may differ from this example.
MATLAB Profile Report: Summary
Report generated 30-Jul-2004 16:57:01
Total recorded time: 3.09 s
Number of M-functions: 4
Clock precision: 0.016 s
Function List
Name Time Time Time/call Self time Location
|
example1 |
3.09 |
100.0% |
1 |
3.094000 |
2.36 |
76.3% |
~/example1.m |
|
gammaln |
0.73 |
23.7% |
3562 |
0.000206 |
0.73 |
23.7% |
../toolbox/matlab/specfun/gammaln.m |
|
profile |
0.00 |
0.0% |
1 |
0.000000 |
0.00 |
0.0% |
../toolbox/matlab/general/profile.m |
|
profreport |
0.00 |
0.0% |
1 |
0.000000 |
0.00 |
0.0% |
../toolbox/matlab/general/profreport.m |
Clicking the “example1” link gives more details:
Lines where the most time was spent
|
Line Number |
Code |
Calls |
Total Time |
% Time |
|
4 |
result(k) = sin(k/50); |
5000 |
2.11 s |
68% |
|
7 |
result(k) = gammaln(k); |
721 |
0.84 s |
27% |
|
6 |
if result(k) < -0.9 |
5000 |
0.14 s |
5% |
|
Totals |
|
|
3.09 s |
100% |
The most time-consuming lines are displayed, along with time, time percentage, and line number. The most costly lines are the computations on lines 4 and 7.
Another helpful section of the profile report is “M-Lint Results,” which gives feedback from the M-Lint code analyzer. Possible errors and suggestions are listed here.
M-Lint results
Line number Message
4 ‘result’ might be growing inside a loop. Consider preallocating for speed.
7 ‘result’ might be growing inside a loop. Consider preallocating for speed.
(Preallocation is discussed in the next section.)
The profiler has limited time resolution, so to profile a piece of code that runs too quickly, run the test code multiple times with a loop. Adjust the number of loop iterations so that the time it takes to run is noticeable. More iterations yields better time resolution.
The profiler is an essential tool for identifying bottlenecks and per-statement analysis, however, for more accurate timing of a piece of code, use the tic/toc stopwatch timer.
tic; example1(5000); toc;
Elapsed time is 3.082055 seconds
For serious benchmarking, also close your web browser, anti-virus, and other background processes that may be taking CPU cycles.
Function List
Name Time Time Time/call Self time Location
|
example1 |
3.09 |
100.0% |
1 |
3.094000 |
2.36 |
76.3% |
~/example1.m |
|
gammaln |
0.73 |
23.7% |
3562 |
0.000206 |
0.73 |
23.7% |
../toolbox/matlab/specfun/gammaln.m |
|
profile |
0.00 |
0.0% |
1 |
0.000000 |
0.00 |
0.0% |
../toolbox/matlab/general/profile.m |
|
profreport |
0.00 |
0.0% |
1 |
0.000000 |
0.00 |
0.0% |
../toolbox/matlab/general/profreport.m |
Clicking the “example1” link gives more details:
Lines where the most time was spent
|
Line Number |
Code |
Calls |
Total Time |
% Time |
|
4 |
result(k) = sin(k/50); |
5000 |
2.11 s |
68% |
|
7 |
result(k) = gammaln(k); |
721 |
0.84 s |
27% |
|
6 |
if result(k) < -0.9 |
5000 |
0.14 s |
5% |
|
Totals |
|
|
3.09 s |
100% |
Popularity: 1% [?]
Related Posts
Comments
Translator
Follow Us
Video Posts
