Profiler biases execution time of optimized code

10 次查看（过去 30 天）
Olaf
Olaf 2011-10-18
Hi all,
I have got a problem with profile. It delivers some unexpected results when comparing two versions of the same algorithm, one written in Matlab and the other one invoked through a mex-file implementation.
I understand that profile measures the actual execution time and thus usually differs from the time measured when using for example tic and toc. That is not the problem.
What I observed first when profiling my script was that one particular function consumes about 63% (self time that is) of the entire execution time of the script. I went and optimized this function by implementing it in C and was happy to see that the execution time of the entire script according to profile was reduced from 170s down to 76s and the fraction of time that was spent in the optimized function was down to about 12% of the total execution time. Perfect, I thought, I overall gained more than 100% in performance.
Unfortunately the world looks different as soon as I turn off profile. Then, the script executes in about 24s with the original Matlab function and in about 21s with the optimized function, hence only 14% of performance gain. I would have expected the ratios of the execution times to be at least similar as to when profile was turned on.
That would mean, unless I have overseen something obvious, the results of profile are actually no indication whatsoever as to where the time in my code is really spent. Where am I mistaken?
Please help.
Thanks a lot in advance.
Olaf

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

采纳的回答

Jan
Jan 2011-10-19
The profiler disables the JIT acceleration of Matlab! This can lead to totally different timings.
Since Matlab 6.5 loops are optimized by the internal JIT-acceleration, such that the repeated calculations are performed much faster. To achieve this, the JIT can reorder the commands of the code. This would confuse the profiler, which looses the relation between code lines and time measurements. In consequence PROFILE disables the JIT completely.
The same behaviour appears, if you enable the debugger by setting a break point. To allow a line-by-line execution, the order of commands/lines must not be modified, and therefore the JIT is disabled, too.
Therefore the PROFILEr, the standard tool for speed optimizations, has a very limited use for optimizing code, which profits from the JIT. Strange, isn't it?
Inserting TIC/TOCs is more reliable.
  3 个评论
显示 1更早的评论
Olaf
Olaf 2011-10-19
Thanks to you both. That sheds some light on the issue. It makes the choice of default options for the profiler, to say the least, questionable :(
Jan
Jan 2011-10-19
In former releases the profiler showed messages about lines, which could not be optimized by the JIT, but the JIT itself did not run.

请先登录，再进行评论。

更多回答（1 个）

Daniel Shub
Daniel Shub 2011-10-19
In order to profile your code MATLAB needs to do a little extra work. In general, I think this extra work is minimal. In your case before optimization your code takes 170 seconds with the profiler and 24 seconds without. I think this indicates something unusual (not necessarily wrong) about your code. It is quite possible that the mex file changes the overhead associated with profiling.
I would suspect that the portion of your code that you optimized is called many times and for some reason the overhead of profiling is a significant portion of the task.
  3 个评论
显示 1更早的评论
Daniel Shub
Daniel Shub 2011-10-19
I wouldn't expect this. At some point the profiler stops digging down into the code. I think when it hits a mex file, but maybe when it hits java or private functions. I wouldn't expect running the code with the profiler turned on to take 7.5 times as long.
Olaf
Olaf 2011-10-19
The mex file shows up in the results page, hence it is not excluded by the profiler.
Thanks for your reply in any case.

请先登录，再进行评论。

类别

在 Help Center 和 File Exchange 中查找有关 Solver Outputs and Iterative Display 的更多信息

标签

产品

Community Treasure Hunt

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

Start Hunting!

Translated by