|On this page…|
Profiling is a way to measure where a program spends time. To assist you in profiling, MATLAB® software provides a graphical user interface, called the Profiler, which is based on the results returned by the profile function. Once you identify which functions are consuming the most time, you can determine why you are calling them. Then, look for ways to minimize their use and thus improve performance. It is often helpful to decide whether the number of times the code calls a particular function is reasonable. Because programs often have several layers, your code might not explicitly call the most time-consuming functions. Rather, functions within your code might be calling other time-consuming functions that can be several layers down in the code. In this case it is important to determine which of your functions are responsible for such calls.
Profiling helps to uncover performance problems that you can solve by:
Avoiding unnecessary computation, which can arise from oversight
Changing your algorithm to avoid costly functions
Avoiding recomputation by storing results for future use
When profiling spends most of its time on calls to a few built-in functions, you have probably optimized the code as much as you can.
Note: When using the Parallel Computing Toolbox™ software, you can use the parallel profiler to profile parallel jobs. For details, see Profiling Parallel Code .
Here is a general process you can follow to use the Profiler to improve performance in your code. This section includes the following topics:
Tip Premature optimization can increase code complexity unnecessarily without providing a real gain in performance. Your first implementation should be as simple as possible. Then, if speed is an issue, use profiling to identify bottlenecks.
In the summary report produced by the Profiler, look for functions that used a significant amount of time or are called most frequently. See Profile Summary Report for more information.
View the detail report produced by the Profiler for those functions and look for the lines that use the most time or are called most often. See Profile Detail Report for more information.
Consider keeping a copy of your first detail report as a basis for comparison. After you change the function file, run the Profiler again and compare the reports.
For example, if you have a load statement within a loop, load is called every time the loop is called. You might be able to save time by moving the load statement so it is before the loop and therefore is called only once.
Click the links to the files and make the changes you identified for potential performance improvement. Save the files and run clear all. Run the Profiler again and compare the results to the original report. Note that there are inherent time fluctuations that are not dependent on your code. If you profile the identical code twice, you can get slightly different results each time.
The Profiler is a useful tool for isolating problems in your code.
For example, if a particular section of a file did not run, you can look at the detail reports to see what lines did run. The detail report might point you to the problem.
You can also view the lines that did not run to help you develop test cases that exercise that code.
If you get an error in the file when profiling, the Profiler provides partial results in the reports. You can see what ran and what did not to help you isolate the problem. Similarly, you can do this if you stop the execution using Ctrl+C. Using Ctrl+C can be useful when a file is taking much more time to run than expected.
For a lengthy MATLAB code file that you did not create, or with which you are unfamiliar, use the Profiler to see how the file actually works. Use the Profiler detail reports to see the lines called.
If there is an existing GUI tool (or file) like one that you want to create, start profiling, use the tool, then stop profiling. Look through the Profiler detail reports to see what functions and lines ran. This helps you determine the lines of code in the file that are most like the code you want to create.
Use the Profiler to help you determine where you can modify your code to make performance improvements. The Profiler is a tool that shows you where a file is spending its time. This section covers:
You can open the Profiler using several different methods:
Select one or more statements in the Command History window, right-click to view the context menu, and then select Profile Code.
Type profile viewer in the Command Window.
To profile a MATLAB code file or a line of code:
If your system uses Intel® multi-core chips, consider restricting the active number of CPUs to one.
See one of the following for details:
In the Command Window, type profile viewer.
Do one of the following in the Profiler:
For a statement you have not profiled in the current MATLAB session:
For example, you can run the Lotka-Volterra example, which is provided with MATLAB examples (lotkademo):
[t,y] = ode23('lotka',[0 2],[20;20])
For a statement you previously profiled in the current MATLAB session:
Select the statement from the list box—MATLAB automatically starts profiling the code.
Skip to step 5.
While the Profiler is running, the Profile time indicator is green and the number of seconds it reports increases. The Profile time indicator appears at the top right of the Profiler window.
When the Profiler finishes, the Profile time indicator becomes dark red and shows the length of time the Profiler ran. The statements you profiled display as having been executed in the Command Window.
This time is not the actual time that your statements took to run. It is the wall clock (or tic/toc) time elapsed from when you clicked Start Profiling until profiling stops. If the time reported is very different from what you expected (for example, hundreds of seconds for a simple statement), you might have had profiling on longer than you realize. This time also does not match the time reported in Profiler Summary report statistics, which is based on cpu time by default, not wall clock time. To view profile statistics based on wall clock time, use the profile function with the -timer real option as shown in Using the profile Function to Change the Time Type Used by the Profiler.
When profiling is complete, the Profile Summary report appears in the Profiler window. For more information about this report, see Profile Summary Report.
Reset the number of active CPUs to the original setting if you restricted the number in step 1.
Intel Multi-Core Processors — Setting for Most Accurate Profiling on Windows Systems. If your system uses Intel multi-core chips, and you plan to profile using CPU time, set the number of active CPUs to one before you start profiling. This results in the most accurate and efficient profiling.
Open Windows® Task Manager.
On the Processes tab, right-click MATLAB.exe and then click Set Affinity.
The Processor Affinity dialog box opens.
In the Processor Affinity dialog box, note the current settings, and then clear all the CPUs except one.
Your Processor Affinity dialog box should appear like the following image.
Reset the state of the Profiler so that it recognizes the processor affinity changes you made. The easiest way to do so is to change the Profiler timer setting to real and then back to cpu, by issuing the following in the Command Window:
profile -timer real profile -timer cpu
Remember to set the number of CPUs back to their original settings when you finish profiling. Rerun the preceding steps, and restore the original selections in the Processor Affinity dialog box in step 3.
Intel Multi-Core Processors — Setting for Most Accurate Profiling on Linux Systems. If your system uses Intel multi-core chips, and you plan to profile using CPU time, set the number of active CPUs to one before you start profiling. This results in the most accurate and efficient profiling.
For example, to set the processor affinity to one you can use the Linux® taskset command, as follows:
Get the process ID (PID) of the currently running MATLAB instance:
ps -C MATLAB PID TTY TIME CMD 8745 pts/1 00:00:50 MATLAB
The PID in this example is 8745.
Call the Linux taskset command to get the current number of active CPUs for the MATLAB process:
taskset -pc 8745 pid 8745's current affinity list: 0-3
The -p option specifies that taskset operate on an existing PID, instead of creating a new task. The -c option lists the processor numbers.
Call the Linux taskset command again — this time to set the processor affinity for the MATLAB process to one CPU (that is, CPU #0):
taskset -pc 0 8745 pid 8745's current affinity list: 0-3 pid 8745's new affinity list: 0
For more information on the syntax of taskset, execute man taskset from a Linux terminal.
Reset the state of the Profiler so that it recognizes the processor affinity changes you made. The easiest way to do this is to change the Profiler timer setting to real and then back to cpu, by issuing the following in the Command Window:
profile -timer real profile -timer cpu
Remember to set the number of CPUs back to its original setting when you finish profiling. Rerun the preceding steps, and then restore the original number of CPUs returned in step 2.
You can run the Profiler for a graphical user interface, such as the Filter Design and Analysis tool included with Signal Processing Toolbox™. You can also run the Profiler for an interface you created, such as one built using GUIDE.
To profile a graphical user interface:
The Profile Summary report appears in the Profiler.
To profile more than one statement:
The Profile Summary report appears in the Profiler.
To change the fonts used in the Profiler:
On the Home tab, in the Environment section, click Preferences .
Select Fonts > Custom in the left pane.
Under Desktop tools, select Profiler and Comparison Tool.
Under Font to use, select the font. For more information, click the Help button in the dialog box.
The Profile Summary report presents statistics about the overall execution of the function and provides summary statistics for each function called. The report formats these values in four columns.
Function Name — A list of all the functions called by the profiled function. When first displayed, the functions are listed in order by the amount of time they took to process. To sort the functions alphabetically, click the Function Name link at the top of the column.
Calls — The number of times the function was called while profiling was on. To sort the report by the number of times functions were called, click the Calls link at the top of the column.
Total Time — The total time spent in a function, including all child functions called, in seconds. The time for a function includes time spent on child functions. To sort the functions by the amount of time they consumed, click the Total Time link at the top of the column. By default, the summary report displays profiling information sorted by Total Time. Be aware that the Profiler itself uses some time, which is included in the results. Also note that total time can be zero for files whose running time was inconsequential.
Self Time — The total time spent in a function, not including time for any child functions called, in seconds. If MATLAB can determine the amount of time spent for profiling overhead, MATLAB excludes it from the self time also. (MATLAB excludes profiling overhead from the total time and the time for individual lines in the Profile Detail Report as well.)
The bottom of the Profiler page contains a message like one of the following, depending on whether MATLAB can determine the profiling overhead:
Self time is the time spent in a function excluding:
The time spent in its child functions
Most of the overhead resulting from the process of profiling
In the present run, self time excludes 0.240 secs of profiling overhead. The amount of remaining overhead reflected in self time cannot be determined, and therefore is not excluded.
Self time is the time spent in a function excluding the time spent in its child functions. Self time also includes some overhead resulting from the process of profiling.
To sort the functions by this time value, click the Self Time link at the top of the column.
Total Time Plot — Graphic display showing self time compared to total time.
The following is an image of the summary report for the Lotka-Volterra model used in Example: Using the profile Function.
In the summary report, you can:
Print it, by clicking the Print button .
Get more detailed information about a particular function by clicking its name in the Function Name column. See Profile Detail Report for more information.
Sort by a given column by clicking the name of the column. For example, click to sort by the names of the functions included in the summary report.
The Profile Detail report shows profiling results for a selected function that was called during profiling. A Profile Detail report has seven sections. The topics that follow describe each section. By default, the Profile Detail report includes all seven sections, although, depending on the function, not every section contains data. To return to the Profile Summary report from the Profile Detail report, click in the toolbar of the Profile window.
The following topics provide details about opening and using a Profile Detail Report:
To open the Profile Detail Report:
Create a Profile Summary report, as described in Using the Profiler.
Click a function name listed in the Profile Summary report.
To specify which sections the Profile Detail Report includes:
Select report options from the set of check boxes at the top of the report.
Click the Refresh button.
The detail report header includes:
The name of the function profiled
The number of times the profiled function was called in the parent function
The amount of time the profiled function used
A link that opens the function in your default text editor
A link that copies the report to a separate window
Creating a copy of the report is helpful when you change the file, run the Profiler for the updated file, and compare the Profile Detail reports for the two runs. Do not change files provided with products from MathWorks®, that is, files in the matlabroot/toolbox folders.
To include the Parents section in the Detail Report, select the Show parent functions check box. This section of the report provides information about the parent functions, with links to their detail reports. Click the name of a parent function to open a Detail Report for that parent function.
To include information about the lines of code that used the most amount of processing time in the detail report, select the Show busy lines check box.
To include the Children section of the detail report, select the Show child functions check box. This section of the report lists all the functions called by the profiled function. If the called function is a MATLAB code file, you can view the source code for the function by clicking its name.
To include the Code Analyzer results section in the detail report display, select the Show Code Analyzer results check box. This section of the report provides information about problems and potential improvements for the function.
To include the Coverage results section in the detail report display, select the Show file coverage check box. This section of the report provides statistical information about the number of lines in the code that executed during the profile run.
To include the Function listing section in the detail report display, select the Show function listing check box. If the file is a MATLAB code file, the Profile Detail report includes three columns:
The first column lists the execution time for each line.
The second column lists the number of times the line was called
The third column specifies the source code for the function.
In the function listing, the color of the text indicates the following:
Green — Comment lines
Black — Lines of code that executed
Gray — Lines of code that did not execute
By default, the Profile Detail report highlights lines of code with the longest execution time. The darker the highlighting, the longer the line of code took to execute.
To change the lines of code highlighted based on other criteria, use the drop-down menu in this section of the detail report. The color of the highlighting changes, depending on the drop-down option you choose. You can choose to highlight lines of code called the most, lines of code that were (or were not) executed, or lines called out by the Code Analyzer. Or, you can turn off highlighting by selecting none.
The following image shows that lines highlight in blue when you select coverage from the drop-down menu.
The Profiler is based on the results returned by the profile function. The profile function provides some features that are not available in the GUI. For example, use the profile function to specify that statistics display the time it takes for statements to run as clock time, instead of CPU time.
This section includes the following topics with respect to the profile function:
This example demonstrates how to run profile:
[t,y] = ode23('lotka',[0 2],[20;20]);
The profile function is now ready to continue gathering statistics for any more files you run. It will add these new statistics to those statistics generated in the previous steps.
p = profile('info') p = FunctionTable: [33x1 struct] FunctionHistory: [2x0 double] ClockPrecision: 1.0000e-03 ClockSpeed: 3.0000e+09 Name: 'MATLAB' Overhead: 0
The FunctionTable indicates that statistics were gathered for 33 functions.
By default, profsave puts these HTML files in a subfolder of the current folder named profile_results, and displays the summary report in your system browser. You can specify another folder name as an optional second argument to profsave.
The profile function returns results in a structure. This example illustrates how you can access these results:
profile on -history
The history option specifies that the report include information about the sequence of functions as they are entered and exited during profiling.
[t,y] = ode23('lotka',[0 2],[20;20]);
stats = profile('info') stats = FunctionTable: [33x1 struct] FunctionHistory: [2x880 double] ClockPrecision: 1.0000e-03 ClockSpeed: 3.0000e+09 Name: 'MATLAB' Overhead: 0
The FunctionTable field is an array of structures, where each structure represents a MATLAB function (M-function), MATLAB local function, MEX-function, or, because the builtin option is specified, a MATLAB built-in function.
stats.FunctionTable ans = 33x1 struct array with fields: CompleteName FunctionName FileName Type Children Parents ExecutedLines IsRecursive TotalRecursiveTime PartialData NumCalls TotalTime
stats.FunctionTable(2) ans = CompleteName: [1x95 char] FunctionName: 'ode23' FileName: [1x89 char] Type: 'M-function' Children: [6x1 struct] Parents: [0x1 struct] ExecutedLines: [139x3 double] IsRecursive: 0 TotalRecursiveTime: 0 PartialData: 0 NumCalls: 1 TotalTime: 0.0920
To view the history data generated by profile, view the FunctionHistory, for example, stats.FunctionHistory. The history data is a 2-by-n array. The first row contains Boolean values, where 0 (zero) means entrance into a function and 1 means exit from a function. The second row identifies the function being entered or exited by its index in the FunctionTable field. To see how to create a formatted display of history data, see the example on the profile reference page.
To save the profile report, use the profsave function.
This function stores the profile information in separate HTML files, for each function listed in the FunctionTable field of the structure, stats.
By default, profsave puts these HTML files in a subfolder of the current folder named profile_results. You can specify another folder name as an optional second argument to profsave.
By default, MATLAB generates the Profiler Summary report using CPU time, as opposed to real (wall clock) time. This example illustrates how you can direct MATLAB to use real time instead.
Specify that the Profiler use real time instead, by using the profile function with the -timer real option, as shown in this example:
If the Profiler is currently open, close the Profiler, and if prompted, stop profiling.
profile on -timer real
Run the file that you want to profile. This example runs the Lotka-Volterra predator-prey population model.
[t,y] = ode23('lotka',[0 2],[20;20]);
Open the Profiler by typing the following in the Command Window:
The Profiler opens and indicates that it is using real time, as shown in the following image.
To change the timer back to using CPU time:
Close the Profiler, and if prompted, stop profiling.
Type the following in the Command Window:
profile on -timer cpu
Type the following in the Command Window to reopen the Profiler: