Julia: Dot calling in global scope has excessively long compilation time

Created on 10 Apr 2018  路  8Comments  路  Source: JuliaLang/julia

f(x) = x

0.6:

julia> @time f.(rand(2))
  0.170154 seconds (53.89 k allocations: 2.928 MiB)

0.7:

julia> @time f.(rand(2))
  4.075771 seconds (869.73 k allocations: 51.770 MiB, 0.41% gc time)

However, note on 0.7:

julia> f(x) = x
f (generic function with 1 method)

julia> g(x) = f.(x)
g (generic function with 1 method)

julia> @time g(rand(2)):
  0.069514 seconds (73.85 k allocations: 4.065 MiB, 10.33% gc time)

Is this related to the "fast path" of . in global scope cc @keno, @vtjnash?

broadcast performance

Most helpful comment

Ok, so:

0.1s -> 0.5s: 8b395aadc3b7459d8817e3a65b88bd422a983dc4
0.5s -> 0.8s: 8345b783993a61ba0e2865e11c51538e
0.8s -> 1.3s: 4ed54db82c50f046a32966dc1ae0
1.3s -> 1.6s: ?
1.6s -> 3.3s: bce5bbef9ba4b0a30a857d9

All 8 comments

Would be good to bisect this.

I happen to have a bunch of random branches already checked out and built:

# master/28e79562f4 (5 days ago)
julia> @time f.(rand(2))
  3.305299 seconds (1.11 M allocations: 66.015 MiB, 3.21% gc time)

# master/bf45de8c33 (15 days ago)
julia> @time f.(rand(2))
  1.633016 seconds (1.06 M allocations: 62.159 MiB, 1.84% gc time)

# teh-jn/lazydotfuse/8147932909 (0 days ago)
julia> @time f.(rand(2))
  0.085282 seconds (92.90 k allocations: 5.784 MiB)

Ok, so the commit that took it from 1.6 to 3.3 seconds is bce5bbef9ba4b0a30a857d9032c00b1375de73ff @vtjnash, looking for the one that made it go from 0.1 to 1.6 now.

Ok, so:

0.1s -> 0.5s: 8b395aadc3b7459d8817e3a65b88bd422a983dc4
0.5s -> 0.8s: 8345b783993a61ba0e2865e11c51538e
0.8s -> 1.3s: 4ed54db82c50f046a32966dc1ae0
1.3s -> 1.6s: ?
1.6s -> 3.3s: bce5bbef9ba4b0a30a857d9

On freshly pulled master (890239f24f444d887298cc8176e84ee0c54acc2e), I get (without any prior warm-up):

julia> @time identity.(rand(2));
  1.097517 seconds (192.40 k allocations: 11.320 MiB, 0.40% gc time)

julia> f(x) = x;

julia> @time f.(rand(2));
  0.063176 seconds (30.62 k allocations: 1.681 MiB)

The first one is still significantly slower than on 0.6, but that could potentially be a question of what is precompiled in the sysimg? The second one is pretty similar to 0.6.

Yeah, seems much better now. Perhaps https://github.com/JuliaLang/julia/pull/26785 or did that only touch disabled code?

Is this a dup of #26714?
Going back to bce5bbe, I have

julia> @time identity.(rand(2));
  4.359986 seconds (1.13 M allocations: 66.379 MiB, 1.29% gc time)

julia> @time @code_warntype 1+1
# ...
  2.755632 seconds (1.20 M allocations: 66.892 MiB, 0.43% gc time)

or (is fresh session):

julia> @time @code_warntype 1+1;
# ...
  6.947450 seconds (2.12 M allocations: 121.545 MiB, 1.01% gc time)

julia> @time identity.(rand(2));
  0.164185 seconds (210.29 k allocations: 11.828 MiB, 2.02% gc time)

Yeah, looks like both are testing the same thing, probably invoking inference for the first time. Closing as dup of #26714

Was this page helpful?
0 / 5 - 0 ratings

Related issues

tkoolen picture tkoolen  路  3Comments

m-j-w picture m-j-w  路  3Comments

wilburtownsend picture wilburtownsend  路  3Comments

TotalVerb picture TotalVerb  路  3Comments

felixrehren picture felixrehren  路  3Comments