As promised: Elixir v1.19.5 released !
6 Likes
Even for projects not having the issue above, then there is a noticeable performance improvements from 1.19.4 to 1.19.5
6 Likes
Iāve noticed that in our project the verification step of the Phoenix router takes significantly longer than on 1.18. From lless than a second to more than 10 seconds.
This is specifically noticable when the code live-reloads because of a change in the live_views
Im now regularly getting these messages in console:
Verifying CvsWeb.Router (itās taking more than 10s)
This only happens when changing live_views. Live_components are fine and donāt cause this slowdown.
Our suspicion was that the issue is due to the large Cycle that occurs in the Phoenix router. (this seems to be a known issue: Verified routes feature is pathological in terms of compile-connected cycles. Ā· Issue #6522 Ā· phoenixframework/phoenix Ā· GitHub)
> mix xref graph --format cycles
2 cycles found. Showing them in decreasing size:
Cycle of length 106:
.. modules omitted ..
Cycle of length 7:
.. modules omitted ..
But after removing references to verified_route and bringing down the cycle count from 106 to 6 itās still slow.
Weāre seeing these issues on 1.19.1, tried upgrading to 1.19.5 but that didnāt change anything.
I have replied to the issue, but as far as I know, the issue seems to be a false positive: VerifiedRoutes do not add compile-time dependencies to the router. From your description, it seems to be an issue in the verification code itself, an unexpected slow down, rather than something symtomatic, but it is hard to say without the context given.
My suggestion is to either:
- debug and measure where the time is spent in the verification code
- provide a minimal reproduction case
Iāve narrowed down the verification slowdown in the Phoenix router to the Module.Types.Desc.tuple_empty?/1 function.
Profiling indicates most of the time is spent calculating warnings in parallel_checker.ex, specifically within the Expr.of_expr call in Module.Types.
I added instrumentation to Module.Types.Desc.tuple_empty?/1 and found a large number of calls:
# Total time is > 10s even without instrumentation overhead
[Descr Instrumentation Report]
tuple_empty? calls: 4725510
tuple_empty? total time: 17445.936ms
tuple_line_empty? calls: 33037288
tuple_elements_empty? calls: 40118070
intersection calls: 40118070
difference calls: 40118070
max tuple elements seen: 4
max negations count: 15
It appears the bottleneck is caused by the large number of calls to tuple_line_empty? and tuple_elements_empty?
update:
Iāve found that the number of calls to tuple_empty?/1 grows exponentially (roughly 2x) for every def on_mount(...) clause in our UserAuth module. Since we have about 11 of those clauses the number of calls really explodes
This behavior seems tied to how ash_authentication_phoenix interacts with live_session. When using standard Phoenix live_session blocks, the number of calls to these stays constant in relationship to the number of clauses in the UserAuth module.
I will create a minimal reproduction repo to demonstrate the issue
3 Likes
Here is a minimal reproduction repo:
You can change the @total_on_mount_clauses to see the result.
Even without using the modified elixir version with instrumentation you will notice a significant difference between 4 and 16 clauses.
3 Likes
Thank you, this was a very well done sample app! I can no longer reproduce the issue as of v1.20.0-rc.1. Can you confirm thatās the case for you too?
Btw, regarding the 16 clauses, we simplify inferred code once it has more than 16 clausesā¦ 
The issue is gone in the reproduction repo for me too.
On our real project the performance has improved significantly from above 10s to something around 3 seconds
However, if I add a few extra clauses (taking the total to 15) it is still slow, not as slow as it was on 1.19, but above 10 seconds.
Will see if I can figure out whatās causing it
