bugGNU Octave - Bugs: bug #58445, significant slow down in stable...

 
 

bug #58445: significant slow down in stable version for cellfun invocations which use function handles

Submitter:  A.R. Burgers <arb>
Submitted:  Mon 25 May 2020 09:21:39 PM UTC
   
 
Category:  Interpreter Severity:  4 - Important
Priority:  5 - Normal Item Group:  Performance
Status:  Confirmed Assigned to:  None
Originator Name:  Open/Closed:  * Open
Release:  * dev Operating System:  * GNU/Linux
Fixed Release:  None Planned Release:  None
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Sun 28 Jan 2024 07:02:09 PM UTC, comment #15: 

Splitting this example into bm1.m (@numel loop only) and bm2.m
("numel" loop only). Also increased N to 1e6.

octave:1> profile on
octave:2> bm1
Time for cellfun (@numel, C) : 11.454379
octave:3> profile off
octave:4> profshow
   #  Function Attr     Time (s)   Time (%)        Calls
--------------------------------------------------------
  26   cellfun             7.104      64.97      1000000
   1       bm1             3.059      27.97            1
  27     numel             0.771       7.05      4000000
   2     magic    R        0.000       0.00            5
  17    fliplr             0.000       0.00            2


octave:1> profile on
octave:2> bm2
Time for cellfun ("numel", C) : 3.036819
octave:3> profile off
octave:4> profshow
   #  Function Attr     Time (s)   Time (%)        Calls
--------------------------------------------------------
   1       bm2             2.324      79.13            1
  26   cellfun             0.612      20.85      1000000
   2     magic    R        0.000       0.01            5
  17    fliplr             0.000       0.01            2

(where are the numel calls?)

Also attached are uProf screenshots (bm1_uprof.png and bm2_uprof.png for each run.

Dmitri.
--



Dmitri A. Sergatskov <dasergatskov>
Sun 28 Jan 2024 05:32:54 PM UTC, comment #14: 

Somehow we left this regression alone for 3 years, but the slowdown is still there.

I wrote another small test before re-discovering this bug report.  The code is attached.



N = 1e5;

C = {magic(2), magic(3), magic(4), magic(5)};

tic;
for i = 1:N
  n = cellfun (@numel, C);
end
printf ('Time for cellfun (@numel, C) : %f\n', toc);

tic;
for i = 1:N
  n = cellfun ("numel", C);
end
printf ('Time for cellfun ("numel", C) : %f\n', toc);


Results are


Time for cellfun (@numel, C) : 0.705530
Time for cellfun ("numel", C) : 0.202134


Still a significant slowdown for "accelerated" function names.


(file #55632)

Rik <rik5>
Group administrator
Thu 05 Nov 2020 08:01:39 PM UTC, comment #13: 

Retagging the release as "dev".  Any further performance fixes will have to be applied to default and deferred until Octave 7.

John W. Eaton <jwe>
Group administrator
Sun 14 Jun 2020 02:41:21 AM UTC, comment #12: 

Same comparison in version 5.2 using the unaccelerated function sum()


cellfun('sum'): 1.2765 secs
cellfun(@sum):  1.34633 secs


Essentially no difference between using a function or a string.

Rik <rik5>
Group administrator
Sat 13 Jun 2020 06:31:00 PM UTC, comment #11: 

Updating the timings after the function handle refactoring.  These times are on the stable branch (6.0.90).


cellfun('numel'): 0.012671 secs
cellfun(@numel):  2.44392 secs


The function handle is still orders of magnitude slower, but it is also far better than the 17.4 seconds before.

But, "numel" is one of the accelerated functions so it might be better to compare to an unaccelerated function.  I used the same benchmark from comment #1 but substituted sum() for numel().  Results are


cellfun('sum'): 0.999322 secs
cellfun(@sum):  3.2546 secs


So, for some reason it is still 3X slower to use function handles rather than strings.


Rik <rik5>
Group administrator
Wed 27 May 2020 11:54:24 AM UTC, comment #10: 

Rik: Yeah, both of those functions probably need to be refactored or rewritten.  I hope it will become easier after the function handle refactoring is done.

John W. Eaton <jwe>
Group administrator
Tue 26 May 2020 10:29:21 PM UTC, comment #9: 

@jwe: WTF? Matlab behavior.  They decide to have a specific input to cellfun which calculates numel(), but then call it "prodofsize".  And, as they indicate, if you use a string rather than a function handle then overloading does not occur.  It's as if you called builtin ("function_name").

Rik <rik5>
Group administrator
Tue 26 May 2020 09:48:55 PM UTC, comment #8: 

@Rik:
It's more that I remembered it to be around that time (2010-2012 or so), but I needed google to help me find it back.

But there must be also another posting from (IIRC) you in either the bug tracker or maintainers ML where you benchmarked again and found function handles to be generally faster than function names in cellfun(). Based on that I've always preferred function handles since .... which now turns out to be wrong.
Oh well ...

Philip Nienhuis <philipnienhuis>
Group Member
Tue 26 May 2020 09:00:00 PM UTC, comment #7: 

@Philip: Wow, you found that old thread.  I only had a vague memory that this had been discussed before.

@jwe: cacheing seems like a good solution.  Also, it is one of my pet peeves that arrayfun() was programmed to parse its arguments and then hand off execution to cellfun().  This results in a big slowdown because, for arrayfun(), the function and the datatype are known upfront.  There is only one signature that is ever needed, but by delegating to cellfun the code has to assume that the data type might change for every value through the loop.

Rik <rik5>
Group administrator
Tue 26 May 2020 08:36:11 PM UTC, comment #6: 

As to comment #2, I remember from a long time ago (many years) that, IIRC in response to an earlier mailing list posting, Rik and Jordi benchmarked cellfun calls. See here:
https://lists.gnu.org/archive/html/octave-maintainers/2011-08/msg00087.html

Philip Nienhuis <philipnienhuis>
Group Member
Tue 26 May 2020 08:16:12 PM UTC, comment #5: 

Thanks and sorry for the trouble.  I should have just looked at the docs.

But under the description for the "func" argument it says that functions may be passed by name but that it only works for a subset of function names and "numel" is not included in the list.  So it looks like we were attempting to handle "numel" in addition to "prodofsize" (What?  I don't even remember any mention of that one before now!?).

When we have a string argument, we have special cases that dispatch directly to octave_value methods, which explains why those are fast.

With function handles we are currently doing a function lookup in all cases.  In the past we tried to avoid that but I think our check for the case of no function overloads could be incorrect, so that's why it was removed and cellfun became slower.

We should be able to do better by doing lookups more efficiently when we see the same types for a given function name.  I'm thinking of caching the exact function to call based on the list of argument types, but maybe there is a better way?

John W. Eaton <jwe>
Group administrator
Tue 26 May 2020 07:12:06 PM UTC, comment #4: 

Matlab responds with


Error using cellfun
unknown option

Error in foo (line 11)
  cellfun ('numel', x)


The documentation says that cellfun only accepts handles to functions, not the string name.  See https://www.mathworks.com/help/matlab/ref/cellfun.html.

Commenting out that code and re-running gives


ans = [13, 13]


So, it is picking up the handle to the subfunction.

Rik <rik5>
Group administrator
Tue 26 May 2020 05:21:24 PM UTC, comment #3: 

I'm pretty sure I caused the problem with this changeset:

http://hg.savannah.gnu.org/hgweb/octave/annotate/8bd9fd99c12a/libinterp/corefcn/cellfun.cc#l468

What does Matlab do if "numel" (for example) is a handle to a subfunction or nested function?  In that case, does it still call the built-in numel or does it call the subfunction and (probably fail)?  Here's an example:


function foo ()
  x = {1, [2,3;4,5]};
  %% Do both of the following do the same thing?
  %% Do they call the built-in numel function for
  %% each element of the cell array or do they call
  %% the numel subfunction defined in this file?
  cellfun ('numel', x)
  cellfun (@numel, x)
end
function r = numel (x)
  % subfunction
  r = 13;
end


With an answer to the above, I can probably fix the problem.

John W. Eaton <jwe>
Group administrator
Tue 26 May 2020 03:12:04 PM UTC, comment #2: 

Something like this has been an issue before.  I can't find the bug report, but I remember that using a function handle was slower than using the string name (such as 'numel') for the function.

Rik <rik5>
Group administrator
Tue 26 May 2020 03:08:16 PM UTC, comment #1: 

Confirmed.  This is yet another example of the reason why we need a set of performance tests, as well as the tests for correct function that we already have, so that as developers we don't accidentally introduce massive slowdowns.

I thought at first it might be a problem with for loops, because your tic/toc bracket included the cellfun call and the for loop.  There was also a repeatability issue in that the test used random data so there was the possibility that the data for one version was longer and required more processing.  I wrote a new performance benchmark which is attached as tst_cellfun_perf.m and shown below.


nrep = 1e3;

## Load same test variable for repeatability
load cellfun.var;

## Call function once so all m-files necessary are parsed.
## Otherwise, first time through loop will be slower than others.
cellfun ('numel', aa);

bm1 = zeros (nrep, 1);
for j = 1 : nrep
  tic;
  cellfun ('numel', aa);
  bm1(j) = toc;
end
fprintf ('cellfun(''numel''): %g secs\n', sum (bm1));

bm2 = zeros (nrep, 1);
for j = 1 : nrep
  tic;
  cellfun(@numel, aa);
  bm2(j) = toc;
end
fprintf('cellfun(@numel):  %g secs\n', sum (bm2));


The data for the test is created just once with


aa = num2cell (rand (1000,3), 2);
save -binary cellfun.var


which is also attached as mk_cellfun_tst_var.m.

Results are


6.0.90
------------------------------------------------------------
cellfun('numel'): 0.0420563 secs
cellfun(@numel):  17.388 secs

5.2.0
------------------------------------------------------------
cellfun('numel'): 0.019412 secs
cellfun(@numel):  0.025914 secs


The difference in performance between the two versions for @numel is 671X!



(file #49176, file #49177)

Rik <rik5>
Group administrator
Mon 25 May 2020 09:21:39 PM UTC, original submission:  

Certain cellfun invocations have slowed down a lot, a factor 1000 in this example, for cellfun(@numel). For cellfun('numel') the cellfun call is also a factor 2.5 slower, but not as dramatic as in the function handle case.

octave 5.2.1 timings:

ver = 5.2.1
cellfun('numel'): 0.128928 secs
cellfun(@numel):  0.00182199 secs


octave-6.0.1 timings:

ver = 6.0.1
cellfun('numel'): 0.304217 secs
cellfun(@numel):  2.28019 secs


Here is the test script that times cellfun(@numel) and cellfun('numel').


ver = version

% aa: 1000x1 cell vector, each cell containing a 1x3 row vector
aa = num2cell(rand(1000,3), 2);

tic;
nrep = 10000;
for j = 1 : nrep
  cellfun('numel', aa);
end
fprintf('cellfun(''numel''): %g secs\n', toc);

tic;
nrep = 100;
for j = 1 : nrep
  cellfun(@numel, aa);
end
fprintf('cellfun(@numel):  %g secs\n', toc);


A.R. Burgers <arb>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #55633:  bm1_uprof.png added by dasergatskov (122KiB - image/png)
file #55634:  bm2_uprof.png added by dasergatskov (124KiB - image/png)
file #55632:  bm_cellfun_handle.m added by rik5 (263B - text/x-objcsrc)
file #49176:  tst_cellfun_perf.m added by rik5 (515B - text/x-matlab)
file #49177:  mk_cellfun_tst_var.m added by rik5 (59B - text/x-matlab)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by dasergatskov (Updated the item)
  • -email is unavailable- added by jwe (Posted a comment)
  • -email is unavailable- added by rik5 (Updated the item)
  • -email is unavailable- added by arb (Submitted the item)
  •  

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

    Only group members can vote.

     

    Follow 9 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2024-01-28 dasergatskov Attached File- Added bm1_uprof.png, #55633
        Attached File- Added bm2_uprof.png, #55634
    2024-01-28 rik5 Attached File- Added bm_cellfun_handle.m, #55632
    2020-11-05 jwe Release6.0.90 dev
    2020-05-26 rik5 Summarysignificant slow down in dev version for certain cellfun invocations significant slow down in stable version for cellfun invocations which use function handles
    2020-05-26 rik5 Attached File- Added tst_cellfun_perf.m, #49176
        Attached File- Added mk_cellfun_tst_var.m, #49177
        Severity3 - Normal 4 - Important
        StatusNone Confirmed

    Back to the top

    Powered by Savane 3.13-4448.
    Corresponding source code