MATLAB: Implausible execution times

jitMATLABtic toc

I teach a university course on numerical methods and MATLAB. I assigned my students to evaluate the execution times for various operations. Specifically, I had them compare the following two cases:

    format short
    tic
    for i=1:1000
        for j=1:1000
            for k=1:1000
                x=k;
            end
        end
    end
    toc

versus this:

    format short
    tic
    for i=1:1000
        for j=1:1000
            for k=1:1000
                x=j+k;
            end
        end
    end
    toc

The second code with the added addition operation reproducibly takes significantly (~30%) less execution time than the first. This seemingly implausible result appears to occur in version R2011b and not earlier versions (although I haven't done an exhaustive test). Any explanation for this? (BTW, the same result holds if the addition is replaced by a multiplication).

Best Answer

J I T - Matlab's magic, efficient and poorly documented JustInTime accelerator can understand some loop constructions. Then the performance can be increases dramatically in some cases, e.g. in your 2nd example. When the loop contents does not match to a pattern recognized by the JIT, or if some external functions are included, the JIT looses its power.

Try to measure the speed with a disabled JIT:

feature('jit', 'off')
feature('accel', 'off')

I'm not sure, if these are synonyms.

Another way to disable the JIT is setting a breakpoint (behind the toc - otherwise the timings are not usable) or starting the profiler. The later is a serious problem, because the results of the profiler are not really useful without considering the effects of the JIT. Debugging and profiling must collide with the JIT, because these procedure require a line-by-line procesing of the code - but the JIT can combine or re-order lines to increase the efficiency.

Related Solutions

MATLAB: Profiler biases execution time of optimized code

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.

MATLAB: Are the times took for consequent tocs not consistent

I would personally use multiple tic tocs instead of tic then multiple tocks. tic tocs are meant to be used as a pair, that's the primay function. Although your usage is supported, it's probably be so by logistics in an obscure way, (e.g. 1st toc release resources and 2nd toc need to dig the last used tic ID from somewhere.) If one uses multiple tocs for less critical timings (several milliseconds) it will be fine. In your case you are measurement is back to front. In addition, the documentation says it is much more accuracte to loop over multiple calculations between the tic and the toc if the calculations take too short of a time.

If you modify your code to include the tic IDs the picture changes, supporting my 'logistics' theory. Now the 1st toc uses slightly more time than the second, than the 3rd, and similar from then on. 2nd still uses more than the 3rd probably as it still have to check through why am I being called a 2nd time and set stage for the 3rd and so on.

for i = 1:k
    ID = tic;
    tocs(i,1) = toc(ID); 
    tocs(i,2) = toc(ID); % the second toc!
    tocs(i,3) = toc(ID); 
    tocs(i,4) = toc(ID);
    tocs(i,5) = toc(ID);
    tocs(i,6) = toc(ID);
    pause(0.001); % this also affects the results.
end

If you run paired tic tocs:

for i = 1:k
    pause(0.001); 
    for j=1:6
    tic;
    tocs(i,j) = toc; 
    end
end
elapsed = tocs;

Then, only the first toc take longer than the rest, which is forgiveable.

In anycase, you would not use tic toc for measuring very fast timings like this. If you need to do so, use:

tic
for i=1:1000
%some fast code%
end
time = toc;
time = time/1000;

Best Answer

Related Solutions

MATLAB: Profiler biases execution time of optimized code

MATLAB: Are the times took for consequent tocs not consistent

Related Question