Struct revision takes several minutes for packages with large type trees

[lassepe]

Original (but outdated) issue description

I have a medium-sized project (5k LOC) and noticed that, since #894 was merged, some revisions cause Revise to lock up (I'm not sure if it will terminate eventually because I've terminated it after 5min). In my project, I can most reliably trigger this situation by changing some default values in a `@kwdef` struct, e.g., changing

Base.@kwdef struct Foo
  a::Int = 1
end

to

Base.@kwdef struct Foo
  a::Int = 2
end

Unfortunately, this change in isolation does not trigger the issue and I have yet to find a good way to isolate a compact MWE. Still, I thought it's worth opening this issue in case others observe similar issues or have ideas for how to narrow this down.

Updated Issue Description

I have a medium-sized project and noticed that, since #894 was merged, revisions cause Revise to take very long. My project itself has only about 5k LOC but it has a few heavy dependencies (including CUDA and Plots.jl). I added some logging to Revise (see #988 (comment)) and found that collect_all_subtypes(Any) reaches 62k subtypes (almost all of which are from dependencies). Indexing those takes about 16min.

Looking at those logs, it looks like the initial cache that is built on the background thread hits only about 13k types (because it is loaded before everything else). Upon the first change to any code, we hit collect_all_subtypes(Any) again which now has to index another ~49k subtypes reachable through the newly loaded (transient) dependencies.

So, in sum, this slowness seems to be the compounding effect of three issues:

1. Changes of default arguments in @kwdef trigger struct revision (not just traditional non-struct revision)
2. alltypes gets way too large (perhaps because it also includes all subtypes of Function)
3. The initial call to collect_all_subtypes hits only a small portion of the type tree because is typically loaded before everything else

[alexandergunnarson]

FWIW I've also found this to be the case when changing types in a struct. I have a reasonably large project, and it takes at least as long as precompilation does (45 seconds). Probably more like ~3 minutes.

[lassepe]

@alexandergunnarson does it eventually terminate for you? I didn't even see it terminate in my case and I waited considerably longer than the precompile time for that package

[alexandergunnarson]

It does eventually terminate, though to my perception it took "quite a while" (3 minutes just sitting there? more?). Granted, I may not have as large or complex a project as you. There are perhaps 150 files of decent size. I also didn't change the default value; I changed the type.

[lassepe]

I've run the problematic workload on a more powerful machine and it turns out that it does eventually terminate. However, it does a huge amount of work to get there: I've made a fork that logs the work done from all different threads and a single kwarg-change triggered collect_all_subtypes on two different threads which generated a total of 8MB of logs.

You can find my fork with some extra debug output here (perhaps @alexandergunnarson you could run this on your workload and post your logs)
https://github.com/lassepe/Revise.jl/tree/debug/struct_revision_hangs

The logs from my workload generated via this branch are here:

This is what is generated by the background thread upon launching the session:
thread_6.log
This is what is generated on the main thread after changing the struct default kwargs:
thread_1.log

[lassepe]

As evident from the logs, part of the problem is that a change of the kwargs triggers collect_all_subtypes with parent type Any.

[lassepe]

cc @aviatesk

[timholy]

Yeah, I'm finding that the performance of type revisions is pretty bad in real-world usage. For me it's almost always faster to quit the session and restart.

Given your excellent diagnosis, it seems like it could be as simple as launching a background task to augment the subtype cache for each new loaded package.

Unfortunately, I am still short on time to dig into this myself, but I'm hoping that will change soon.

[lassepe]

I'm not really sure if just throwing more threads at this will solve the issue (especially given that users already complained in #991 about the extra thread).

One thing that struck me during my analysis is that most of the entries enumerated during background caching are subtypes of Function. I was wondering whether those even need to be part of the struct-revision logic. If not, there may be an opportunity to skip 80% of the work.

That said, I don't understand the current design well enough to make that call.

[timholy]

Not threads, tasks. I also need to familiarize myself more deeply with @aviatesk's changes, but

Revise.jl/src/packagedef.jl

Lines 1657 to 1665 in e9a591b

	if __bpart__ && (isnothing(distributed_module) || distributed_module.myid() == 1)
	Threads.@spawn :default foreach_subtype(Any) do @nospecialize type
	# Populating this cache can be time consuming (eg, 30s on an
	# i7-7700HQ) so do this incrementally and yield() to the scheduler
	# regularly so this thread gets a chance to exit if the user quits early
	yield()
	fieldtypes_cached(type)
	end
	end

only runs during __init__, so the cache gets populated with what was available at the time Revise was loaded, but nothing further gets added until you're forced by a revision to do so. I suspect we may wish to make a variant of it run after each package gets loaded.

That said, the sooner all this can move into julia proper, the better. The right time to populate this cache is when types get defined (and it could be stored for each package in the precompile image). Or we need Julia to provide us with more comprehensive backedges.

[quachpas]

I tried something and it seems to improve revision time, instead of >5 min it decreases for me to <10s. master...quachpas:Revise.jl:master

I'm sure the design could be improved, but it basically hooks onto watch_package to spawn a single caching task.
Interested to know whether that improves revision time for larger code bases.

[lassepe]

I think that this is a good improvement over the current caching logic. However, I don't see how you could achieve the latency reduction reported above. If, originally, the first revision took 5 minutes then it means that building the cache for all your dependencies loaded after Revise took about 5 minutes. The only change between your fork and the current master is that you start building that cache as soon as the package is loaded, but it should still take ~5min. So if you are now seeinig a latency of only 10s, then it probably means you waited ~4min 50s before you did the first struct revision.

[lassepe]

I suspect that one puzzle piece to solving this is not including regular functions in the backedge cache. They show up because they are subtype of Any but my understanding is that they are updated through a different logic. In my workload, those are 80% of the cache entries. Maybe @aviatesk can comment on whether those need to be part of the cache?