bugGNU Octave - Bugs: bug #62358, Performance of Matrix...

 
 

bug #62358: Performance of Matrix Multiplication significantly slower in 7.1.0 compared to 6.1.0

Submitter:  Stefan Schlögl <schinzilord>
Submitted:  Sun 24 Apr 2022 04:42:27 PM UTC
   
 
Category:  Performance Severity:  3 - Normal
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

Mon 17 Oct 2022 06:56:10 AM UTC, comment #11: 

If that change caused the performance regression, it will probably take some code refactoring to avoid it. Imho, it might be better to handle that on the default branch.

Changing release to "dev".

Markus Mützel <mmuetzel>
Group administrator
Sat 15 Oct 2022 04:12:35 PM UTC, comment #10: 

Thanks for bisecting.

@jwe: Do we have an idea why using custom allocators would cause a performance decrease? Is there a way to get back to the previous performance?
Would it make a difference if we had a member in ArrayRep that we'd use as the allocator for the data in that class instead of the ArrayRep class itself being an allocator class?

-  class ArrayRep
+  class ArrayRep : public Alloc


Markus Mützel <mmuetzel>
Group administrator
Mon 25 Apr 2022 04:37:45 PM UTC, comment #9: 

Found it: https://hg.savannah.gnu.org/hgweb/octave/rev/298995435071
It's the one that adds custom memory allocators to Array.

Bisection trail:

$ hg bisect -g 8d7671609955    ## 6.4.0 known fast: 469 GFLOPS
$ hg bisect -b 04120d65778a    ## 7.1.0 known slow: 444 GFLOPS

Testing changeset 30510:84344af9b019 (320 changesets remaining, ~8 tests)
## 444 GFLOPS
$ hg bisect -b

Testing changeset 30370:dbff48b54dd2 (160 changesets remaining, ~7 tests)
## 467 GFLOPS
$ hg bisect -g

Testing changeset 30438:ad705550616c (80 changesets remaining, ~6 tests)
## 468 GFLOPS
$ hg bisect -g

Testing changeset 30473:b33ae3c094ac (40 changesets remaining, ~5 tests)
## 470 GFLOPS
$ hg bisect -g

Testing changeset 30492:e9a6d3822244 (20 changesets remaining, ~4 tests)
## 444 GFLOPS
$ hg bisect -b

Testing changeset 30486:298995435071 (10 changesets remaining, ~3 tests)
## 446 GFLOPS
$ hg bisect -b

Testing changeset 30480:83dbee7c8f08 (5 changesets remaining, ~2 tests)
## 468 GFLOPS
$ hg bisect -g

Testing changeset 30482:ddd58087ca97 (3 changesets remaining, ~1 tests)
## 468 GFLOPS
$ hg bisect -g

Testing changeset 30484:02b11b9f1e61 (2 changesets remaining, ~1 tests)
## 468 GFLOPS
$ hg bisect -g

The first bad revision is:
changeset:   30486:298995435071
branch:      stable
parent:      30484:02b11b9f1e61
user:        John W. Eaton <jwe@octave.org>
date:        Sat Dec 04 08:49:18 2021 -0500
summary:     allow custom allocators for the Array class


Arun Giridhar <arungiridhar>
Group Member
Mon 25 Apr 2022 02:13:42 PM UTC, comment #8: 

When there are changes in the build system like you mention with generated header files, I think the only reliable way to bisect is to start with a clean build tree and also to run the bootstrap script in the source tree for each build.  Using ccache will still help to speed things up significantly.

John W. Eaton <jwe>
Group administrator
Mon 25 Apr 2022 02:07:51 PM UTC, comment #7: 

@jwe, since the OpenBlas library is the same across all Octave versions for me, I ascribed the difference in performance to a mix of interpreter speed and any other changes made to the libinterp library. To eliminate the "for i = 1:100" loop:

  tic;
  c = a*b;  ## replicated 100 times
  t = toc;


A variant with cputime is:

    start = cputime;
    c = a*b;  ## replicated 100 times
    finish = cputime;
    t = finish - start;
    mf(j) = 1999 * 100/t;


The trend is the same as before though. Octave 8.0.0 and 7.1.0 (no major difference):

octave:3> bench_mmult_noloop
N = 1000
Method 2: MEAN GFLOPS single: 442.26854
Method 2: MAX GFLOPS single: 444.24100


Octave 6.1.0 and 6.4.0: (no major difference this time)

octave:3> bench_mmult_noloop
N = 1000
Method 2: MEAN GFLOPS single: 466.00226
Method 2: MAX GFLOPS single: 467.94603


The above were with tic/toc. The cputime variant gives lower numbers (divided by the number of CPU cores roughly) but the trend is still the same, being 5% to 7% slower for 7.1.0 compared to 6.4.0.

Bisection is difficult in the range from 6.4.0 to 7.1.0 because of changed libraries or missing files like this one:

config.status: error: cannot find input file: `oct-conf-post-private.in.h'

Does anyone know how to work around that?

Arun Giridhar <arungiridhar>
Group Member
Mon 25 Apr 2022 01:30:04 PM UTC, comment #6: 

The tic/toc functions measure wall-clock time, so for better results, please use cputime instead.

Are we sure that we aren't measuring a change in interpreter performance for looping and calling built-in functions?

John W. Eaton <jwe>
Group administrator
Mon 25 Apr 2022 01:16:35 PM UTC, comment #5: 

Octave 6.1.0 is nearly as fast as 5.2.0:

octave:3> bench_mmult
N = 1000
Method 2: MEAN GFLOPS single: 463.67590
Method 2: MAX GFLOPS single: 466.03481


Octave 6.4.0 is a little bit slower still:

octave:4> bench_mmult
N = 1000
Method 2: MEAN GFLOPS single: 460.57625
Method 2: MAX GFLOPS single: 461.59664
octave:5> bench_mmult
N = 1000
Method 2: MEAN GFLOPS single: 460.65557
Method 2: MAX GFLOPS single: 461.59766


There might not be just one change that causes the drop from 5.2.0 to 7.1.0 but it might have accumulated over time, which makes it more difficult to localize. But the bigger part of the drop seems to be between 6.4.0 and 7.1.0. This means I was likely mistaken in comment #1. Bisecting there next.

Arun Giridhar <arungiridhar>
Group Member
Mon 25 Apr 2022 12:40:41 PM UTC, comment #4: 

Thanks for confirmatoin!

I re-run my tests on Octave 5.2.0 (as part of Ubuntu 20.04 LTS release), and I get exactly the same performance as with Octave 6.1.0 (built from source by myself. Sources NEWS says version 6.1.0 (2020-11-26)).


Best,
Stefan

Stefan Schlögl <schinzilord>
Mon 25 Apr 2022 12:32:50 PM UTC, comment #3: 

I am in the process of bisecting. It is slow. So far I compared the runtimes based on the three versions of Octave I had and saw the slowdown from 5.2.0 to 7.1.0.

I too am not able to see why namespaces would affect performance. Also OP says that 6.1.0 is fast (I cannot replicate) but the change I listed happened between 5.2.0 and 6.1.0, so that too is inexplicable.

Will post what I get from bisecting when it's done.

Arun Giridhar <arungiridhar>
Group Member
Mon 25 Apr 2022 12:27:11 PM UTC, comment #2: 

@Arun: Did you bisect to that change? Is the performance better before and less after that change?
It would be surprising if moving functions to inside a namespace would have any effect on performance...

Markus Mützel <mmuetzel>
Group administrator
Mon 25 Apr 2022 12:00:27 PM UTC, comment #1: 

I get similar trends for both single and double. Roughly 6% slower for newer versions even using the same OpenBLAS.

Octave 8.0.0 dev:

octave:1> bench_mmult
N = 1000
Method 2: MEAN GFLOPS single: 439.98066
Method 2: MAX GFLOPS single: 444.30221


Octave 7.1.0:

octave:4> bench_mmult
N = 1000
Method 2: MEAN GFLOPS single: 434.11718
Method 2: MAX GFLOPS single: 444.75095


Octave 5.2.0:

octave:3> bench_mmult
N =  1000
Method 2: MEAN GFLOPS single: 464.80058
Method 2: MAX GFLOPS single: 470.33189
octave:4>


The mtimes function (same as the * operator) in data.cc has been unchanged for the versions tested above, and only calls binary_assoc_op_defun_body in data.cc, which too has been unchanged for the three versions and calls binary_op in ov.cc.

Digging deeper in ov.h and ov.cc, the relevant change to binary_op appears to be https://hg.savannah.gnu.org/hgweb/octave/rev/70cdf8de553d

changeset:   28631:70cdf8de553d
user:        John W. Eaton <jwe@octave.org>
date:        Thu Jul 30 16:16:04 2020 -0400
summary:     move non-member octave_value operator functions to octave namespace

That change in July 2020 was after 5.2.0 was released (Jan 2020) but before 6.1.0 (Nov 2020). (See https://wiki.octave.org/Release_History for the version number over time):

CCing jwe for his input. Is there a way to get the performance back?

Arun Giridhar <arungiridhar>
Group Member
Sun 24 Apr 2022 04:42:27 PM UTC, original submission:  

Upon performing performance tests of matrix multiplication, it appears that at least on my system the performance of Octave 7.1.0 is significantly slower compared to Octave 6.1.0 by roughly +7% calculation increase time.

The following code has been executed to estimate the multiplication performance:

N = 1000
    rand("seed",3298423492389472);
    a=single(rand(N,N));
    b=single(rand(N,N));
    for j=1:10
        tic;
        for i=1:100
            c=a*b;
        end
        t=toc;
        mf(j)=1999*100/t;
    end

    fprintf('Method 2: MEAN GFLOPS single: %5.5f\n',mean(mf ./ 1000))
    fprintf('Method 2: MAX GFLOPS single: %5.5f\n',max(mf)/1000)

After profiling the code snippet, the following emerged:
Octave 7.1.0:
Method 2: MEAN GFLOPS single: 317.06996
Method 2: MAX GFLOPS single: 319.74584

========   Profile Overview of 10 Functions   ========
   #   Function Attr     Time (s)   Time (%)        Calls
---------------------------------------------------------
  11   binary *             6.287      99.08         1010
   8       rand             0.039       0.62            3
   4 get_gflops             0.017       0.26            1
   9     single             0.002       0.04            2
  15       mean             0.000       0.00            1

Octave 6.1.0:
Method 2: MEAN GFLOPS single: 340.92255
Method 2: MAX GFLOPS single: 345.96801

========   Profile Overview of 10 Functions   ========
   #   Function Attr     Time (s)   Time (%)        Calls
---------------------------------------------------------
  11   binary *             5.844      98.96         1010
   8       rand             0.041       0.69            3
   4 get_gflops             0.018       0.31            1
   9     single             0.002       0.03            2
  15       mean             0.000       0.00            1

The performance degradation is seen in binary * multiplication operator. However, I assume that both Octave versions just call the same OpenBLAS version for matrix multiplication:
OpenBLAS 0.3.8

The following CPU is used:
Architektur:                     x86_64
CPU Operationsmodus:             32-bit, 64-bit
Byte-Reihenfolge:                Little Endian
Adressgrößen:                    39 bits physical, 48 bits virtual
CPU(s):                          8
Liste der Online-CPU(s):         0-7
Thread(s) pro Kern:              2
Kern(e) pro Socket:              4
Sockel:                          1
NUMA-Knoten:                     1
Anbieterkennung:                 GenuineIntel
Prozessorfamilie:                6
Modell:                          60
Modellname:                      Intel(R) Core(TM) i7-4790K CPU @ 4.00GHz
Stepping:                        3
CPU MHz:                         959.614
Maximale Taktfrequenz der CPU:   4400,0000
Minimale Taktfrequenz der CPU:   800,0000
BogoMIPS:                        7995.78
Virtualisierung:                 VT-x
L1d Cache:                       128 KiB
L1i Cache:                       128 KiB
L2 Cache:                        1 MiB

Have there been any further changes introduced in calling the binary multiplicator with Octave 7?
Best,
Stefan

Stefan Schlögl <schinzilord>

 

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

Attach Files:
   
   
Comment:
   

No files currently attached

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by mmuetzel (Posted a comment)
  • -email is unavailable- added by jwe (Posted a comment)
  • -email is unavailable- added by arungiridhar (Posted a comment)
  • -email is unavailable- added by arungiridhar
  • -email is unavailable- added by schinzilord (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 project members can vote.

     

    Follow 4 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2022-10-17 mmuetzel Release7.1.0 dev
    2022-04-25 mmuetzel Carbon-CopyRemoved 102357 -
    2022-04-25 arungiridhar StatusNone Confirmed
        Carbon-Copy- Added jwe

    Back to the top

    Powered by Savane 3.12