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

Avoid several bad show_default invalidations #37125

Merged
merged 3 commits into from
Aug 25, 2020
Merged

Conversation

timholy
Copy link
Sponsor Member

@timholy timholy commented Aug 19, 2020

This fixes 53 quite critical invalidations from loading StaticArrays. At least by our old standards, 53 invalidations would be considered a modest number, but in this case they manage to hit the package-loading code, the docstring code, and the MethodError display code. Since particularly the first two are used by everything, these invalidations are about as bad as they could be.

The invalidation of the package-loading code is due to a rather hilarious chain of events. This method definition
ends up invalidating show_default, which got called because stale_cachefile used an outdated variable name in a @debug macro that ended up grabbing the global mod function. Since show(::IO, ::Function) can call show_default, this ended up invalidating basically all the package-loading code.

The docstring code got invalidated because show(::IO, ::Pair{Symbol,Any}) calls show_default. This PR provides a dedicated path that circumvents show_default.

Finally, an innocuous-seeming function-print in showerror(::IO, ::MethodError) also led to quite a chain of invalidation.

EDIT: as pointed out below by @KristofferC, this fixes #36005. (If master hadn't already fixed it, I haven't checked.)

This fixes ~50 quite critical invalidations from loading StaticArrays,
which manages to hit the package-loading code, the docstring code,
and the `MethodError` display code. Since particularly the first two
are used by *everything*, these invalidations are about as bad as it
gets given that this is not a huge number of invalidations (at least, by
our old standards).

The invalidation of the package-loading code is due to a rather
hilarious chain of events.
[This method definition](https://github.com/JuliaArrays/StaticArrays.jl/blob/ad583c99768f3a381ba20b1a0782c9ca50890b50/src/SArray.jl#L125-L126)
ends up invalidating [`show_default`](https://github.com/JuliaLang/julia/blob/89d6b469b633dde8f92b4d245ca3d8e5606e229c/base/show.jl#L417),
which got called because `stale_cachefile` used an outdated variable
name in a [`@debug` macro](https://github.com/JuliaLang/julia/blob/89d6b469b633dde8f92b4d245ca3d8e5606e229c/base/loading.jl#L1518)
that ended up grabbing the global `mod` function. Since
`show(::IO, ::Function)` can call `show_default`, this ended up
invalidating basically all the package-loading code.

The docstring code got invalidated because
`show(::IO, ::Pair{Symbol,Any})`
[calls `show_default`](https://github.com/JuliaLang/julia/blob/89d6b469b633dde8f92b4d245ca3d8e5606e229c/base/show.jl#L907).
This PR provides a dedicated path that circumvents `show_default`.

Finally, an innocuous-seeming function-print in
`showerror(::IO, ::MethodError)` also led to quite a chain of invalidation.
@timholy timholy added the compiler:latency Compiler latency label Aug 19, 2020
@timholy
Copy link
Sponsor Member Author

timholy commented Aug 19, 2020

Just to show the overall consequences: on this branch,

julia> using StaticArrays

julia> @time using Example
  0.002901 seconds (2.90 k allocations: 185.891 KiB)

On Julia 1.5,

julia> using StaticArrays

julia> @time using Example
  0.656540 seconds (1.33 M allocations: 66.060 MiB, 7.79% gc time)

That's gonna make a difference in package loading times.

There are a couple of show_default stragglers:

  • we lack a show method for generic IPAddr: we have them for all subtypes but when inference is lost we end up inferring a call to show_default.
  • something is calling print(::ProcessException) (we have a showerror method but not a show method)
  • of course, show(::IO, ::Function) gets invalidated

For all of these, the trail of backedges truncates (#37046) so it is not easy to figure out where these are coming from.

@KristofferC
Copy link
Sponsor Member

Fixes #36005?

These are the only two types supported by `Sockets`, so this seems
reasonable, although it does block further extension.
@timholy
Copy link
Sponsor Member Author

timholy commented Aug 20, 2020

Heck yeah!

julia> @time using Plots
  3.217109 seconds (7.83 M allocations: 544.377 MiB, 4.78% gc time)

julia> @time using Plots
  0.000421 seconds (717 allocations: 38.922 KiB)

That 3.2s load time is pretty awesome (CCing @daschw, @BeastyBlacksmith). For reference, here's what I get on Julia 1.5:

julia> @time using Plots
  8.466600 seconds (18.09 M allocations: 1021.804 MiB, 3.44% gc time)

julia> @time using Plots
  0.685273 seconds (1.43 M allocations: 70.920 MiB, 11.50% gc time)

julia> @time using Plots
  0.000393 seconds (761 allocations: 44.250 KiB)

Both with Plots 1.6.0, FWIW. My guess is that on 1.5 the loading code was being invalidated repeatedly by several different dependencies of Plots (that extra time for the second using is just the most recent of these invalidations). Most of those were probably fixed in other PRs though.

I also pushed a proposed fix for the IPAddr issue described above, although it has the downside of blocking any additional IPAddr subtypes. Such types would surely require other changes to the Sockets library so on balance I think it's a worthy fix, but let's see what others think. (It's also not a big deal either way, it only affects 2 additional invalidations.)

@daschw
Copy link

daschw commented Aug 20, 2020

Wow, that's awesome!

@KristofferC
Copy link
Sponsor Member

That 3.2s load time is pretty awesome (CCing @daschw, @BeastyBlacksmith). For reference, here's what I get on Julia 1.5:

FWIW. My guess is that the loading code was being invalidated repeatedly by several different dependencies of Plots (that extra time for the second using is just the most recent of these invalidations).

Out of curiosity, what do you get on master without this PR?

@giordano
Copy link
Contributor

@timholy what version of FFMPEG.jl are you using? How long does it take to load?

@timholy
Copy link
Sponsor Member Author

timholy commented Aug 20, 2020

@KristofferC, here's master (which of course has a lot of relevant recent work from you, Jeff, Jameson, Elliot, me, and likely others I'm not naming):

julia> @time using Plots
  3.370194 seconds (7.59 M allocations: 528.619 MiB, 6.43% gc time)

julia> @time using Plots
  0.377861 seconds (588.13 k allocations: 33.855 MiB, 4.82% gc time)

julia> @time using Plots
  0.000394 seconds (717 allocations: 38.922 KiB)

So most of the benefit over 1.5 is due to things we've recently added, but this PR adds further progress on the scale of ~0.5s if you're loading more than just Plots.

@giordano, here's what I get on master:

julia> @time using FFMPEG
  0.457856 seconds (994.93 k allocations: 63.036 MiB, 3.36% gc time)

I doubt this PR changes that (loading FFMPEG produces zero invalidations).

@KristofferC
Copy link
Sponsor Member

KristofferC commented Aug 20, 2020

I doubt this PR changes that (loading FFMPEG produces zero invalidations).

@staticfloat has work in progress that will reduce this time quite significantly though.

@giordano
Copy link
Contributor

What version of FFMPEG.jl is that? Does it use FFMPEG_jll?

@timholy
Copy link
Sponsor Member Author

timholy commented Aug 20, 2020

(@v1.6) pkg> st FFMPEG
Status `~/.julia/environments/v1.6/Project.toml`
  [c87230d0] FFMPEG v0.3.0

base/show.jl Outdated Show resolved Hide resolved
Co-authored-by: Jeff Bezanson <[email protected]>
@JeffBezanson JeffBezanson merged commit 6aee988 into master Aug 25, 2020
@JeffBezanson JeffBezanson deleted the teh/show_default branch August 25, 2020 17:05
simeonschaub pushed a commit to simeonschaub/julia that referenced this pull request Aug 29, 2020
This fixes ~50 quite critical invalidations from loading StaticArrays,
which manages to hit the package-loading code, the docstring code,
and the `MethodError` display code. Since particularly the first two
are used by *everything*, these invalidations are about as bad as it
gets given that this is not a huge number of invalidations (at least, by
our old standards).

The invalidation of the package-loading code is due to a rather
hilarious chain of events.
[This method definition](https://github.com/JuliaArrays/StaticArrays.jl/blob/ad583c99768f3a381ba20b1a0782c9ca50890b50/src/SArray.jl#L125-L126)
ends up invalidating [`show_default`](https://github.com/JuliaLang/julia/blob/89d6b469b633dde8f92b4d245ca3d8e5606e229c/base/show.jl#L417),
which got called because `stale_cachefile` used an outdated variable
name in a [`@debug` macro](https://github.com/JuliaLang/julia/blob/89d6b469b633dde8f92b4d245ca3d8e5606e229c/base/loading.jl#L1518)
that ended up grabbing the global `mod` function. Since
`show(::IO, ::Function)` can call `show_default`, this ended up
invalidating basically all the package-loading code.

The docstring code got invalidated because
`show(::IO, ::Pair{Symbol,Any})`
[calls `show_default`](https://github.com/JuliaLang/julia/blob/89d6b469b633dde8f92b4d245ca3d8e5606e229c/base/show.jl#L907).
This PR provides a dedicated path that circumvents `show_default`.

Finally, an innocuous-seeming function-print in
`showerror(::IO, ::MethodError)` also led to quite a chain of invalidation.

* Specify that getaddrinfo(::AbstractString) returns a `Union{IPv4,IPv6}`

These are the only two types supported by `Sockets`, so this seems
reasonable, although it does block further extension.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
compiler:latency Compiler latency
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Second "using" is slow (slower than third, can even be slower than the first)
5 participants