Viewing saved profiling results

Many Matlab users know and utilize Matlab’s built-in Profiler tool to identify performance bottlenecks and code-coverage issues. Unfortunately, not many are aware of the Profiler’s programmatic interface. In past articles as well as my performance book I explained how we can use this programmatic interface to save profiling results and analyze it offline. In fact, I took this idea further and even created a utility (profile_history) that displays the function call timeline in a standalone Matlab GUI, something that is a sorely missed feature in the built-in profiler:

Function call timeline profiling (click for full-size image)
Function call timeline profiling (click for full-size image)

Today I will discuss a related undocumented feature of the Profiler: loading and viewing pre-saved profiling results.

Programmatic access to profiling results

Matlab’s syntax for returning the detailed profiling results in a data struct is clearly documented in the profile function’s doc page. Although the documentation does not explain the resulting struct and sub-struct fields, they have meaningful names and we can relatively easily infer what each of them means (I added a few annotation comments for clarity):

>> profile('on','-history')
>> surf(peaks); drawnow
>> profile('off')
>> profData = profile('info')
profData = 
      FunctionTable: [26x1 struct]
    FunctionHistory: [2x56 double]
     ClockPrecision: 4.10517962829241e-07
         ClockSpeed: 2501000000
               Name: 'MATLAB'
           Overhead: 0
>> profData.FunctionTable(1)
ans = 
          CompleteName: 'C:\Program Files\Matlab\R2016a\toolbox\matlab\specgraph\peaks.m>peaks'
          FunctionName: 'peaks'
              FileName: 'C:\Program Files\Matlab\R2016a\toolbox\matlab\specgraph\peaks.m'
                  Type: 'M-function'
              Children: [1x1 struct]
               Parents: [0x1 struct]
         ExecutedLines: [9x3 double]
           IsRecursive: 0
    TotalRecursiveTime: 0
           PartialData: 0
              NumCalls: 1
             TotalTime: 0.0191679078068094
>> profData.FunctionTable(1).Children
ans = 
        Index: 2   % index in profData.FunctionTable array
     NumCalls: 1
    TotalTime: 0.00136415141013509
>> profData.FunctionTable(1).ExecutedLines   % line number, number of calls, duration in secs
ans =
         43      1      0.000160102031282782
         44      1      2.29890096200918e-05
         45      1      0.00647592190637408
         56      1      0.0017093970724654
         57      1      0.00145036019621044
         58      1      0.000304193859437286
         60      1      4.39254290955326e-05
         62      1      3.44835144301377e-05
         63      1      0.000138755093778411
>> profData.FunctionHistory(:,1:5)
ans =
     0     0     1     1     0   % 0=enter, 1=exit
     1     2     2     1     6   % index in profData.FunctionHistory array

As we can see, this is pretty intuitive so far.

Loading and viewing saved profiling results

If we wish to save these results results in a file and later load and display them in the Profiler’s visualization browser, then we need to venture deeper into undocumented territory. It seems that while retrieving the profiling results (via profile(‘info’)) is fully documented, doing the natural complementary action (namely, loading this data into the viewer) is not. For the life of me I cannot understand the logic behind this decision, but that’s the way it is.

Luckily, the semi-documented built-in function profview does exactly what we need: profview accepts 2 input args (function name and the profData struct) and displays the resulting profiling info. The first input arg (function name) accepts either a string (e.g., 'peaks' or 'view>isAxesHandle'), or the numeric value 0 which signifies the home (top-level) page:

profView(0, profData);  % display profiling home (top-level) page
profview('peaks', profData);  % display a specific profiling page

I use the 0 input value much more frequently than the string inputs, because I often don’t know which functions exactly were profiled, and starting at the home page enables me to easily drill-down the profiling results interactively.

Loading saved profiling results from a different computer

Things get slightly complicated if we try to load saved profiling results from a different computer. If the other computer has exactly the same folder structure as our computer, and all our Matlab functions reside in exactly the same disk folders/path, then everything will work out of the box. The problem is that in general the other computer will have the functions in different folders. When we then try to load the profData on our computer, it will not find the associated Matlab functinos in order to display the line-by-line profiling results. We will only see the profiling data at the function level, not line level. This significantly reduces the usefulness of the profiling data. The Profiler page will display the following error message:

This file was modified during or after profiling. Function listing disabled.

We can solve this problem in either of two ways:

  1. Modify our profData to use the correct folder path on the local computer, rather than the other computer’s path (which is invalid on the local computer). For example:
    % Save the profData on computer #1:
    profData = profile('info');
    save('profData.mat', 'profData');
    % Load the profData on computer #2:
    fileData = load('profData.mat');
    profData = fileData.profData;
    path1 = 'N:\Users\Juan\programs\myProgram';
    path2 = 'C:\Yair\consulting\clients\Intel\code';
    for idx = 1 : numel(profData.FunctionTable)
       funcData = profData.FunctionTable(idx);
       funcData.FileName     = strrep(funcData.FileName,     path1, path2); 
       funcData.CompleteName = strrep(funcData.CompleteName, path1, path2);
       profData.FunctionTable(idx) = funcData;
    % note: this loop can be vectorized if you wish
  2. As an alternative, we can modify Matlab’s profview.m function (%matlabroot%/toolbox/matlab/codetools/profview.m) to search for the function’s source code in the current Matlab path, if the specified direct path is not found (note that changing profview.m may require administrator priviledges). For example, the following is the code from R2016a’s profview.m file, line #506:
        % g894021 - Make sure the MATLAB code file still exists
        if ~exist(fullName, 'file')
            [~,fname,fext] = fileparts(fullName);  % Yair        fname = which([fname fext]);           % Yair        if isempty(fname)                      % Yair            mFileFlag = 0;
            else                                   % Yair            fullName = fname;                  % Yair        end                                    % Yair    end

These two workarounds complement each other: the first workaround does not require changing any installed Matlab code, and so is platform- and release-independent, but would require rerunning the code snippet for each and every profiling data file that we receive from external computers. On the other hand, the second workaround is a one-time operation that should work for multiple saved profiling results, although we would need to redo it whenever we install Matlab.

Additional profview customizations

Modifying the profview.m function can be used for different improvements as well.

For example, several years ago I explained how this function can be modified to display 1 ms timing resolutions, rather than the default 10 mS.

Another customization that I often do after I install Matlab is to change the default setting of truncating function lines longer than 40 characters – I typically modify this to 60 or 80 (depending on the computer monitor’s size…). All we need to do is to update the truncateDisplayName sub-function within profview.m as follows (taken from R2016a again, line #1762):

function shortFileName = truncateDisplayName(longFileName,maxNameLen)
%TRUNCATEDISPLAYNAME  Truncate the name if it gets too long
maxNameLen = max(60,maxNameLen);  % YairshortFileName = escapeHtml(longFileName);
if length(longFileName) > maxNameLen,
    shortFileName = char(com.mathworks.util.FileUtils.truncatePathname( ...
        shortFileName, maxNameLen));

You can see additional undocumented profiling features in the “Related posts” section below, as well as in Chapter 2 of my book “Accelerating MATLAB Performance“.

Do you have any other customization to the profiling results? If so, please share it in a comment.

Categories: Desktop, Low risk of breaking in future versions, Semi-documented function, Stock Matlab function, Undocumented feature

Tags: , ,

Bookmark and SharePrint Print

Leave a Reply

Your email address will not be published. Required fields are marked *