Slow compile times in a large app due to full schema recompilation since upgrading from 1.4

[dmarkow]

I have a fairly large API using Absinthe (25,000 lines of code, around 400 objects, 300 queries, and 300 mutations). I've noticed that it's getting slower and slower to compile my schema, and since just about every module in my app is reachable from one of my resolvers, touching basically any file in the project results in a full recompile of my schema, even if none of my fields/queries changed. Compiling the schema adds around 15 seconds to every recompilation, making frequent updates and test runs painful.

I spent some time digging through and determined that most of the time is spent in phase/schema/compile.ex, specifically at the Module.create(...) call, which takes around 10 seconds to generate the ApiWeb.Schema.Compiled module.

It seems to make no difference if I keep everything in one giant schema file versus splitting it by my contexts and using import_types/import_fields. I found https://devonestes.herokuapp.com/trying-to-speed-up-compilation-with-absinthe but even trying the umbrella app experiment outlined there, my compile times only improved about 10% (and added a lot of complexity).

Out of curiosity I reverted back to absinthe 1.4.16 and everything is way faster. The schema.ex file is still recompiled, but it happens in around 750ms instead of 15 seconds. The bump up to 1.5 is where the recompilation issues started.

Is this just a downside to the convenience of the new features added since 1.5, or is there something that can be done either on Absinthe's end or my own to help with this?

Environment

• Elixir version (elixir -v): Elixir 1.11.3 (compiled with Erlang/OTP 23)
• Absinthe version (mix deps | grep absinthe): 1.6.1 (Hex package) (mix)

Expected behavior

Changes that don't actually affect my schema to not trigger a costly recompile.

Actual behavior

Touching any file referenced by a resolver triggers a complete recompile of my schema.

Relevant Schema/Middleware Code

Basic schema with many fields, queries, and mutations. No extra plugins/middleware.

[benwilson512]

Hi @dmarkow, can you try using the persistent term backend found here: https://hexdocs.pm/absinthe/1.5.5/Absinthe.Schema.PersistentTerm.html ?

[dmarkow]

@benwilson512 Big improvement! I initially tried that but it didn't seem to improve anything. But I just looked at the implementation and noticed that calling use Absinthe.Schema overrides the @schema_provider attribute, which I had put before the use line. Moving it after seems to help a bunch. Still not as fast as 1.4 was, but much more tolerable (around 4-5 seconds to recompile) and something I can live with.

[benwilson512]

@dmarkow we will continue to work on improving compilation performance. Notably although 1.5 and 1.6 are slower to compile, they actually perform at run time much better and in particular when using persistent term, use a lot less memory.

We'll continue to put effort into improving compilation speed though, and in a release soon we plan to make the persistent term backend standard.

[dmarkow]

Awesome! Thanks for helping me out with this so quickly.

[dmarkow]

@benwilson512 One extra piece of info in case it's useful for future work on this. It seems that with PersistentTerm compilation of schema.ex is actually very close that that of 1.4.16. The thing that's delaying it is a 3-second "group pass check" on the project's modules, regardless of using PersistentTerm or not. In 1.4.16, the group pass check took less than a second for the same number of modules.

# 1.6.1 without PersistentTerm
> touch lib/api_web/schema.ex && time mix compile --profile time
Compiling 2 files (.ex)
[profile] lib/api_web/router.ex compiled in 1311ms
[profile] lib/api_web/schema.ex compiled in 9635ms
[profile] Finished compilation cycle of 4 modules in 9645ms
[profile] Finished group pass check of 349 modules in 3124ms
mix compile --profile time  23.66s user 2.27s system 189% cpu 14.717 total

# 1.6.1 with PersistentTerm
> touch lib/api_web/schema.ex && time mix compile --profile time
Compiling 2 files (.ex)
[profile] lib/api_web/schema.ex compiled in 844ms
[profile] lib/api_web/router.ex compiled in 1025ms
[profile] Finished compilation cycle of 3 modules in 1032ms
[profile] Finished group pass check of 348 modules in 2858ms
mix compile --profile time  13.02s user 1.19s system 256% cpu 5.543 total

# 1.4.16
> touch lib/api_web/schema.ex && time mix compile --profile time
Compiling 2 files (.ex)
[profile] lib/api_web/schema.ex compiled in 766ms
[profile] lib/api_web/router.ex compiled in 1116ms
[profile] Finished compilation cycle of 3 modules in 1126ms
[profile] Finished group pass check of 348 modules in 734ms
mix compile --profile time  9.07s user 1.21s system 283% cpu 3.623 total

[benwilson512]

@dmarkow interesting! Can you elaborate a bit on what the "Group pass check" is? This isn't a term I recognize.

[dmarkow]

I saw this mentioned in José's post at https://dashbit.co/blog/how-to-debug-elixir-erlang-compiler-performance — from reading through this it sounds like a standard part of Elixir's compilation process, stating that it's "the time to execute a group pass which looks at all modules at once, in order to find undefined functions, emit deprecations, etc." You can track it when you compile with the --profile time flag.

Relevant code in Elixir for checking the modules:

• https://github.com/elixir-lang/elixir/blob/master/lib/elixir/lib/kernel/parallel_compiler.ex#L230
• https://github.com/elixir-lang/elixir/blob/master/lib/elixir/lib/module/parallel_checker.ex#L14

I tried a dev build of Elixir 1.12 which has some compiler improvements that speed this up quite a bit (reducing that group pass check from around 3 seconds to 1 second) so it may not need to be something to worry about on Absinthe's end. In the mean time, it also seems that splitting some of my larger absinthe schema type files into multiple smaller files helps take advantage of the parallel checking a bit more and shaves a second off even under Elixir 1.11.

So with a combination of PersistentTerm, splitting my larger schema files, and using Elixir 1.12, I'm back in the 700-800ms zone for the group pass check, and a total of around 3 seconds of real world time (which feel instantaneous compared to the 15-20 seconds I started with) 🎉

[benwilson512]

OK great, glad we could get things back to a good place!