Elixir v1.11.2 (phoenix umbrella-)application won't compile

Hey there,
we are currently trying to migrate to Elixir 1.11.
We had a few warnings that needed to be fixed in our otp app. But now the compile step won’t finish and I have know idea where to start debugging.
Using the --verbose flag I can confirm that all modules finish compilitation ( same output with 1.10 ).
But what is missing is the Generated hello app output and the compiler does not continue with the web app.
We are using the elixir-1.11.2-slim docker image, but trying to compile without the docker environment shows the same behaviour.

I aborted the compiler to produce a crash dump. As this I am not good in reading this logs some things I think are unusual but might be totally normal:

  • All processes are in state waiting except for :erlang.apply/2
  • :erlang.apply/2 has a huge amount of reductions ~500_000_000
  • message queue is empty except for :erlang.apply/2 (one message)

I waited ~30m and nothing happens, but 1 cpu core is always at 100% usage.

Thanks for your help. A good start might be pointing me into a direction where to look for strange behaviours.

Cheers,
~Nick

That sounds like it might be https://bugs.erlang.org/browse/ERL-1236

Are you using an affected version of Erlang?

Thanks for the reply.
As stated we are using the elixir-1.11.2-slim container which is based on the latest OTP 23 version: 23.1.2.
Since the issue says “soon releasing a fix for 23” posted in May, I guess this has been fixed.

Can you please try this:

MIX_DEBUG=1 mix compile --force --profile time

And post the results?

2 Likes

Sure thing (had to anonymize app name and module names):

my_app@3ce7524f5cdd:/app$ MIX_DEBUG=1 mix compile --force --profile time
** Running mix loadconfig (inside MyApp.Umbrella.Mixfile)
** Running mix compile --warnings-as-errors --force --profile time (inside MyApp.Umbrella.Mixfile)
** Running mix loadpaths --warnings-as-errors --force --profile time (inside MyApp.Umbrella.Mixfile)
** Running mix archive.check --warnings-as-errors --force --profile time (inside MyApp.Umbrella.Mixfile)
** Running mix deps.loadpaths --warnings-as-errors --force --profile time (inside MyApp.Umbrella.Mixfile)
** Running mix deps.precompile (inside MyApp.Umbrella.Mixfile)
==> geo_db
** Running mix compile --no-deps-loading --no-apps-loading --no-archives-check --no-elixir-version-check --no-warnings-as-errors (inside GeoDb.Mixfile)
** Running mix loadpaths --no-deps-loading --no-apps-loading --no-archives-check --no-elixir-version-check --no-warnings-as-errors (inside GeoDb.Mixfile)
** Running mix compile.all --no-deps-loading --no-apps-loading --no-archives-check --no-elixir-version-check --no-warnings-as-errors (inside GeoDb.Mixfile)
** Running mix compile.yecc --no-deps-loading --no-apps-loading --no-archives-check --no-elixir-version-check --no-warnings-as-errors (inside GeoDb.Mixfile)
** Running mix compile.leex --no-deps-loading --no-apps-loading --no-archives-check --no-elixir-version-check --no-warnings-as-errors (inside GeoDb.Mixfile)
** Running mix compile.erlang --no-deps-loading --no-apps-loading --no-archives-check --no-elixir-version-check --no-warnings-as-errors (inside GeoDb.Mixfile)
** Running mix compile.elixir --no-deps-loading --no-apps-loading --no-archives-check --no-elixir-version-check --no-warnings-as-errors (inside GeoDb.Mixfile)
** Running mix compile.app --no-deps-loading --no-apps-loading --no-archives-check --no-elixir-version-check --no-warnings-as-errors (inside GeoDb.Mixfile)
==> serving_domain_plug
** Running mix compile.all --warnings-as-errors --force --profile time (inside ServingDomainPlug.MixProject)
** Running mix compile.yecc --warnings-as-errors --force --profile time (inside ServingDomainPlug.MixProject)
** Running mix compile.leex --warnings-as-errors --force --profile time (inside ServingDomainPlug.MixProject)
** Running mix compile.erlang --warnings-as-errors --force --profile time (inside ServingDomainPlug.MixProject)
** Running mix compile.elixir --warnings-as-errors --force --profile time (inside ServingDomainPlug.MixProject)
Compiling 1 file (.ex)
[profile] lib/serving_domain_plug.ex compiled in 26ms
[profile] Finished compilation cycle of 1 modules in 26ms
[profile] Finished group pass check of 1 modules in 1ms
** Running mix compile.app --warnings-as-errors --force --profile time (inside ServingDomainPlug.MixProject)
Generated serving_domain_plug app
==> urmel
** Running mix compile.all --warnings-as-errors --force --profile time (inside Urmel.MixProject)
** Running mix compile.yecc --warnings-as-errors --force --profile time (inside Urmel.MixProject)
** Running mix compile.leex --warnings-as-errors --force --profile time (inside Urmel.MixProject)
** Running mix compile.erlang --warnings-as-errors --force --profile time (inside Urmel.MixProject)
** Running mix compile.elixir --warnings-as-errors --force --profile time (inside Urmel.MixProject)
Compiling 1 file (.ex)
[profile] lib/urmel.ex compiled in 118ms
[profile] Finished compilation cycle of 2 modules in 118ms
[profile] Finished group pass check of 2 modules in 5ms
** Running mix compile.app --warnings-as-errors --force --profile time (inside Urmel.MixProject)
Generated urmel app
==> my_app
** Running mix compile.all --warnings-as-errors --force --profile time (inside MyApp.Mixfile)
** Running mix compile.yecc --warnings-as-errors --force --profile time (inside MyApp.Mixfile)
** Running mix compile.leex --warnings-as-errors --force --profile time (inside MyApp.Mixfile)
** Running mix compile.erlang --warnings-as-errors --force --profile time (inside MyApp.Mixfile)
** Running mix compile.elixir --warnings-as-errors --force --profile time (inside MyApp.Mixfile)
Compiling 95 files (.ex)
[profile] lib/my_app/some/module.ex compiled in 114ms
[profile] lib/my_app/some.ex compiled in 129ms
[profile] lib/my_app/some.ex compiled in 176ms
[profile] lib/my_app/some/module.ex compiled in 284ms
[profile] lib/my_app/some/module.ex compiled in 254ms (plus 50ms waiting)
[profile] lib/my_app/some/module/submodule.ex compiled in 339ms
[profile] lib/my_app/some/module/submodule.ex compiled in 389ms
[profile] lib/my_app/some.ex compiled in 467ms
[profile] lib/my_app/some/module.ex compiled in 525ms
[profile] lib/my_app/some.ex compiled in 281ms
[profile] lib/my_app/some/module.ex compiled in 507ms
[profile] lib/my_app/some.ex compiled in 229ms
[profile] lib/my_app/some/module.ex compiled in 160ms
[profile] lib/my_app/some/module.ex compiled in 413ms
[profile] lib/my_app/some/module.ex compiled in 748ms
[profile] lib/my_app/some/module.ex compiled in 139ms
[profile] lib/my_app/some/module.ex compiled in 257ms
[profile] lib/my_app/some/module/submodule.ex compiled in 164ms
[profile] lib/my_app/some/module.ex compiled in 247ms
[profile] lib/my_app/some.ex compiled in 168ms
[profile] lib/my_app/some/module/submodule.ex compiled in 182ms
[profile] lib/my_app/some/module.ex compiled in 179ms
[profile] lib/my_app/some/module.ex compiled in 926ms
[profile] lib/my_app/some.ex compiled in 384ms
[profile] lib/my_app/some.ex compiled in 157ms
[profile] lib/my_app/some/module.ex compiled in 253ms
[profile] lib/my_app/some/module.ex compiled in 423ms
[profile] lib/my_app/some/module.ex compiled in 171ms
[profile] lib/my_app/some/module.ex compiled in 486ms
[profile] lib/my_app/some/module.ex compiled in 1067ms
[profile] lib/my_app/some.ex compiled in 631ms
[profile] lib/my_app/some/module.ex compiled in 163ms
[profile] lib/my_app/some/module.ex compiled in 1233ms
[profile] lib/my_app/some.ex compiled in 138ms
[profile] lib/my_app/some/module.ex compiled in 763ms
[profile] lib/my_app.some compiled in 93ms
[profile] lib/my_app/some.ex compiled in 631ms
[profile] lib/my_app/some.ex compiled in 311ms
[profile] lib/my_app/some/module.ex compiled in 364ms
[profile] lib/my_app/some/module/submodule.ex compiled in 297ms
[profile] lib/my_app/some/module/submodule.ex compiled in 438ms
[profile] lib/my_app/some/module.ex compiled in 905ms
[profile] lib/my_app/some/module.ex compiled in 449ms
[profile] lib/my_app/some.ex compiled in 787ms
[profile] lib/my_app/some.ex compiled in 303ms
[profile] lib/my_app/some/module.ex compiled in 245ms (plus 358ms waiting)
[profile] lib/my_app/some/module/submodule.ex compiled in 135ms
[profile] lib/my_app/some/module/submodule.ex compiled in 177ms
[profile] lib/my_app/some/module.ex compiled in 308ms
[profile] lib/my_app/some/module.ex compiled in 345ms
[profile] lib/my_app/some/module.ex compiled in 294ms
[profile] lib/my_app/some/module/submodule.ex compiled in 343ms
[profile] lib/my_app/some/module.ex compiled in 318ms
[profile] lib/my_app/some/module.ex compiled in 335ms (plus 2005ms waiting)
[profile] lib/my_app/some.ex compiled in 213ms
[profile] lib/my_app/some.ex compiled in 115ms
[profile] lib/my_app/some.ex compiled in 192ms
[profile] lib/my_app/some/module.ex compiled in 258ms
[profile] lib/my_app/some.ex compiled in 701ms
[profile] lib/my_app/some/module.ex compiled in 177ms
[profile] lib/my_app/some/module/submodule/poller.ex compiled in 198ms
[profile] lib/my_app/some.ex compiled in 238ms
[profile] lib/my_app/some/module.ex compiled in 302ms
[profile] lib/my_app/some.ex compiled in 561ms
[profile] lib/my_app/some.ex compiled in 858ms
[profile] lib/my_app/some/module/submodule.ex compiled in 1616ms
[profile] lib/my_app/some.ex compiled in 324ms
[profile] lib/my_app/some/module.ex compiled in 501ms
[profile] lib/my_app/some/module.ex compiled in 643ms
[profile] lib/my_app/some/module.ex compiled in 1096ms (plus 856ms waiting)
[profile] lib/my_app/some/module.ex compiled in 590ms
[profile] lib/my_app/some.ex compiled in 272ms
[profile] lib/my_app/some/module.ex compiled in 1982ms (plus 1548ms waiting)
[profile] lib/my_app/some/module/submodule.ex compiled in 165ms
[profile] lib/my_app/some/module.ex compiled in 844ms
[profile] lib/my_app/some/module.ex compiled in 168ms
[profile] lib/my_app/some/module/submodule.ex compiled in 574ms
[profile] lib/my_app/some/module/submodule.ex compiled in 861ms
[profile] lib/my_app/some.ex compiled in 367ms
[profile] lib/my_app/some/module.ex compiled in 890ms (plus 2232ms waiting)
[profile] lib/my_app/some/module.ex compiled in 606ms (plus 96ms waiting)
[profile] lib/my_app/some/module.ex compiled in 440ms (plus 29ms waiting)
[profile] lib/my_app/some/module.ex compiled in 728ms (plus 3182ms waiting)
[profile] lib/my_app/some/module.ex compiled in 488ms (plus 2336ms waiting)
[profile] lib/my_app/some/module.ex compiled in 483ms (plus 2601ms waiting)
[profile] lib/my_app/some/module.ex compiled in 572ms (plus 3061ms waiting)
[profile] lib/my_app/some/module.ex compiled in 858ms (plus 1838ms waiting)
[profile] lib/my_app/some/module.ex compiled in 1424ms (plus 470ms waiting)
[profile] lib/my_app/some/module.ex compiled in 1114ms (plus 153ms waiting)
[profile] lib/my_app/some/module.ex compiled in 207ms (plus 2950ms waiting)
[profile] lib/my_app/some/module/submodule.ex compiled in 533ms (plus 1982ms waiting)
[profile] lib/my_app/some/module.ex compiled in 656ms (plus 2316ms waiting)
[profile] lib/my_app/some/module.ex compiled in 1526ms
[profile] lib/my_app/some/module.ex compiled in 2646ms
[profile] lib/my_app/some/module.ex compiled in 1212ms (plus 3918ms waiting)
[profile] Finished compilation cycle of 178 modules in 5133ms

this is where it stops doing anything visible (except for high cpu usage)
compilation of my_app_web and my_app_api is missing.

Ok. Next Elixir is supposed to run a group pass and it seems we are getting stuck on it. This means there is one module in all of those that is slowing things down. My suggestion is to remove modules one by one and compile, until you find the slow one. If you send me the project in private (see my contact info on GitHub) I can debug it too.

2 Likes

Thanks for the offer! I’ll try myself first and then beg for help if I am stuck again :stuck_out_tongue:
Is there a possibility that a dependency might disturb the compiling process?

Hey there,
thanks again, you were right. I narrowed it down to a single, more likely two lines of code.
I fixed it but I don’t quite understand the issue:

# contains some more fields that are not important for the demonstration
%{consumption: %Consumption{}} = queried = some_query_function()

with(
  true <- is_nil(queried.consumption.video_started_at)
  update_arguments <- %{
    consumption: queried.consumption
  }
) do

removing one of those two accesses (either queried.consumption or queried.consumption.video_started_at) resolves the compiling issue. It doesn’t matter which one.
So I replaced the first check with:

      %{consumption: %{video_started_at: nil}} <- queried

and it works.

Do you have any idea why?
Might there be an issue with the new compiler checks here?

Awesome job! Can you please give me a minimal function that reproduces the issue? Run mix new example and try to copy only the minimal amount of code (most likely a single module with a single single function) that reproduces it and we will readily take a look at it and push a fix to master.

2 Likes

There you go:

I noticed that it’s not just the two lines but a synergy with a macro we are using, so I provided that too.

2 Likes

Thanks, here is a further minimal case:

defmodule CompilerExample do
  def hello(queried) do
    with(
      true <- is_nil(queried.foo.bar),
      _ = queried.foo
    ) do
      %{foo: %{other_id: _other_id} = foo} = queried
      %{other_id: id} = foo
      %{id: id}
    end
  end
end

We are looking into the root cause now.

4 Likes

Thank you for your help and quick fixing <3
But even with you fix I don’t quite understand the problem.

Could you shortly explain the problem? That would be nice :slight_smile:

Cheers
~Nick

1 Like