Documentation

Profiling for Improving Performance

What Is Profiling?

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 .

Profiling Process and Guidelines

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.

  1. 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.

  2. 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.

  3. Determine whether there are changes you can make to the lines most called or the most time-consuming lines to improve performance.

    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.

  4. 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.

  5. Repeat this process to continue improving the performance.

Using Profiling as a Debugging Tool

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.

Using Profiling to Understand an Unfamiliar File

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.

Using the Profiler

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:

For information about the reports generated by the Profiler, see Profile Summary Report and Profile Detail Report.

Running the Profiler

To profile a MATLAB code file or a line of code:

  1. Launch the Profiler using one of the following methods:

    • On the Editor tab, in the Run section, click Run and Time. If you use this method, the Profiler automatically profiles the code in the current Editor tab, so skip to step 4.

    • On the Home tab, in the Code section, click Run and Time.

    • In the Command Window, type profile viewer.

  2. Do one of the following in the Profiler:

    • For a statement you have not profiled in the current MATLAB session:

      In the Run this code field, type the statement you want to run.

      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:

      1. Select the statement from the list box—MATLAB automatically starts profiling the code.

      2. Skip to step 4.

  3. Click Start Profiling.

    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 Profile 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.

  4. When profiling is complete, the Profile Summary report appears in the Profiler window. For more information about this report, see Profile Summary Report.

Profiling a Graphical User Interface

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:

  1. In the Profiler, click Start Profiling. Make sure that no code appears in the Run this code field.

  2. Start the graphical user interface. (If you do not want to include its startup process in the profile, do not click Stop Profiling, step 1, until after you start the graphical interface.)

  3. Use the graphical interface. When you finish, click Stop Profiling in the Profiler.

    The Profile Summary report appears in the Profiler.

Profiling Statements from the Command Window

To profile more than one statement:

  1. In the Profiler, clear the Run this code field and click Start Profiling.

  2. In the Command Window, enter and run the statements you want to profile.

  3. After running all the statements, click Stop Profiling in the Profiler.

    The Profile Summary report appears in the Profiler.

Changing Fonts for the Profiler

To change the fonts used in the Profiler:

  1. On the Home tab, in the Environment section, click Preferences .

  2. Select Fonts > Custom in the left pane.

  3. Under Desktop tools, select Profiler.

  4. Under Font to use, select the font. For more information, click the Help button in the dialog box.

  5. Click Apply or OK. The Profiler font reflects the changes.

Troubleshooting

If your profiling results are not what you expect, and your system has multiple cores and/or processors consider restricting the active number of CPUs to one. See one of the following for details:

Multi-Core Processors — Setting for Most Accurate Profiling on Windows Systems.  If your system uses multiple cores and/or processors, 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.

  1. Open Windows® Task Manager.

  2. On the Processes tab, right-click MATLAB.exe and then click Set Affinity.

    The Processor Affinity dialog box opens.

  3. 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.

  4. Click OK.

  5. 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.

Multi-Core Processors — Setting for Most Accurate Profiling on Linux Systems.  If your system uses multiple cores and/or processors, 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:

  1. 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.

  2. 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.

  3. 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.

Profile Summary Report

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.

Profile Detail 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:

Opening the Profile Detail Report

To open the Profile Detail Report:

  1. Create a Profile Summary report, as described in Using the Profiler.

  2. Click a function name listed in the Profile Summary report.

Controlling the Contents of the Detail Report Display

To specify which sections the Profile Detail Report includes:

  1. Select report options from the set of check boxes at the top of the report.

  2. Click the Refresh button.

Profile Detail Report Header

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.

Parent Functions

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.

Busy Lines

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.

Child Functions

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.

Code Analyzer Results

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.

File Coverage

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.

Function Listing

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 profile Function

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:

Example: Using the profile Function

This example demonstrates how to run profile:

  1. To start profile, type the following in the Command Window:

    profile on
    
  2. Execute a MATLAB code file. This example runs the Lotka-Volterra predator-prey population model. For more information about this model, type lotkademo, which runs a demonstration.

    [t,y] = ode23('lotka',[0 2],[20;20]);
    
  3. Generate the profile report and display it in the Profiler window. This suspends profile.

    profile viewer 
    
  4. Restart profile, without clearing the existing statistics.

    profile resume
    

    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.

  5. Stop profile when you finish gathering statistics.

    profile off
    
  6. To view the profile data, call profile specifying the 'info' argument. The profile function returns data in a structure.

    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.

  7. To save the profile report, use the profsave function. This function stores the profile information in separate HTML files, for each function listed in FunctionTable of p.

    profsave(p)
    

    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.

Accessing profile Function Results

The profile function returns results in a structure. This example illustrates how you can access these results:

  1. To start profile, specifying the history option, type the following in the Command Window:

    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.

  2. Execute a MATLAB code file. This example runs the Lotka-Volterra predator-prey population model. For more information about this model, type lotkademo, which runs a demonstration.

    [t,y] = ode23('lotka',[0 2],[20;20]);
    
  3. Stop profiling.

    profile off
    
  4. Get the structure containing profile results.

    stats = profile('info')
    stats = 
    
          FunctionTable: [33x1 struct]
        FunctionHistory: [2x880 double]
         ClockPrecision: 1.0000e-03
             ClockSpeed: 3.0000e+09
                   Name: 'MATLAB'
               Overhead: 0
  5. 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
  6. View the second structure in FunctionTable.

    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
  7. 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.

Saving profile Function Reports

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.

profsave(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.

profsave(stats,'mydir')

Using the profile Function to Change the Time Type Used by the Profiler

By default, MATLAB generates the Profile 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:

  1. If the Profiler is currently open, close the Profiler, and if prompted, stop profiling.

  2. Set the timer to real time by typing the following in the Command Window:

    profile on -timer real
    
  3. 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]);
    
  4. Open the Profiler by typing the following in the Command Window:

    profile viewer
    

    The Profiler opens and indicates that it is using real time, as shown in the following image.

  5. To change the timer back to using CPU time:

    1. Close the Profiler, and if prompted, stop profiling.

    2. Type the following in the Command Window:

      profile on -timer cpu
      
    3. Type the following in the Command Window to reopen the Profiler:

      profile viewer
      
Was this topic helpful?