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

Buggy Profiler option

October 31, 2012 6 Comments

During my work on the recent series of articles on undocumented Profiler options, I came across a very odd bug. Apparently, a major documented Profiler functionality has been dysfunctional since at least R2008a (and probably earlier), and AFAIK was not reported until now.
The functionality in question is the Profiler’s documented ability to display results in either wall-clock (profile -timer real) or CPU-time (profile -timer cpu) modes. In fact, at least since R2008a and possibly sooner (I’m unsure about earlier releases), at least on Windows (I’m unsure about other platforms), both of these Profiler options provide wall-clock measurements – CPU-time measurements is not available. The irony is that CPU mode is stated in the documentation to be the Profiler’s default mode, and has been this way ever since this option was introduced about a decade ago.
I used a very simple test harness – prepare the following function in test.m:

function test
    pause(2)
end

function test pause(2) end

And now run it in the Profiler:

>> profile on -timer cpu
>> test
>> profile off; profile report

>> profile on -timer cpu >> test >> profile off; profile report

If everything had worked as documented, the Profiler report would show the test function as taking no time at all, or maybe only a few millisecs of overhead. In fact, this is exactly what we see in Matlab release R14 SP3 (7.1, dated 2005):

Correct CPU-time profiling report (R14 SP3)
Correct CPU-time profiling report (R14 SP3)

Unfortunately, on R2008a and later (and possibly also some earlier releases), the same profiling run reports the timing as taking 2 full seconds (=wall-clock time):
Bug: wall-clock timing instead of CPU-time (R2008a+)
Bug: wall-clock timing instead of CPU-time (R2008a+)


You might assume that the built-in pause function has a bug that causes it to churn the CPU, and in that case the Profiler’s report would be correct. However, a quick check in the Task Manager (I actually use Process Explorer that I find much better) proves that this is not the case – no discernible CPU-time is used by the Matlab process during the pause.
Somewhere between R2006a and R2008a a bug was introduced that caused the Profiler to only use wall-clock mode.
Note that even in R14 SP3 the situation is not perfect: I have found that the default mode (i.e., when not specifying the -timer mode explicitly) is sometimes wall-clock and sometimes CPU, with no apparent consistency. However, if we explicitly use the -timer option, it works ok.
It is strange that such a feature has escaped everyone’s attention (the community’s no less than MathWorks’) for so many years. It is true that this is not an often-used functionality, and it is also true that the profile function itself it way under-utilized by the general public. Still, anyone who needs to do serious performance tuning must have used this feature at some point in time. When performance-tuning code, it is very important to be aware of both the wall-clock and the CPU-time of the profiled program. Different tuning strategies apply to these two modes. Relying only on wall-clock timing can lead to incorrect conclusions about the application’s hotspots, and therefore to sub-optimal tuning. So I am very surprised that this bug was not reported until now. I’ve reported it (1-K1I06V) lately, and I really hope that it will be fixed in R2013a.

Related posts:

  1. tic / toc – undocumented option – Matlab's built-in tic/toc functions have an undocumented option enabling multiple nested clockings...
  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 4 – Several undocumented features of the Matlab Profiler can make it much more useful - part 4 of series. ...
  4. Undocumented Profiler options part 2 – Several undocumented features of the Matlab Profiler can make it much more useful - part 2 of series. ...
  5. Undocumented Profiler options part 3 – An undocumented feature of the Matlab Profiler can report call history timeline - part 3 of series. ...
  6. Function call timeline profiling – A new utility enables to interactively explore Matlab function call timeline profiling. ...
Performance Profiler Pure Matlab
Print Print
« Previous
Next »
6 Responses
  1. Malcolm Lidierth November 4, 2012 at 11:00 Reply

    From the command line:

    profile on -timer cpu;
    pause(2);
    profile off;
    profile report

    profile on -timer cpu; pause(2); profile off; profile report

    works as expected giving:

    No profile information to display.

    But making test.m a script gives the same result as the function.

  2. Eric S December 11, 2012 at 13:22 Reply

    Yair, from what I remember hearing from a TMWer, the ability to measure CPU time has become more and more meaningless over time as things such as hyperthreading, complex pipelining, and multi-core/CPU technologies have been developed. I wouldn’t be surprised if CPUTIME went away in a future version (or just returned wall time), and the same thing could happen with the profiler. See the note at the end of the following doc page: http://www.mathworks.com/help/matlab/matlab_prog/analyzing-your-programs-performance.html

    Maybe you could post a question on CSSM or email one of the blog owners to see if they can clarify all of this 🙂

    • Yair Altman December 11, 2012 at 14:06 Reply

      @Eric – I think that even in a modern environment there can be a use for both CPU and wall clock profiling: The former highlights algorithmic hotspots, whereas the latter highlights I/O hotspots, for example.

      As for your suggestion to fish for clarifications via CSSM/blogs, there was actually a recent CSSM thread that posted on the same day as my article (a pure coincidence – I usually prepare my articles several days before posting). Anyway, that CSSM thread did not get a response from any MathWorker. This blog has very high visibility at TMW, so all the relevant people there are now well aware of my post. No official response was given here, not because they are not aware of this, but because they chose not to do so. You shouldn’t read too much into this – there can be numerous reasons why they chose not to respond (in fact, they do respond very rarely here, but not for lack of interest).

      • Eric S December 12, 2012 at 10:17

        Thanks Yair – but what I remember hearing was that technically, being able to measure CPU time has become more challenging (or maybe not possible accurately?). Maybe this was specific to Windows? Either way I’m trying to remember a conversation from 5 years ago, so you’ll have to excuse my rustiness 🙂

        Cheers

  3. Dan S. December 12, 2012 at 23:52 Reply

    On 64-bit linux “-timer cpu” and “-timer real” are definitely different. I recently found the default “-timer cpu” to be somewhat uselessly unpredictable on a quad-core cpu on linux, and verified the same issues back at least to 2010a. Slight changes in the code would show up as major profile differences on lines before the change, and profiled times often disagreed with tic/toc too substantially to make any sense. According to the mathworks rep it was at least partly because I profiled a script rather than a function, although why this should be was not explained. I’ve used the default timer for years, but no more.

  4. Tim Holy December 15, 2012 at 03:23 Reply

    At least as of 2011 (and may still be true), perhaps the biggest difference between the CPU and wall clock options is how they handle multithreading. It seems that CPU time does something along the lines of summing the time spent by all processors. On systems with many CPUs, this can be pretty confusing: for example, I’ve found that it’s possible to come to the conclusion that repmat is faster than bsxfun, which I’ve never found to be true in reality.

    Switching to wall time is now one of my startup.m settings.

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
ActiveX (6) 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) uitools (20) Undocumented feature (187) Undocumented function (37) Undocumented property (20)
Recent Comments
  • Nicholas (3 days 21 hours ago): Hi Yair, Thanks for the reply. I am on Windows 10. I also forgot to mention that this all works wonderfully out of the editor. It only fails once compiled. So, yes, I have tried a...
  • Nicholas (3 days 21 hours ago): Hi Yair, Thanks for the reply. I am on Windows 10. I also forgot to mention that this all works wonderfully out of the editor. It only fails once compiled. So, yes, I have tried a...
  • Yair Altman (4 days 4 hours ago): Nicholas – yes, I used it in a compiled Windows app using R2022b (no update). You didn’t specify the Matlab code location that threw the error so I can’t help...
  • Nicholas (5 days 0 hours ago): Hi Yair, Have you attempted your displayWebPage utility (or the LightweightHelpPanel in general) within a compiled application? It appears to fail in apps derived from both R2022b...
  • João Neves (8 days 5 hours ago): I am on matlab 2021a, this still works: url = struct(struct(struct(struct(hF ig).Controller).PlatformHost). CEF).URL; but the html document is empty. Is there still a way to do...
  • Yair Altman (11 days 4 hours ago): Perhaps the class() function could assist you. Or maybe just wrap different access methods in a try-catch so that if one method fails you could access the data using another...
  • Jeroen Boschma (11 days 6 hours ago): Never mind, the new UI components have an HTML panel available. Works for me…
  • Alexandre (11 days 7 hours ago): Hi, Is there a way to test if data dictionnatry entry are signal, simulink parameters, variables … I need to access their value, but the access method depends on the data...
  • Nicholas (11 days 21 hours ago): In case anyone is looking for more info on the toolbar: I ran into some problems creating a toolbar with the lightweight panel. Previously, the Browser Panel had an addToolbar...
  • Jeroen Boschma (15 days 4 hours ago): I do not seem to get the scrollbars (horizontal…) working in Matlab 2020b. Snippets of init-code (all based on Yair’s snippets on this site) handles.text_explorer...
  • Yair Altman (43 days 6 hours ago): m_map is a mapping tool, not even created by MathWorks and not part of the basic Matlab system. I have no idea why you think that the customizations to the builtin bar function...
  • chengji chen (43 days 13 hours ago): Hi, I have tried the method, but it didn’t work. I plot figure by m_map toolbox, the xticklabel will add to the yticklabel at the left-down corner, so I want to move down...
  • Yair Altman (51 days 6 hours ago): @Alexander – this is correct. Matlab stopped including sqlite4java in R2021b (it was still included in 21a). You can download the open-source sqlite4java project from...
  • Alexander Eder (57 days 1 hour ago): Unfortunately Matlab stopped shipping sqlite4java starting with R2021(b?)
  • K (63 days 12 hours ago): Is there a way to programmatically manage which figure gets placed where? Let’s say I have 5 figures docked, and I split it into 2 x 1, I want to place 3 specific figures on the...
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