Performance tuning - finding CPU time

2013 7 19
3 个回答
7 次查看（30 天）

1 个投票

Hi -
I have a Matlab function (my code) that takes about 1.5ms to run most of the time, but every once in a while spikes up - 10ms, 15ms, 20ms, or even higher. I would like to figure out why.
I may have to do this with other functions in future - so my question is not about this specific piece of code, but rather about how to debug this type of a problem in Matlab.
1) tic/toc - Above timings were done using tic/toc. Natural question is - since I am measuring elapsed time, are my outlier purely due to things like thread switches, etc. etc.? If so, would setting processor affinity of the Matlab process help?
2) cputime - I tried using cputime - for a lot of my calls, the cputime returns zero even when tic/toc returns a non-zero value. Has anyone experienced this?
3) Profiler - Pretty useless in this case I think - it reports average times. Well, on average, the function performs just fine. I am trying to track down the outliers, and I don't quite see how the Profiler can be helpful here.
Thanks in advance! matal

请先登录，再回答此问题。

回答（3 个）

per isakson
per isakson 2013-7-19
编辑：per isakson 2013-7-19

1 个投票

See
They link to other resources on timing.
BTW: Which OS do you use?
.
cputime
First time ever(?) I try cputime. The resolution is poor (0.0156s on Windows 7, R2012a 64bit). That's why you see ZERO.
>> t = cputime; surf(peaks(40)); e = cputime-t
e =
0.2028
>> t = cputime; surf(peaks(40)); e = cputime-t
e =
0.0624
>> t = cputime; surf(peaks(40)); e = cputime-t
e =
0.0156
>> t = cputime; surf(peaks(40)); e = cputime-t
e =
0.0156
>> t = cputime; surf(peaks(40)); e = cputime-t
e =
0.0312
>> t = cputime; surf(peaks(40)); e = cputime-t
e =
0.0156
>> t = cputime; surf(peaks(40)); e = cputime-t
e =
0

6 个评论
显示 4更早的评论 隐藏 4更早的评论

matal
matal 2013-7-19
1) TIMEIT - Thanks I had seen this in my googling and I checked again after you suggested it - it uses tic/toc, i.e. elapsed time. I would have thought a way to measure cpu time / cycles would be the most accurate way to do this, no?
2) Is this bug still open?
FYI - I am using R2010b on Windows XP, but will deploy on R2009a/Linux (my current production environment).
matal
matal 2013-7-19
Also - just to be clear - my function is not stateless, so repeated calls change state and the spikes may be related to that too. Something like TIMEIT (i haven't read thru all the code yet, mind you) seems to be more of a fit for a stateless math function.
Seems to me if the profiler could provide me with a distribution of times per line along with a way of viewing execution times for selected iterations of my timing loop, that's what I am looking for.
I am currently having to put tic/toc around selected lines within the function, returning the times out of the function, and having the driver generate distributions and execution paths.... if you see what i mean?
per isakson
per isakson 2013-7-19
编辑：per isakson 2013-7-19
1) TIMEIT runs the function several times, excludes the first (few?) and report an average for the rest. More important than the code is the rational for TIMEIT.
2) AFAIK: Yes! (I'm not sure about the status of this "issue", whether it is a BUG with an ID and all that.)
The behavior, "spikes", you report is not typical - I dare to say. Have you seen it with many different m-files?
matal
matal 2013-7-19
And the problem is - when the spikes are due to tic/toc timing, i am not quite sure whether that's "real" or that's due to perhaps a task switch in the middle by the OS.
matal
matal 2013-7-19
1) Thanks - I am assuming the rationale is "warm up". I do one call to warm up and then do ~2000 calls and look at a chart of their times - so if there was a consistent pattern (early calls slow, later calls faster), I would know by now.
Further - I am calling out to mex files and external C++ libraries - the intermittent spike problem may well be with one of those calls.
But what I am hoping to do is this - scientifically establish the exact line(s) of code that are resulting in the spikes. Using tic/toc isn't precise in this case since they are elapsed time.....
2) Hmm. Let me check with Mathworks.
It seems to me now (given your point re profile above and cputime) that Matlab actually doesn't provide me with a precise way to measure CPU time - this will be tremendously disappointing to say the least.
per isakson
per isakson 2013-7-19
编辑：per isakson 2013-7-19
Regarding the "inner workings" Matlab is a black box and The Mathworks wants too keep it that way.
"scientifically establish the exact line(s) of code that are resulting in the spikes." Sounds difficult to me. Don't forget the accelerator and just-in-time-compiler.
See More undocumented timing features

请先登录，再进行评论。

Yair Altman
Yair Altman 2013-7-20
编辑：Yair Altman 2013-7-20

1 个投票

The Profiler DOES provide detailed information about specific call invocations, but you need to dig a bit in its undocumented raw data. This is explained here: http://undocumentedmatlab.com/blog/undocumented-profiler-options-part-3/
Naturally, the raw data begs for someone to write a utility that presents the info in a more human-readable manner. I would have done it myself if I had any time - maybe someone else will pick up the glove (Jan? Per? anyone?)

1 个评论
显示 -1更早的评论 隐藏 -1更早的评论

matal
matal 2013-7-22
Thank you much! This seems almost exactly what I am looking for - I will dig into this a bit later when I return to working on this portion of the code.
I say "almost exactly" because your link above says "we can run profile with the undocumented/unsupported –timestamp switch, which stores the CPU clock next to the history information".
Still not clear to me that a context/thread/process switch (what's the right term?) in the middle of my function will not bias the timings. Am I even right to worry about such external factors as being the potential cause for the spike?
And finally - why are these functionalities undocumented??? I am relatively new to Matlab - am I trying to push this product into areas where it's not meant to go (highly time critical, real-time processing)?

请先登录，再进行评论。

Jan
Jan 2013-7-19

0 个投票

Measuring the timing can be influenced by other applications also. E.g. the garbage collection of the operating system's memory manager. Or the WLAN adapter checks the connection. I do not think that the source of the delays can be reliably determined in every case. So a strategy for measuring timings is to exclude the outliers from the statistics.

1 个评论
显示 -1更早的评论 隐藏 -1更早的评论

matal
matal 2013-7-22
Excluding outliers is not an option when spikes such as this in our calculation code may have material implications for production business logic. The production system will ensure no such external factors. However, in testing, I need to rule out our (internal) code being the cause of such spikes - hence my question about how to do accurate timing.

请先登录，再进行评论。

类别

在 帮助中心 和 File Exchange 中查找有关 Historical Contests 的更多信息

产品

标签

提问:

matal
matal
2013-7-19

Community Treasure Hunt

Find the treasures in MATLAB Central and discover how the community can help you!

Start Hunting!

Translated by