Phoenix: With Repo: Erlang 23 is considerably slower (+50%) than 21/22 in the Phoenix test suite

[plicjo]

I made a repository with the standard Phoenix installation + generating code with phx_gen_auth

https://github.com/plicjo/phoenix_otp_22_vs_23

My specs:

Hardware Overview:

  Model Name:   Mac mini
  Model Identifier: Macmini6,2
  Processor Name:   Quad-Core Intel Core i7
  Processor Speed:  2.3 GHz
  Number of Processors: 1
  Total Number of Cores:    4
  L2 Cache (per Core):  256 KB
  L3 Cache: 6 MB
  Hyper-Threading Technology:   Enabled
  Memory:   16 GB
  Boot ROM Version: 286.0.0.0.0
  SMC Version (system): 2.8f1
  Serial Number (system):   C07N1161DY3H
  Hardware UUID:    7C3792EF-B8F7-54FB-A607-E0FF2D31EBF1

Expected behavior

I expected performance to be similar/faster using Erlang 23, as opposed to Erlang 22.

Actual behavior

I noticed a considerable slowdown in test suite speed when I upgraded from Erlang 22 to 23 in my own Phoenix project.

With OTP 23, with the same code, same Phoenix and Elixir version, on the same machine:

The test suite took 4.5 seconds.

With OTP 22, with the same code, same Phoenix and Elixir version, on the same machine:

The test suite took 1.3 seconds.

The original report of this issue lives here: https://github.com/phoenixframework/phoenix/issues/3976

The repository, where I made a repository with the standard Phoenix installation + generating code with phx_gen_auth

https://github.com/plicjo/phoenix_otp_22_vs_23

[ghost]

Probably because OTP 23 hype compiler is not working

[cid:[email protected]]

Roberto Della Pasqua
Software Architect Developer
Microsoft Certificate of Excellence
Embarcadero Certificate of Excellence
American Design Award

roberto.[email protected][e-mail]
www.dellapasqua.comhttp://www.dellapasqua.com/
linkedinhttps://www.linkedin.com/in/roberto-della-pasqua-126366189/

Da: Joshua Plicque [e-mail]
Inviato: mercoledì 9 settembre 2020 20:12
A: phoenixframework/phoenix [e-mail]
Cc: Subscribed [e-mail]
Oggetto: [phoenixframework/phoenix] With Repo: Erlang 23 is considerably slower (+50%) than 21/22 in the Phoenix test suite (#3986)

I made a repository with the standard Phoenix installation + generating code with phx_gen_auth

https://github.com/plicjo/phoenix_otp_22_vs_23https://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fplicjo%2Fphoenix_otp_22_vs_23&data=02%7C01%7C%7Ca97ce015e7f34b13be9108d854ebe885%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637352719472458189&sdata=VPSPAo%2F1fhlBOTKOdh%2FGxcO%2FpMlALtnaZcFjWX7mdfE%3D&reserved=0

My specs:

Hardware Overview:

Model Name: Mac mini

Model Identifier: Macmini6,2

Processor Name: Quad-Core Intel Core i7

Processor Speed: 2.3 GHz

Number of Processors: 1

Total Number of Cores: 4

L2 Cache (per Core): 256 KB

L3 Cache: 6 MB

Hyper-Threading Technology: Enabled

Memory: 16 GB

Boot ROM Version: 286.0.0.0.0

SMC Version (system): 2.8f1

Serial Number (system): C07N1161DY3H

Hardware UUID: 7C3792EF-B8F7-54FB-A607-E0FF2D31EBF1

With OTP 23, with the same code, same Phoenix and Elixir version, on the same machine:
[Screen Shot 2020-09-02 at 11 09 32 AM]https://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fuser-images.githubusercontent.com%2F7145362%2F92005745-d612ba80-ed11-11ea-8338-667ea006e707.png&data=02%7C01%7C%7Ca97ce015e7f34b13be9108d854ebe885%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637352719472458189&sdata=24gANNkdX%2Bf%2FxUBM6wnYQQOyXWEjFb6M9g4gmKSEJ7E%3D&reserved=0

The test suite took 4.5 seconds.

With OTP 22, with the same code, same Phoenix and Elixir version, on the same machine:
[Screen Shot 2020-09-02 at 11 42 51 AM]https://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fuser-images.githubusercontent.com%2F7145362%2F92005831-f2165c00-ed11-11ea-8369-a6bd02660b2c.png&data=02%7C01%7C%7Ca97ce015e7f34b13be9108d854ebe885%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637352719472468184&sdata=B1F%2FrYpArsjfVfyVdy4LEJHlBtGCXddfIZpdepr2hJA%3D&reserved=0
The test suite took 1.3 seconds.

The original report of this issue lives here: #3976https://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fphoenixframework%2Fphoenix%2Fissues%2F3976&data=02%7C01%7C%7Ca97ce015e7f34b13be9108d854ebe885%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637352719472468184&sdata=70c31T%2BOKzKWda3xnyzGRjJ55lcqmQBaOY%2BjXXUKBZ0%3D&reserved=0

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHubhttps://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fphoenixframework%2Fphoenix%2Fissues%2F3986&data=02%7C01%7C%7Ca97ce015e7f34b13be9108d854ebe885%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637352719472468184&sdata=H%2FGdhMagWtT5ugVsdsJoHhmLS5nx1SVCVs3FKomo1UU%3D&reserved=0, or unsubscribehttps://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FAMLAQJ6ZF6QX4P4XEV3RB3LSE7AQVANCNFSM4RC44ADA&data=02%7C01%7C%7Ca97ce015e7f34b13be9108d854ebe885%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637352719472478180&sdata=D%2B%2BxFHlEfrrQi993K5OWsT12eiInImGEnl6usPL4aXo%3D&reserved=0.

[josevalim]

One thing to keep in mind is that in order to run tests, we have to compile the test modules, and as compilers get smarter, it ends up taking more time. I have reported some of them upstream but I will investigate if there is one particular script causing this. I would also try this again once Erlang 23.1 is out.

[josevalim]

Thanks for the report!

[plicjo]

@josevalim Understood on the test file compilation. Thank you! Alright, I'll keep my eyes open for that release.

[josevalim]

@plicjo I have taken a further look at this and I can confirm most of the time is spent loading tests rather than running them:

On Erlang/OTP 23:

$  time MIX_ENV=test MIX_BUILD_ROOT=_build23 elixir -pa "_build23/test/lib/*/ebin" -r test/test_helper.exs -pr "test/**/*_test.exs"

real    0m5.080s
user    0m13.707s
sys 0m0.644s

On 22:

$ time MIX_ENV=test MIX_BUILD_ROOT=_build22 elixir -pa "_build22/test/lib/*/ebin" -r test/test_helper.exs -pr "test/**/*_test.exs"

real    0m1.860s
user    0m5.867s
sys 0m0.486s

Now I need to go deeper.

[dvic]

For what it's worth, on my machine the difference is smaller:

• 1.0 second for otp-22;
• 2.6 seconds for otp-23;

(both elixir 1.10.4).

Machine specs:

  Model Name:                 MacBook Pro
  Model Identifier:           MacBookPro14,3
  Processor Name:             Quad-Core Intel Core i7
  Processor Speed:            2,9 GHz
  Number of Processors:       1
  Total Number of Cores:      4
  L2 Cache (per Core):        256 KB
  L3 Cache:                   8 MB
  Hyper-Threading Technology: Enabled
  Memory:                     16 GB
  Boot ROM Version:           428.0.0.0.0
  SMC Version (system):       2.45f4

[josevalim]

Progress:

$ time MIX_ENV=test MIX_BUILD_ROOT=_build22 elixir -pa "_build22/test/lib/*/ebin" -r test/test_helper.exs -pr "test/**/*_test.exs"

real    0m1.538s
user    0m4.780s
sys 0m0.382s

$  time MIX_ENV=test MIX_BUILD_ROOT=_build23 elixir -pa "_build23/test/lib/*/ebin" -r test/test_helper.exs -pr "test/**/*_test.exs"

real    0m2.719s
user    0m8.305s
sys 0m0.442s

Commits for those fixes are in Elixir master!

[josevalim]

Yeah, I have a humbler machine. :)

[josevalim]

More speedups:

23:

$  time MIX_ENV=test MIX_BUILD_ROOT=_build23 elixir -pa "_build23/test/lib/*/ebin" -r test/test_helper.exs -pr "test/**/*_test.exs"

real    0m2.010s
user    0m6.995s
sys 0m0.455s

22:

$ time MIX_ENV=test MIX_BUILD_ROOT=_build22  elixir -pa "_build22/test/lib/*/ebin" -r test/test_helper.exs -pr "test/**/*_test.exs"

real    0m1.383s
user    0m4.632s
sys 0m0.400s

Also on Elixir master and v1.11.

[josevalim]

I will close this one for now as I believe most of the possible improvements have been done. Thanks for the report!