One specific line of a function is taking too long

I am having issues with a particular function. Also, it is a very simple one, with very quick calculations in it. It serves to assemble the stiffness matrix in a Finite Element Analysis. All it does is: takes a 3x3 matrix out of a bigger one and adds an already-calculated 3x3 to it. I started noticing strange calculation times, so I tried different ways to compute that, but the results are always the same. I'm posting the results of the Profiler run on the 3 different versions of this particular function. The weird thing is that Matlab always takes a huge amount of time to run the 1st row of the program, while going fairly quick with the others.

Version 1:

Version 2:

Version 3:

Has anybody got a clue about what's taking it so long?

Thanks.

[dpb]

I see you have both K as input and output...what's the dimension of K on input?

I'm guessing that K is being dynamically reallocated and that if you preallocated K to the maximum size initially you'd see the time taken in that initial line go down drastically.

[Alessandro]

Dimensions of the K matrix in input and output is the same (in this particular case around 1800x1800 elements). It is needed because this function is called inside a loop over the total number of elements. The matrix, anyways, is preallocated outside the loop to the correct dimensions and doesn't change size over the iterations.

[dpb]

Problem is if you modify an input argument in a function, Matlab creates a copy.

[per isakson]

Might not apply, but is worth reading: In-place Operations on Data

[Alessandro]

So, any suggestions?

[per isakson]

Why only the first line?

With R2013a this code

    val = randn( 1e4 );
    tic, val( 111,113 ) = val( 1111, 1133 ); toc

returns

    Elapsed time is 0.000004 seconds.

(The Task Manager does not show allocating of memory.)

[Alessandro]

That's what I am trying to find out. Apparently the problem is the fact that an input variable changes during the call. I will investigate this tomorrow. Anyways I'm using 2013a as well.

Answer 1

[per isakson]

This experiment on R2013a 64bit, Win7 and 8GB suggests

• try make K global
• a copy of val is created by cssm_passing_by_value(val) (and Task Manager confirms)
• however, it does not explain your 25s(?)

    >> global val
    >> val = randn( 1e4 );

    >> cssm_global() ;
    Elapsed time is 0.000007 seconds.        <<<<<<<<<<<<<<<<<
    Elapsed time is 0.000001 seconds.

    >> val = cssm_passing_by_value( val ) ;
    Elapsed time is 0.506452 seconds.        <<<<<<<<<<<<<<<<<<
    Elapsed time is 0.000003 seconds.
    >>

where

    function    cssm_global()
        global val
        tic, val( 111,113 ) = val( 1111, 1133 ); toc  
        tic, val( 119,119 ) = val( 5111, 5133 ); toc
    end

and where

    function    val = cssm_passing_by_value( val )
        tic, val( 111,113 ) = val( 1111, 1133 ); toc
        tic, val( 119,119 ) = val( 5111, 5133 ); toc
    end

and see In-place Operations on Data

.

Surprising result with passing "by value"

I've made another few confusing experiments. (I don't think confusing, because of mistakes on my part, but [...].) Here is one such result:

• the long execution time disappears when I successively pass the array to sub-functions and change an element at each level - unbelievable

    >> val = randn( 1e4 );
    >> val = cssm_passing( val );
    Elapsed time is 0.000004 seconds.           <<<<<<<<<<<<<<<<
    Elapsed time is 0.000001 seconds.

where ( I've renamed the old m-file se above.)

    function    val = cssm_passing ( val )
        val(1,1) = 1;
        val = sub_passing( val );
    end
    function    val = sub_passing( val )
        val(2,2) = 2;
        val = sub2_passing( val );
    end
    function    val = sub2_passing( val )
        tic, val( 111,113 ) = val( 1111, 1133 ); toc
        tic, val( 119,119 ) = val( 5111, 5133 ); toc
    end

I've tested with these three functions in one m-file and in three, respectively. The result was the same in both cases.

[Alessandro]

Not only it does not explain the 29sec (!!) operation, but things get worse and worse while K gets larger.

[per isakson]

• Most likely, the 29sec is not mainly because of the creation of the temporary copy of K.
• Have you watched the Windows Task Manager window when this is going on?
• What Matlab release do you use?
• Do you have enough physical memory?

You might want to read Undocumented Profiler options part 4 together with part 1, 2 and 3. There are undocumented features related to memory use.

[Alessandro]

I'll look at the Task Manager, trying to isolate the problem. I am using R2013a, on a i7 16Gb RAM machine.

[dpb]

What does

memory

show?

It's possible if you've been running and have large arrays while you've got plenty of physical memory it's become fragmented to the point there's not sufficient contiquous memory w/o swapping...

[Alessandro]

I don't have my PC with me during weekends, but I can add a new result: on a bigger problem, with K having size 1500x1500, I got a 19956.0s runtime (!!!).

[per isakson]

• That's five and an half hour. Something is terribly wrong.
• Did you try feature('accel','on/off')?
• Did you try to "pass" K as global?
• Send the problem to the tech support. Do you have a license that allows that?

[Alessandro]

This last result is obtained by the same model I had before. I can't access my PC on weekends, I just have it run and sendmail when it finishes running the script. Anyways that runtime is outrageous. Hope they are going to give me a good explanation for that!

Answer 2

[Alessandro]

New informations about the issue:

• Making K global doesn't change anything. Still same runtime.
• By-passing the function and pasting those 4 lines inside the main code, of course, solves the issue, but I honestly do not like to do that. Especially since I do not understand the reason why the error shows up.

This is the new runtime for those particular 4 lines of code (same as the "Version 1" in my original post):

0.02 compared to the previous 29 seconds is a 145000% difference. :D

[dpb]

Can you make this happen in a short piece of code with data? If so, paste it here so folks can compare. Also, you might submit it to TMW for comment/resolution altho you might choose to wait until forum folks have had a go at it (assuming you can do so).

[Alessandro]

I will try to. Not sure I can reproduce this huge amount of time-wasting, but I am guessing the issue can be easily reproduced in big loops.

[per isakson]

• You write "Making K global doesn't change anything. Still same runtime." That is not consistent with my result.
• I've added the result of another experiment to my answer. See above.

[Alessandro]

In my script, passing K to the function as global, did not change runtime. Still have no clue about this. Although your experiment proves it may speed things up. Also, it is very interesting that you noticed the long runtime disappears while using sub-functions!