Undocumented Matlab
  • SERVICES
    • Consulting
    • Development
    • Training
    • Gallery
    • Testimonials
  • PRODUCTS
    • IQML: IQFeed-Matlab connector
    • IB-Matlab: InteractiveBrokers-Matlab connector
    • EODML: EODHistoricalData-Matlab connector
    • Webinars
  • BOOKS
    • Secrets of MATLAB-Java Programming
    • Accelerating MATLAB Performance
    • MATLAB Succinctly
  • ARTICLES
  • ABOUT
    • Policies
  • CONTACT
  • SERVICES
    • Consulting
    • Development
    • Training
    • Gallery
    • Testimonials
  • PRODUCTS
    • IQML: IQFeed-Matlab connector
    • IB-Matlab: InteractiveBrokers-Matlab connector
    • EODML: EODHistoricalData-Matlab connector
    • Webinars
  • BOOKS
    • Secrets of MATLAB-Java Programming
    • Accelerating MATLAB Performance
    • MATLAB Succinctly
  • ARTICLES
  • ABOUT
    • Policies
  • CONTACT

Undocumented Profiler options part 4

October 3, 2012 One Comment

Today’s article concludes my series on undocumented features of the Matlab Profiler. Past articles explained how to profile memory, improve timing resolution and fix a font issue, and display the call history. Today’s article will explain undocumented switches of the profile function that can be used to profile built-in functions, to report and remove the profiling overhead, plus a couple of as-yet-unsolved mysteries.

Profiling built-in functions

Built-in functions (e.g., isempty, length, find) are not monitored or displayed in the profiling summary by default. They are also not linkable to a detailed profiling report in the detailed report of any user function. So, if we have a code line such as the following, we cannot know how much time is spent in length, find as opposed to being spent in userFunction:

numResults = length(find(userFunction()));

numResults = length(find(userFunction()));

However, we can tell the profile to monitor and display built-in functions using the undocumented optional -detail builtin switch of the profile function:

profile on –detail builtin
profile('on','-detail','builtin')   % an equivalent alternative

profile on –detail builtin profile('on','-detail','builtin') % an equivalent alternative

Alternately, we can use the undocumented built-in function callstats directly (as I already explained, the profile function is simply a convenient wrapper function to callstats):

callstats('level', 2);  % 1=mmex, 2=builtin

callstats('level', 2); % 1=mmex, 2=builtin

The built-in functions will now be reported in the profiling summary and detailed reports, and will be linkable within the code lines of the detailed report.
Note: old MATLAB releases also supported the ‘operator’ detail level, which provided profiling information about built-in operators such as +. However, this level of detail is no longer supported in the latest MATLAB releases.
The -detail switch can also be used with other profile switches. For example:

>> profile('on','-detail','builtin','-timestamp'); surf(peaks); profile('off')

>> profile('on','-detail','builtin','-timestamp'); surf(peaks); profile('off')

To return to the standard profiling level (‘mmex’), run one of the following:

profile on –detail mmex
profile('on','-detail','mmex')   % an equivalent alternative
callstats('level', 1);           % an equivalent alternative

profile on –detail mmex profile('on','-detail','mmex') % an equivalent alternative callstats('level', 1); % an equivalent alternative

Profiling overhead removal

The -remove_overhead switch checks the profiler’s own overhead and knows to remove this overhead from all relevant timing values. This is normally off by default, and returns profData.overhead=0. When turned on, it stores the computed profiling overhead in profData.overhead:

profile -remove_overhead on
profile('-remove_overhead','on')        % equivalent alternative
callstats('remove_sample_overhead',1);  % equivalent alternative

profile -remove_overhead on profile('-remove_overhead','on') % equivalent alternative callstats('remove_sample_overhead',1); % equivalent alternative

We need to make a small fix to the profview function (%matlabroot%/toolbox/matlab/codetools/profview.m), otherwise the profiling report will croak on an error. The fix is simple: replace the following code segment (lines #351-355 in the profview.m file of R2012a)

if profileInfo.Overhead==0
    s{end+1} = sprintf(['<p><a name="selftimedef"></a>', getString(message('MATLAB:profiler:SelfTime1st')) ' ']);
else
    s{end+1} = sprintf(['<p><a name="selftimedef"></a>', getString(message('MATLAB:profiler:SelfTime2nd', profileInfo.Overhead))]);
end

if profileInfo.Overhead==0 s{end+1} = sprintf(['<p><a name="selftimedef"></a>', getString(message('MATLAB:profiler:SelfTime1st')) ' ']); else s{end+1} = sprintf(['<p><a name="selftimedef"></a>', getString(message('MATLAB:profiler:SelfTime2nd', profileInfo.Overhead))]); end

with this (changed line highlighted – note the extra num2str):

if profileInfo.Overhead==0
    s{end+1} = sprintf(['<p><a name="selftimedef"></a>', getString(message('MATLAB:profiler:SelfTime1st')) ' ']);
else
    s{end+1} = sprintf(['<p><a name="selftimedef"></a>', getString(message('MATLAB:profiler:SelfTime2nd', num2str(profileInfo.Overhead)))]);end

if profileInfo.Overhead==0 s{end+1} = sprintf(['<p><a name="selftimedef"></a>', getString(message('MATLAB:profiler:SelfTime1st')) ' ']); else s{end+1} = sprintf(['<p><a name="selftimedef"></a>', getString(message('MATLAB:profiler:SelfTime2nd', num2str(profileInfo.Overhead)))]); end

Turning the overhead switch on causes the message at the bottom of the profiling summary report to change, from something that says:

Self time is the time spent in a function excluding the time spent in its child functions. Self time also includes overhead resulting from the process of profiling.

To this (the numeric value is the computed overhead, also reported in profData.overhead):

Self time is the time spent in a function excluding both the time spent in its child functions and most of the overhead resulting from the process of profiling.
In the present run, self time excludes 0.80601 seconds of profiling overhead. The amount of remaining overhead reflected in self time cannot be determined.

A similar customization needs to be done to fix an error arising from the use of the undocumented profile -timer none option. I don’t really see great value in running a Profiler without timing information, so I’ll skip this part here. If anyone has an idea what this could be used for, I’d be happy to hear.

[As-yet] unsolved mysteries

To conclude my series on undocumented profiling options, a couple of unsolved mysteries:

hardware profiling

The profview.m function has several references to hardware performance counter data, which, if available as fields in profData.FunctionTable, are displayed as separate columns to the left of the time column field in the code section, and also enabled for the sorting and highlighting drop-downs in the detailed profiling report. Separate monitored hardware events are stored in separate fields named profData.FunctionTable.HWevent (see the getHwFields() sub-function on lines 1557-1564). The mystery: how can we tell the Profiler to start hardware monitoring in a way that would add these HW fields to the collected profData.FunctionTable? Lines 1652-1653 give a hint:

hw_events = callstats('hw_events');
match = strcmpi(['hw_' str],hw_events);

hw_events = callstats('hw_events'); match = strcmpi(['hw_' str],hw_events);

Unfortunately, at least on my system, callstats('hw_events') returns an empty cell array:

>> hw_events = callstats('hw_events')
hw_events =
   Empty cell array: 1-by-0

>> hw_events = callstats('hw_events') hw_events = Empty cell array: 1-by-0

So if anyone has an idea how to use these HW events, I’d be happy to hear – please leave a comment below.

parallel profiling

Another mystery relates to the question of how to profile parallel Matlab code. The underlying Java object of the Profiler tool (com.mathworks.mde.profiler.Profiler.getInstance) contains the following tell-tale methods:

  • getHtmlTextParallel(), setHtmlTextParallel()
  • getInstanceWithParallelOpts()
  • getSelectedLabsFromHtml()
  • setNumLabs()
  • setNumLabsParallel()
  • setSelectedLab()


I would have expected the parallel-enabled Profiler to be started using com.mathworks.mde.profiler.Profiler.getInstanceWithParallelOpts.invoke(). This does indeed start the Profiler, but I can’t see any difference between its output and that of the normal Profiler, even when I run parallel (parfor) code. It definitely does not look like output from the Parallel Computing Toolbox (PCT)’s mpiprofile function.
Perhaps these methods are used by mpiprofile internally? It could make sense for both profile and mpiprofile to share the same underlying profiler tool. On the other hand, if this were indeed the case then why would there be a reason for a separate mpiprofile function? Wouldn’t the standard profile function be sufficient?
Anyway, if anyone has an idea how to use these methods in the standard profiler, perhaps to profile parallel applications without the need for pmode, I’d be happy to hear – please leave a comment below.

Conclusion

The Matlab Profiler has quite a few important features, which for some unknown reason have not been made public. Matlab’s Profiler has remained stagnant since Matlab 7 was released last decade. In fact, some functionality, like the JIT information feature, was actually removed. Hopefully, future Matlab releases will improve the Profiler, by making these undocumented features officially supported, as well as by adding other important functionality.
This concludes my series on undocumented profiling features in Matlab. If anyone knows any other Profiler tricks, please share them in a comment below.

Related posts:

  1. Undocumented Profiler options part 3 – An undocumented feature of the Matlab Profiler can report call history timeline - part 3 of series. ...
  2. Undocumented profiler options – The Matlab profiler has some undocumented options that facilitate debugging memory bottlenecks and JIT (Just-In-Time Java compilation) problems....
  3. Undocumented Profiler options part 2 – Several undocumented features of the Matlab Profiler can make it much more useful - part 2 of series. ...
  4. Buggy Profiler option – a bug exists in the profiler that prevents usage of its documented CPU timing functionality. ...
  5. More undocumented timing features – There are several undocumented ways in Matlab to get CPU and clock data...
  6. uiundo – Matlab's undocumented undo/redo manager – The built-in uiundo function provides easy yet undocumented access to Matlab's powerful undo/redo functionality. This article explains its usage....
callstats Performance Profiler Pure Matlab
Print Print
« Previous
Next »
One Response
  1. Michael November 9, 2012 at 13:35 Reply

    Useful article! I discovered that calls to load() on a very small file take up a third of the entire processing time on my function.
    On a side note, the fix to profview.m doesn’t seem to be necessary for 2011b and perhaps earlier versions, as the (presumably) entire message is hard-coded into the sprintf call and so profileInfo.Overhead is converted through sprintf, as shown:

    s{end+1} = sprintf(['<a></a><strong>Self time</strong> is the time spent in a function excluding both the time spent in its ', ...
                            'child functions and most of the overhead resulting from the process of profiling. ', ...
                            'In the present run, self time excludes %4.3f seconds of profiling overhead. ', ...
                            'The amount of remaining overhead reflected in self time cannot be determined.'], profileInfo.Overhead);

    s{end+1} = sprintf(['<a></a><strong>Self time</strong> is the time spent in a function excluding both the time spent in its ', ... 'child functions and most of the overhead resulting from the process of profiling. ', ... 'In the present run, self time excludes %4.3f seconds of profiling overhead. ', ... 'The amount of remaining overhead reflected in self time cannot be determined.'], profileInfo.Overhead);

Leave a Reply
HTML tags such as <b> or <i> are accepted.
Wrap code fragments inside <pre lang="matlab"> tags, like this:
<pre lang="matlab">
a = magic(3);
disp(sum(a))
</pre>
I reserve the right to edit/delete comments (read the site policies).
Not all comments will be answered. You can always email me (altmany at gmail) for private consulting.

Click here to cancel reply.

Useful links
  •  Email Yair Altman
  •  Subscribe to new posts (feed)
  •  Subscribe to new posts (reader)
  •  Subscribe to comments (feed)
 
Accelerating MATLAB Performance book
Recent Posts

Speeding-up builtin Matlab functions – part 3

Improving graphics interactivity

Interesting Matlab puzzle – analysis

Interesting Matlab puzzle

Undocumented plot marker types

Matlab toolstrip – part 9 (popup figures)

Matlab toolstrip – part 8 (galleries)

Matlab toolstrip – part 7 (selection controls)

Matlab toolstrip – part 6 (complex controls)

Matlab toolstrip – part 5 (icons)

Matlab toolstrip – part 4 (control customization)

Reverting axes controls in figure toolbar

Matlab toolstrip – part 3 (basic customization)

Matlab toolstrip – part 2 (ToolGroup App)

Matlab toolstrip – part 1

Categories
  • Desktop (45)
  • Figure window (59)
  • Guest bloggers (65)
  • GUI (165)
  • Handle graphics (84)
  • Hidden property (42)
  • Icons (15)
  • Java (174)
  • Listeners (22)
  • Memory (16)
  • Mex (13)
  • Presumed future risk (394)
    • High risk of breaking in future versions (100)
    • Low risk of breaking in future versions (160)
    • Medium risk of breaking in future versions (136)
  • Public presentation (6)
  • Semi-documented feature (10)
  • Semi-documented function (35)
  • Stock Matlab function (140)
  • Toolbox (10)
  • UI controls (52)
  • Uncategorized (13)
  • Undocumented feature (217)
  • Undocumented function (37)
Tags
AppDesigner (9) Callbacks (31) Compiler (10) Desktop (38) Donn Shull (10) Editor (8) Figure (19) FindJObj (27) GUI (141) GUIDE (8) Handle graphics (78) HG2 (34) Hidden property (51) HTML (26) Icons (9) Internal component (39) Java (178) JavaFrame (20) JIDE (19) JMI (8) Listener (17) Malcolm Lidierth (8) MCOS (11) Memory (13) Menubar (9) Mex (14) Optical illusion (11) Performance (78) Profiler (9) Pure Matlab (187) schema (7) schema.class (8) schema.prop (18) Semi-documented feature (6) Semi-documented function (33) Toolbar (14) Toolstrip (13) uicontrol (37) uifigure (8) UIInspect (12) uitable (6) uitools (20) Undocumented feature (187) Undocumented function (37) Undocumented property (20)
Recent Comments
Contact us
Captcha image for Custom Contact Forms plugin. You must type the numbers shown in the image
Undocumented Matlab © 2009 - Yair Altman
This website and Octahedron Ltd. are not affiliated with The MathWorks Inc.; MATLAB® is a registered trademark of The MathWorks Inc.
Scroll to top