Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

20+ minute precompilation regression on v0.6.1 #24383

Closed
ChrisRackauckas opened this issue Oct 28, 2017 · 20 comments
Closed

20+ minute precompilation regression on v0.6.1 #24383

ChrisRackauckas opened this issue Oct 28, 2017 · 20 comments
Labels
compiler:latency Compiler latency regression Regression in behavior compared to a previous version

Comments

@ChrisRackauckas
Copy link
Member

From here: SciML/DifferentialEquations.jl#209

We see a >20 minute compile time regression, along with post-compilation using statements taking as long as precompilation used to take. @mauro3 noted that it may not occur on Linux though, but latest Travis tests seem to show that this regression is widespread.

@mauro3
Copy link
Contributor

mauro3 commented Oct 28, 2017

Chris narrowed it down to BoundaryValueDiffEq.jl. I ran the pre-compilation of for both Julia 0.6 versions and see a 4x regression:

Here the comparison of v0.6.0 and v0.6.1 of precompilation of BoundaryValueDiffEq.jl (with the __precompile__() statement active here):

              _
   _       _ _(_)_     |  A fresh approach to technical computing
  (_)     | (_) (_)    |  Documentation: https://docs.julialang.org
   _ _   _| |_  __ _   |  Type "?help" for help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 0.6.0 (2017-06-19 13:05 UTC)
 _/ |\__'_|_|_|\__'_|  |
|__/                   |  x86_64-pc-linux-gnu

julia> @time using BoundaryValueDiffEq
INFO: Recompiling stale cache file /home/mauro/.julia/lib/v0.6/BoundaryValueDiffEq.ji for module BoundaryValueDiffEq.
315.972758 seconds (9.44 M allocations: 690.993 MiB, 0.06% gc time)
   _       _ _(_)_     |  A fresh approach to technical computing
  (_)     | (_) (_)    |  Documentation: https://docs.julialang.org
   _ _   _| |_  __ _   |  Type "?help" for help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 0.6.1 (2017-10-24 22:15 UTC)
 _/ |\__'_|_|_|\__'_|  |  
|__/                   |  x86_64-pc-linux-gnu

julia> @time using BoundaryValueDiffEq                                                                                                                                   
INFO: Recompiling stale cache file /home/mauro/.julia/lib/v0.6/BoundaryValueDiffEq.ji for module BoundaryValueDiffEq.                                                    
1120.472693 seconds (17.77 M allocations: 1.298 GiB, 0.06% gc time)                                                                                                      

@JeffBezanson JeffBezanson added the regression Regression in behavior compared to a previous version label Oct 28, 2017
@JeffBezanson
Copy link
Member

Also on master. I notice that BandedMatrices.ji is about 120MB, apparently due to excessive inference. I suspect #21677, as much as I like that change.

@ChrisRackauckas
Copy link
Member Author

BoundaryValueDiffEq is the only library in the DiffEq stack that has BandedMatrices.jl, so that seems like that's where it is. I'll remove BoundaryValueDiffEq.jl for now from DifferentialEquations.jl to isolate the problem.

@JeffBezanson
Copy link
Member

I tried bisecting this. It's a little tricky since it seems to have regressed in two steps, where BandedMatrices.ji went from 20MB to 80MB to 120MB. Unfortunately the culprit from bisecting is #23012. That was definitely a bugfix, which means the bug was an accidental optimization. Frankly, even 20MB is way too big for this package, so I suspect we're doing too much inference, and the bug caused us to skip saving a bunch of stuff that actually didn't matter. We end up spending lots of time in jl_recache_types (loading lots of types takes longer than saving them).

@ChrisRackauckas
Copy link
Member Author

Pinging @dlfivefifty

@dlfivefifty
Copy link
Contributor

Commenting out precompile fixes this issue, though that's probably not the ideal solution.

@mauro3
Copy link
Contributor

mauro3 commented Oct 29, 2017

But a package which has __precompile__() in it, will then still precompile BandedMatrices.jl, unless you set __precompile__(false), but then any packages depending on it can not have precompilation enabled.

@dlfivefifty
Copy link
Contributor

The issue is not the __precompile__(), it's the precompile.jl file with a list of functions to precompile (from SnoopCompile.jl).

@dlfivefifty
Copy link
Contributor

So I meant comment out the include("precompile.jl") line

@JeffBezanson
Copy link
Member

This is related to the unions of matrix types like StridedMatrix. One thing that fixes it is to set MAX_UNION_SPLITTING in inference to 1 (disabling it). Long term, it would be nice to replace those type unions. For now, we might be able to hack around it in inference.

@dlfivefifty
Copy link
Contributor

I think StridedMatrix would work better as a trait. This would allow other, non-Base, matrix types to dispatch to the right BLAS routines.

JeffBezanson added a commit that referenced this issue Oct 29, 2017
reduce O(n^2) behavior of `jl_recache_types`

these help #24383
JeffBezanson added a commit that referenced this issue Oct 29, 2017
reduce O(n^2) behavior of `jl_recache_types`

these help #24383
JeffBezanson added a commit that referenced this issue Oct 30, 2017
reduce O(n^2) behavior of `jl_recache_types`

improve soundness of inferred typevar bounds in subtyping

these help #24383
JeffBezanson added a commit that referenced this issue Oct 30, 2017
reduce O(n^2) behavior of `jl_recache_types`

improve soundness of inferred typevar bounds in subtyping

these help #24383
JeffBezanson added a commit that referenced this issue Nov 14, 2017
reduce O(n^2) behavior of `jl_recache_types`

improve soundness of inferred typevar bounds in subtyping

these help #24383
ararslan pushed a commit that referenced this issue Nov 14, 2017
…24399)

reduce O(n^2) behavior of `jl_recache_types`

improve soundness of inferred typevar bounds in subtyping

these help #24383
@tknopp
Copy link
Contributor

tknopp commented Jan 21, 2018

Is here anything that can be done?

I tracked down why Images.jl loads so long and its

julia> @time using FileIO
 25.040638 seconds (19.17 M allocations: 1.065 GiB, 1.07% gc time)

This is pretty long for such a core package like FileIO which cannot be avoided (I need Images.jl)

Is there any workaround?

@tknopp
Copy link
Contributor

tknopp commented Jan 22, 2018

Switching back to Julia 0.6.0 solves the performance issue. Is this fixed on master? I know that 1.0 is about feature completeness but 25 seconds and 1GB allocations for a tiny package like FileIO sound more like a bug to me.

@KristofferC
Copy link
Member

KristofferC commented Feb 5, 2018

Can you try deleting your FileIO.ji precompilation file and try again.

@tknopp
Copy link
Contributor

tknopp commented Feb 5, 2018

currently not since I changed to 0.6.0 and need that environment right now. I missed to cross-ref JuliaIO/FileIO.jl#156

@ViralBShah
Copy link
Member

Is this still an issue? Perhaps an update?

@ViralBShah ViralBShah added the compiler:latency Compiler latency label Jun 11, 2018
@tknopp
Copy link
Contributor

tknopp commented Jun 11, 2018

under 0.6.3

               _
   _       _ _(_)_     |  A fresh approach to technical computing
  (_)     | (_) (_)    |  Documentation: https://docs.julialang.org
   _ _   _| |_  __ _   |  Type "?help" for help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 0.6.3 (2018-05-28 20:20 UTC)
 _/ |\__'_|_|_|\__'_|  |  Official http://julialang.org/ release
|__/                   |  x86_64-apple-darwin14.5.0

julia> @time using FileIO
  8.100726 seconds (4.97 M allocations: 279.204 MiB, 0.75% gc time)

so still way too slow. (if you were interested in 0.6.3 timing)

@ViralBShah
Copy link
Member

Sorry for not being clear - is it an issue in 0.7-alpha too? Good to see that at least its better than the 25 seconds.

@ViralBShah
Copy link
Member

ViralBShah commented Jun 12, 2018

Well can't really do 0.7 testing yet, because of the deprecation warnings. With all the deprecations being printed, I got 15 seconds on a fairly newish server.

@ViralBShah
Copy link
Member

On the original issue posted here (BoundaryValueDiffEq), I got the whole thing in 0.6.3 in 64 seconds. I did a Pkg.add(), which brought in a bunch of dependent packages for the first time as well.

I propose closing this and tracking compile-time regressions in a new/existing 0.7/1.0 related issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
compiler:latency Compiler latency regression Regression in behavior compared to a previous version
Projects
None yet
Development

No branches or pull requests

7 participants