MATLAB Magical Mystery timing behavior

Question

I am experiencing some very odd timing behavior from a function I wrote. If I wrap my function inside another empty container function, it gets a 3x speedup.

>> tic; foo(args); toc

time elapsed: ~140 seconds

>>tic; bar(args); toc

time elapsed: ~35 seconds

Here's the kicker - the definition of bar():

define bar(args)

foo(args)

end

Is there some sort of optimization that gets triggered in MATLAB for nested function calls? Should I be adding a dummy function to every function that I write?

Answer 1

Have you tried foo a second time without clearing variables? I'm unable to reproduce this performance increase if I run it repeatedly. Else, it does seem faster but that's only because MATLAB does precompile these functions if you run them once.

function barfoo    

    for i = 1:Inf
    end    

end

And,

function foobar        
    barfoo();
end

Answer 2

I don't know if you have tried running your code multiple times, but one potential explanation I've noticed is that the very first run of a newly updated file is usually slower than subsequent runs (I assume due to compiling). I'm guessing you may see different timing for the third line of the following (called after modifying foo):

tic; foo(args); toc;  % First call of foo
tic; bar(args); toc;  % Second call of foo inside bar
tic; foo(args); toc;  % Third call of foo

Answer 3

This is surprising behavior. An intermediate function call should not speed things up like that.

Try profiling it and see where it's spending its time. This is the best first resort to almost any "Why is my Matlab code slow?" question.

clear all
profile on -timer real
foo(args);
profile report
%read the report and save a screencap
clear all
profile clear
bar(args);
profile report

There ends the advice. Here starts the speculation.

There are a couple things that are different in the two calls. There is workspace interaction. Calling foo() from the command line may leave the variable "ans" populated in your workspace. When called from bar(), ans will be set but then immediately cleared when bar() returns. Also, the foo() may be using evalin()/assignin() to look into workspaces up the call stack, and it may interact with variables assigned in your base workspace. The bar() function has a clean workspace.

Depending on where bar.m is, it may actually be invoking a different foo(), or maybe resolving it slightly differently. Check your path resolution with "which foo" in both contexts.

Depending on how "args" is defined, different inputname()s may be visible to foo.

Also, foo() may contain pathological code that checks whether it is being called from the base workspace, or even whether it's being called by a function of a particular name, and behaves differently based on that.

That said, these should mostly be minor interactions and shouldn't cause a slowdown of that order. I'd suspect something else was going on, maybe just exposed by slightly different calling contexts. Adding a level of indirection with bar() shouldn't be the answer. See what the profiler has to say and go from there. Exact code to reproduce will help a lot in getting assistance from the community.

Answer 4

The JIT accelerator does not operate on command line expressions as far as I know. Thus, when you run "tic; foo(args); toc" foo's code runs entirely in the MATLAB interpreter. However, when you run "tic; bar(args); toc", bar is evaluated in the interpreter and the JIT accelerator takes a shot at compiling the call to foo() to native code.

I'm really waving my hands over the details, but that's the gist of it. Details for MATLAB's JIT capabilities are hard to come by; most of what I've found is on Loren's blog at The MathWorks. The closest authoritative statement I can find about the command line being interpreter-only is here: http://blogs.mathworks.com/loren/2006/05/10/memory-management-for-functions-and-variables/#comment-207