TTFP regression since 1.7

[JeffBezanson]

1.7:

julia> @time using Plots
  4.262361 seconds (8.31 M allocations: 578.459 MiB, 8.05% gc time, 15.63% compilation time)

julia> @time display(plot(rand(10)))
  8.242615 seconds (17.50 M allocations: 934.041 MiB, 2.45% gc time, 99.32% compilation time)

master:

julia> @time using Plots
  4.669242 seconds (9.23 M allocations: 614.779 MiB, 7.41% gc time, 15.85% compilation time)

julia> @time display(plot(rand(10)))
  9.217127 seconds (19.85 M allocations: 1.052 GiB, 2.43% gc time, 96.14% compilation time)

[aviatesk]

I guess this is a dup of #41914 (comment). In short @time using xyz is expected to report very different results between v1.7 and master, since now @time and its family force compilation of the applied block while they didn't before.

[martinholters]

I also see a regression with time julia -e 'using Plots; display(plot(rand(10)))', somewhere between 5% and 10%, which we cannot blame on @time.

[KristofferC]

I guess this is a dup of #41914 (comment).

Well, it turned out that that was an actual regression (#42379).
Also, if Julia compiled more upfront (before the timing starts) then the timing should be lower?

[oscardssmith]

As of today's master, I'm seeing a regression from 9.6 seconds to 12.7 seconds. We should try very hard to address this before releasing 1.8.

[vchuravy]

Can you run a bisect?

[oscardssmith]

What's the syntax? (I haven't run one before)

[vchuravy]

https://www.metaltoad.com/blog/beginners-guide-git-bisect-process-elimination

You start with:

git bisect start
git bisect bad HEAD
git bisect good v1.7.0

[oscardssmith]

I haven't managed to bisect it well. the time seems somewhat stochastic, and there appear to be a variety of regressions and improvements mixed together which make it very difficult to hone in on the correct spot.

[timholy]

May not be relevant, but the number of unique invalidations are:

• 1.7: 1285
• 1.8: 2622

precompile_blockers doesn't seem to suggest these count for a lot of re-inference time, but it's possible that compilation takes longer.

[oscardssmith]

Is that expected? That seems really surprising to me.

[timholy]

No, though it will take some digging to figure out why. From a brief glance, it looks like Base.require(::PkgId) is on the invalidation list, which is really bad. (That won't affect plotting time, just loading time.)