Factorization twice as slow on 0.6 than 0.5 #21624

jebej · 2017-04-28T23:29:02Z

A = rand(40,40);
@benchmark sqrtm($A)

0.6: (55c97fb)

BenchmarkTools.Trial:
  memory estimate:  269.69 KiB
  allocs estimate:  26
  --------------
  minimum time:     3.855 ms (0.00% GC)
  median time:      3.999 ms (0.00% GC)
  mean time:        4.105 ms (0.53% GC)
  maximum time:     12.227 ms (15.49% GC)
  --------------
  samples:          1216
  evals/sample:     1

0.5.1:

BenchmarkTools.Trial:
  memory estimate:  269.69 KiB
  allocs estimate:  26
  --------------
  minimum time:     1.731 ms (0.00% GC)
  median time:      1.795 ms (0.00% GC)
  mean time:        1.868 ms (1.13% GC)
  maximum time:     9.239 ms (0.00% GC)
  --------------
  samples:          2653
  evals/sample:     1

The text was updated successfully, but these errors were encountered:

fredrikekre · 2017-04-29T00:29:11Z

Its due to these regression as noted in #20993:

| ["linalg","factorization",("schur","Matrix",1024)] | 2.10 (45%) ❌ | 1.00 (1%) |
| ["linalg","factorization",("schur","Matrix",256)] | 2.36 (45%) ❌ | 1.00 (1%) |
| ["linalg","factorization",("schurfact","Matrix",1024)] | 2.09 (45%) ❌ | 1.00 (1%) |
| ["linalg","factorization",("schurfact","Matrix",256)] | 2.36 (45%) ❌ | 1.00 (1%) |

jebej · 2017-04-29T00:31:20Z

Right. Do we have an idea what caused those? Isn't that all handled by Lapack? A factor of two seems high.

fredrikekre · 2017-04-29T01:14:11Z

Code path have not changed, and not the lapack wrapper either. But the factor 2 are there:

julia> A = rand(256, 256); cA = complex(A);

julia> @btime LinAlg.LAPACK.gees!('V', copy($cA)); # 0.6
  200.070 ms (11 allocations: 2.14 MiB)

julia> @btime LinAlg.LAPACK.gees!('V', copy($cA)); # 0.5.1
  90.971 ms (11 allocations: 2.14 MiB)

andreasnoack · 2017-04-29T01:17:31Z

Same version of OpenBLAS?

…

On Fri, Apr 28, 2017 at 9:14 PM, Fredrik Ekre ***@***.***> wrote: Code path have not changed, and not the lapack wrapper either. But the factor 2 are there: julia> A = rand(256, 256); cA = complex(A); julia> @Btime LinAlg.LAPACK.gees!('V', copy($cA)); # 0.6 200.070 ms (11 allocations: 2.14 MiB) julia> @Btime LinAlg.LAPACK.gees!('V', copy($cA)); # 0.5.1 90.971 ms (11 allocations: 2.14 MiB) — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#21624 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAe0qUeD2AFiY749y_zjxaeVXBdd4zdcks5r0o7kgaJpZM4NMES8> .

jebej · 2017-04-29T01:25:08Z

Nothing obvious shows up when profiling.
0.6:

194 .\REPL[2]:1; macro expansion
 3   .\array.jl:126; copy(::Array{Complex{Float64},2})
 191 .\linalg\lapack.jl:5586; gees!(::Char, ::Array{Complex...

0.5.1:

66 .\REPL[27]:1; macro expansion;
 65 .\linalg\lapack.jl:5584; gees!(::Char, ::Array{Complex{Float64},2})
 1  .\linalg\lapack.jl:5596; gees!(::Char, ::Array{Complex{Float64},2})

fredrikekre · 2017-04-29T01:42:42Z

Same version of OpenBLAS?

Yes, I have just compiled the default for master and 0.5.1 and OpenBLAS version does not seem to have changed?

fredrik@fredrik-desktop:~$ cat julia-master/deps/openblas.version 
OPENBLAS_BRANCH=v0.2.19
OPENBLAS_SHA1=85636ff1a015d04d3a8f960bc644b85ee5157135

fredrik@fredrik-desktop:~$ cat julia-release/deps/openblas.version 
ifneq (,$(filter $(ARCH), powerpc64le ppc64le))
OPENBLAS_BRANCH=v0.2.19
OPENBLAS_SHA1=85636ff1a015d04d3a8f960bc644b85ee5157135
else
OPENBLAS_BRANCH=v0.2.18
OPENBLAS_SHA1=12ab1804b6ebcd38b26960d65d254314d8bc33d6

jebej · 2017-04-29T23:51:31Z

Would it be an issue with the ccall then?

KristofferC · 2017-04-30T07:58:26Z

These calls should be long enough for ccall overhead not to matter. Perhaps some difference in build flags used?

jebej · 2017-05-01T18:07:20Z

I can't compile julia from scratch (Windows) but is there an archive of old nightlies to see if I can identify when the problem started occurring? I think this is a pretty big issue that really should be fixed...

tkelman · 2017-05-01T18:54:02Z

julianightlies.s3.amazonaws.com goes back about a month

stevengj · 2017-05-01T18:54:19Z

I thought sqrtm was supposed to be faster in 0.6 from #20214.

jebej · 2017-05-01T18:59:15Z

According to this report the regressions date from before March 8th.

stevengj · 2017-05-01T19:16:48Z

@jebej, #20214 was merged on Feb 3; can you check whether it is the source of the regression?

jebej · 2017-05-01T19:22:32Z

I believe that PR seems was only for sqrtm of Upper Triangular matrices. The regressions in the OP was sqrtm for generic matrices, which uses schurfact, and thus gees.

stevengj · 2017-05-01T19:28:42Z

@jebej, schurfact is used to get an upper triangular matrix from an arbitrary matrix, at which point the sqrtm code calls sqrtm(UpperTriangular(SchurF[:T])). So, #20214 still seems relevant.

stevengj · 2017-05-01T19:30:14Z

Oh, but I see that you are specifically benchmarking gees above and still seeing a slowdown.

jebej · 2017-05-01T19:34:36Z

You're right, my mistake. Yes, the slowdown seems to be with gees in that case, and there is a similar one with geevx.

stevengj · 2017-05-01T19:54:29Z

I can't reproduce the gees! slowdown on my Mac:

julia> A = rand(256, 256); cA = complex(A);

julia> @btime LinAlg.LAPACK.gees!('V', copy($cA));  # 0.5.1
  257.194 ms (11 allocations: 2.14 MiB)

julia> @btime LinAlg.LAPACK.gees!('V', copy($cA)); # 0.6
  251.435 ms (11 allocations: 2.14 MiB)

stevengj · 2017-05-01T19:55:45Z

Could it be a threading issue on your machine? Try BLAS.set_num_threads(1).

jebej · 2017-05-01T20:00:40Z

Is the optimization level the same between macOS and Linux? I vaguely recall a change from -O3 to -O2 for some dependencies, but I can't find the issue.

jebej · 2017-05-01T20:01:59Z

It's not just my machine, the slowdown is detected by nanosoldier.

fredrikekre · 2017-05-01T21:02:27Z

I can't reproduce the gees! slowdown on my Mac

I just tried on my Mac as well and I still see a slowdown with a factor 2...

andreasnoack · 2017-05-03T01:27:17Z

It might be useful if people would report versioninfo() as well. Maybe we can narrow down if this only happens on some architectures.

fredrikekre · 2017-05-03T05:57:47Z

I can see a slowdown of 2 (or more) on the following 3 setups (comparing 0.5.1 and the release-0.6 branch):

julia> versioninfo()
Julia Version 0.6.0-pre.beta.460
Commit 63ae651* (2017-05-02 12:18 UTC)
Platform Info:
 OS: Linux (x86_64-linux-gnu)
 CPU: Intel(R) Core(TM) i5-7600K CPU @ 3.80GHz
 WORD_SIZE: 64
 BLAS: libopenblas (USE64BITINT NO_AFFINITY HASWELL)
 LAPACK: libopenblas64_
 LIBM: libopenlibm
 LLVM: libLLVM-3.9.1 (ORCJIT, broadwell)

julia> versioninfo()
Julia Version 0.6.0-pre.beta.460
Commit 63ae651d91* (2017-05-02 12:18 UTC)
Platform Info:
 OS: macOS (x86_64-apple-darwin16.5.0)
 CPU: Intel(R) Core(TM) i5-4258U CPU @ 2.40GHz
 WORD_SIZE: 64
 BLAS: libopenblas (USE64BITINT DYNAMIC_ARCH NO_AFFINITY Haswell)
 LAPACK: libopenblas64_
 LIBM: libopenlibm
 LLVM: libLLVM-3.9.1 (ORCJIT, haswell)

julia> versioninfo()
Julia Version 0.6.0-pre.beta.460
Commit 63ae651 (2017-05-02 12:18 UTC)
Platform Info:
 OS: Linux (x86_64-linux-gnu)
 CPU: Intel(R) Core(TM) i7-6600U CPU @ 2.60GHz
 WORD_SIZE: 64
 BLAS: libopenblas (USE64BITINT DYNAMIC_ARCH NO_AFFINITY Haswell)
 LAPACK: libopenblas64_
 LIBM: libopenlibm
 LLVM: libLLVM-3.9.1 (ORCJIT, skylake)

fredrikekre · 2017-05-03T07:02:49Z

I am so confused. With this:

using BenchmarkTools
function benchmark()
    versioninfo()
    A = rand(256, 256)
    cA = complex(A)
    for i in 1:3
        println(minimum(@benchmark LinAlg.LAPACK.gees!('V', copy($cA))))
    end
end
benchmark()

I get the following on the same commit the only difference being that one is from the release-0.6 branch and the other is on the master branch.

609b3d1 checked out from master:

julia> benchmark()
Julia Version 0.6.0-pre.beta.459
Commit 609b3d1* (2017-05-02 04:05 UTC)
Platform Info:
  OS: Linux (x86_64-linux-gnu)
  CPU: Intel(R) Core(TM) i7-6600U CPU @ 2.60GHz
  WORD_SIZE: 64
  BLAS: libopenblas (USE64BITINT DYNAMIC_ARCH NO_AFFINITY Haswell)
  LAPACK: libopenblas64_
  LIBM: libopenlibm
  LLVM: libLLVM-3.9.1 (ORCJIT, skylake)
TrialEstimate(252.737 ms)
TrialEstimate(247.091 ms)
TrialEstimate(218.330 ms)

609b3d1 checked out from release-0.6:

julia> benchmark()
Julia Version 0.6.0-pre.beta.459
Commit 609b3d1 (2017-05-02 04:05 UTC)
Platform Info:
  OS: Linux (x86_64-linux-gnu)
  CPU: Intel(R) Core(TM) i7-6600U CPU @ 2.60GHz
  WORD_SIZE: 64
  BLAS: libopenblas (USE64BITINT DYNAMIC_ARCH NO_AFFINITY Haswell)
  LAPACK: libopenblas64_
  LIBM: libopenlibm
  LLVM: libLLVM-3.9.1 (ORCJIT, skylake)
VERSION
TrialEstimate(513.989 ms)
TrialEstimate(514.151 ms)
TrialEstimate(504.442 ms)

fredrikekre · 2017-05-03T11:15:05Z

So it turns out that my directory for the master branch has a fast version of libopenblas, and compiling from scratch (which I did for the release-0.6 version) compiles a slow version. I just tried compiling everything from scratch and that results in a slow version.

My conclusion is that some build flags must have changed, but did not trigger a recompile of the library in my master directory (which I have been updating continuously).

ViralBShah · 2017-05-03T11:50:23Z

Can you figure out what openblas incantations get the performance back? Is this something to do with DYNAMIC_ARCH detection?

tkelman added performance Must go faster regression Regression in behavior compared to a previous version labels Apr 28, 2017

jebej changed the title ~~sqrtm slower on 0.6 than 0.5~~ Factorization twice as slow on 0.6 than 0.5 Apr 29, 2017

fredrikekre mentioned this issue May 3, 2017

Recover some lost build flags for openblas #21688

Merged

tkelman closed this as completed in #21688 May 4, 2017

maleadt mentioned this issue May 16, 2017

Build fixes for ASAN #21902

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Factorization twice as slow on 0.6 than 0.5 #21624

Factorization twice as slow on 0.6 than 0.5 #21624

jebej commented Apr 28, 2017

fredrikekre commented Apr 29, 2017

jebej commented Apr 29, 2017

fredrikekre commented Apr 29, 2017

andreasnoack commented Apr 29, 2017 via email

jebej commented Apr 29, 2017

fredrikekre commented Apr 29, 2017

jebej commented Apr 29, 2017

KristofferC commented Apr 30, 2017

jebej commented May 1, 2017

tkelman commented May 1, 2017

stevengj commented May 1, 2017

jebej commented May 1, 2017

stevengj commented May 1, 2017

jebej commented May 1, 2017 •

edited

Loading

stevengj commented May 1, 2017

stevengj commented May 1, 2017

jebej commented May 1, 2017

stevengj commented May 1, 2017 •

edited

Loading

stevengj commented May 1, 2017

jebej commented May 1, 2017

jebej commented May 1, 2017

fredrikekre commented May 1, 2017

andreasnoack commented May 3, 2017

fredrikekre commented May 3, 2017

fredrikekre commented May 3, 2017

fredrikekre commented May 3, 2017

ViralBShah commented May 3, 2017

Factorization twice as slow on 0.6 than 0.5 #21624

Factorization twice as slow on 0.6 than 0.5 #21624

Comments

jebej commented Apr 28, 2017

fredrikekre commented Apr 29, 2017

jebej commented Apr 29, 2017

fredrikekre commented Apr 29, 2017

andreasnoack commented Apr 29, 2017 via email

jebej commented Apr 29, 2017

fredrikekre commented Apr 29, 2017

jebej commented Apr 29, 2017

KristofferC commented Apr 30, 2017

jebej commented May 1, 2017

tkelman commented May 1, 2017

stevengj commented May 1, 2017

jebej commented May 1, 2017

stevengj commented May 1, 2017

jebej commented May 1, 2017 • edited Loading

stevengj commented May 1, 2017

stevengj commented May 1, 2017

jebej commented May 1, 2017

stevengj commented May 1, 2017 • edited Loading

stevengj commented May 1, 2017

jebej commented May 1, 2017

jebej commented May 1, 2017

fredrikekre commented May 1, 2017

andreasnoack commented May 3, 2017

fredrikekre commented May 3, 2017

fredrikekre commented May 3, 2017

fredrikekre commented May 3, 2017

ViralBShah commented May 3, 2017

jebej commented May 1, 2017 •

edited

Loading

stevengj commented May 1, 2017 •

edited

Loading