MATLAB Community

MATLAB, community & more

Speeding up your program through Profiling 6

Posted by Michael Katz,

I was originally going to write about about a minor feature of the MATLAB Profiler, but while skimming through the archives here, I realize we haven’t really talked much about profiling at all! So it’s time to go back to MATLAB basics and talk about Profiling.

The Profiler is one of several dynamic analysis tools. The most common form of dynamic analysis focuses on correctness. In that workflow, you run your code and check whether the calculated result matches the expected result. If it doesn’t match you either made some bad assumptions about your data or there’s a bug in the program. You can use tools like the MATLAB Debugger and M-Lint to figure out the problem. A less common way to analyze code is to look at efficiency, in this case how long it takes to run (we’ll look in to memory another time). The Profiler lets you run a program and then look at how long each line took to execute. With this information you can concentrate on optimizing the sections of code that take up the most time.

By default the Profler is not visible on the Desktop. To get it, use the Desktop menu, under Desktop -> Profiler. This brings up the Profiler window (it looks like the Web browser).

Open the MATLAB Profiler with Destkop - Profile
MATLAB Profiler

In the Profiler’s toolbar enter the MATLAB command(s) you wish to profile (where the URL would go if it were a web browser). You can combine multiple MATLAB statements with a “,” or “;”. This way you can set up inputs, if necessary. For example: A = rand(10); myfun(A). Once you enter the function(s) to profile, press Enter to run them. My example uses following function awhile.m:

function z = awhile
    for i=100:100:300
        x = rand(i);
        y = rand(i);
        z = calculate(x,y);
    end
function z = calculate(x,y)
    z = conv2(x,y);
    pause(2);

From the results below, we can see that running awhile took 16 seconds on my computer (the time is listed next to the black bullet on the toolbar). Of that 16 seconds 14.823 was spent in that one function, with almost 100% of that time spent in the three calls to the calculate subfunction. This result is not surprising given my example code. Note that 14.823 < 16. What happened to the other 1.177 seconds? The “16 seconds” reflects the total real time spent from the time the Profiler was started to when it was told to stop, rounded to the nearest second. The reported 14.823 seconds is the amount of time spent by the CPU running that code, and does not reflect the overhead of the operating system or any commands issued around the profiled function.

MATLAB Profiler results from awhile.m

Clicking on a listed function or subfunction will take you to a page that lists a lot detail about each line of code in that function, including:

  • Which functions called that the function and how many times
  • The individual lines where the most time was spent, including the number of times that line was executed and how much time was spent on that line
  • What other profiled functions were called by that function
  • Any warnings reported by M-lint, which can provide suggestions for improving performance
  • A coverage summary showing the number of lines run vs not run
  • A color-coded version of your code, showing potential problem spots.

In the picture below we see that 8.85 seconds of the time was spent in conv2 and 5.97 seconds in pause. With the information presented in the report I know I can get a 40% speedup by eliminating the call to pause, but we see that the conv2 line is darker, meaning I’d get more bang for my buck by improving that line. Since this code doesn’t do anything useful, there’s nothing really to replace it with it. But in your own code you might see a way to either replace a dark red line, or call it fewer times.

The subfunction lines by time

To sumamrize, the workflow for profiling is:

  1. Find a program you wish to speed up.
  2. Run that code with appropriate inputs in the Profiler.
  3. Fix any performance-related M-Lint warnings in your file (if you haven’t already). The Profiler can help you asses which warnings are most significant.
  4. Look for the lines where the code spent the most time, and try to call that line fewer times, replace it with faster statements, or break your code into smaller problems.
  5. Repeat until there’s nothing left to improve.

The profiler can also be run from the MATLAB command line using the profile command.

EDIT (02/01/10): Fixed typo.

Note

Comments are closed.

6 CommentsOldest to Newest

OysterEngineer replied on : 1 of 6

I’ve found the Profiler easy to use & the information provided easy to understand. Having said that, I haven’t often improved the performance of my code by using Profiler since there are always a bunch of constraints that limit my ability to revise the code. Or, the code isn’t excessively slow to begin with.

I hesitate to make this next point. But, I always get confused when I open the Profiler window & see the entry box at the top, with its nice instructions: Run this code. My 1st reaction is to cut & paste the code from my .m file into this box. Instead, what you want is the name (maybe including the path?) of the .m file that is to be profiled.

The way my mind works, it always makes more sense to use profile as a function, something like this:

profile(‘myfun.m’);

Anyway, I expect to be criticized for this comment since clearly, the statement: Run this code, must be pretty clear to a bunch of users or else it wouldn’t be there. But, it is confusing to me.

us replied on : 2 of 6

mike, nice blog

however, you should also mention these two commands, which we put into our startup.m files…
they add a lot of additional information to the output…

setpref(‘profiler’,’showJitLines’,1);
profile -memory on;
profile off; % <- at startup…

us

Mike replied on : 3 of 6

@OysterEngineer,
I think the community here is pretty supportive. Your comments are always appreciated. Given the state of the Desktop and MATLAB now if we designed the Profiler anew, we probably would go with a different approach. We’ll keep those concerns in mind when we do revisit the Profiler.
Profiling does have its limitations. In general the best you can hope for is reducing the number of times a slow function is called. With small enough inputs or smart functions, the payoff by choosing a different algorithm may be a few milli or microseconds.

@us,
Those options are undocumented and thus I am not going to comment on them other than “user be ware.” They may not work or behave as expected on every release or platform, and are difficult to use to compare code between MATLAB releases.

Mike replied on : 5 of 6

@Sima,

CPU-time is the estimated amount of time the cpu spent running the program, and real time is the clock time (including context switches, page swapping, etc).

Chad Gilbert replied on : 6 of 6

Hi Mike,

Say I’ve run two profiles and saved them.

p1 = profile(‘info’);
save profile1 p1;
p2 = profile(‘info’);
save profile2 p2;

Is there any nice way for me to compare them? It seems that “profview(0,p)” will only let me view one profile at a time. The code I’m interested in profiling is fairly complex and only a few changes have been made. It would be very nice to have a sort of “diff viewer” for profiles.