@zachdaniel Any idea about this? If there is some more tests or code changes that I can do here to help figure this out just let me know 
sezaru
0
zachdaniel
Creator of Ash
I haven’t had a chance to look into this. I don’t think you should have to do that though, the regex should be compiled in. The cached regex stuff was added because an inadvertent change was made in Elixir due to OTP 28.0 that didn’t support regexes at compile time. But that’s been patched in 28.1 and latest Elixir AFAIK. So the regex should be compiled in. And in both cases they use the same option type for regexes.
If you can confirm that going back to the old option and using the tuple format solves the performance issue then it may be a simple fix.
0
sezaru
I feel that trying to understand where the 495 calls to :re.import/1 comes from is a better bet to fix the issue instead of a workaround no?
I tried to find who is calling :re.import using this code:
defmodule Test do
alias Core.Cnpj.Estabelecimento
alias Core.Ash.Resource.Cast
@args %{
cnpj_basico: "11111111",
cnpj_sufixo: "666666",
cnpj_formatado: "22.333.333/4444-22",
nome: "Blibs blobs",
matriz?: false,
situacao_cadastral: :ativa,
inicio_da_atividade: Date.utc_today()
}
def run do
tracer =
spawn(fn ->
receive_loop = fn receive_loop ->
receive do
{:trace_ts, pid, :call, {:re, :import, _args}, _ts} ->
stack = Process.info(pid, :current_stacktrace)
IO.puts("\n=== re.import called by #{inspect(pid)} ===")
IO.inspect(stack)
receive_loop.(receive_loop)
_ ->
receive_loop.(receive_loop)
end
end
receive_loop.(receive_loop)
end)
:erlang.trace(:all, true, [:call, :timestamp, {:tracer, tracer}])
:erlang.trace_pattern({:re, :import, 1}, true, [])
@args
|> Cast.cast(:create, Estabelecimento)
end
end
But the stacktrace I got is not very useful, for my changes, I got these 3 times:
=== re.import called by #PID<0.95.0> ===
{:current_stacktrace,
[
{:code_server, :call, 1, [file: ~c"code_server.erl", line: 163]},
{:code_server, :call, 1, [file: ~c"code_server.erl", line: 163]},
{:code, :ensure_loaded, 1, [file: ~c"code.erl", line: 578]},
{:error_handler, :undefined_function, 3,
[file: ~c"error_handler.erl", line: 86]},
{Ash.Changeset, :run_change_or_validation, 6,
[file: ~c"lib/ash/changeset/changeset.ex", line: 3245]},
{Ash.Changeset, :"-run_action_changes/6-fun-2-", 6,
[file: ~c"lib/ash/changeset/changeset.ex", line: 3150]},
{Enum, :"-reduce/3-lists^foldl/2-0-", 3, [file: ~c"lib/enum.ex", line: 2520]},
{Ash.Changeset, :run_action_changes, 6,
[file: ~c"lib/ash/changeset/changeset.ex", line: 3146]},
{Ash.Changeset, :do_for_action, 4,
[file: ~c"lib/ash/changeset/changeset.ex", line: 2577]},
{Core.Ash.Resource.Cast, :cast, 3,
[file: ~c"lib/core/ash/resource/cast.ex", line: 14]},
{:elixir, :eval_external_handler, 3, [file: ~c"elixir.erl", line: 365]},
{:erl_eval, :do_apply, 7, [file: ~c"erl_eval.erl", line: 924]},
{:elixir, :eval_forms, 4, [file: ~c"elixir.erl", line: 343]},
{Module.ParallelChecker, :verify, 1,
[file: ~c"lib/module/parallel_checker.ex", line: 155]},
...
]}
And for the match constraint, I get this trace repeated 495 times:
=== re.import called by #PID<0.95.0> ===
{:current_stacktrace,
[
{:code_server, :call, 1, [file: ~c"code_server.erl", line: 163]},
{:elixir_compiler, :dispatch, 4, [file: ~c"elixir_compiler.erl", line: 82]},
{:elixir_compiler, :compile, 4, [file: ~c"elixir_compiler.erl", line: 56]},
{:elixir_compiler, :maybe_fast_compile, 2,
[file: ~c"elixir_compiler.erl", line: 43]},
{:elixir_lexical, :run, 3, [file: ~c"elixir_lexical.erl", line: 17]},
{:elixir_compiler, :quoted, 3, [file: ~c"elixir_compiler.erl", line: 21]},
{Module.ParallelChecker, :verify, 1,
[file: ~c"lib/module/parallel_checker.ex", line: 155]},
{Code, :require_file, 2, [file: ~c"lib/code.ex", line: 1613]},
{Kernel.CLI, :wrapper, 1, [file: ~c"lib/kernel/cli.ex", line: 562]},
{Enum, :"-map/2-lists^map/1-1-", 2, [file: ~c"lib/enum.ex", line: 1688]},
{Kernel.CLI, :process_commands, 1, [file: ~c"lib/kernel/cli.ex", line: 93]},
{Kernel.CLI, :"-main/1-fun-1-", 2, [file: ~c"lib/kernel/cli.ex", line: 39]},
{Kernel.CLI, :"-exec_fun/2-fun-0-", 3,
[file: ~c"lib/kernel/cli.ex", line: 141]}
]}
0
sabiwara
Elixir Core Team
:re.import is called by the code generated by expanding the ~r sigil (which needs to re-import the exported binary pattern back to a ref).
~r/foo/
is expanded as
%Regex{
re_pattern:
:re.import(
{:re_exported_pattern, "re-PCRE2¤þ¿", "foo", [:export],
"<<long-binary>>"}
),
source: "foo",
opts: []
}
Importing the exported pattern is faster than re-compiling from scratch (it is the reason it was introduced), but is still is slower than the actual matching.
0
sezaru
But that should only happen 3 times in my resource since I have only used the sigil 3 times in the resource no?
Here is a one file code that reproduces the issue:
Application.put_env(:ash, :validate_domain_resource_inclusion?, false)
Application.put_env(:ash, :validate_domain_config_inclusion?, false)
Mix.install([{:ash, "~> 3.0"}], consolidate_protocols: false)
defmodule Cast do
def cast(arguments, action, resource) do
%{accept: accept} = Ash.Resource.Info.action(resource, action)
with {:ok, resource} <-
resource
|> Ash.Changeset.for_create(action, arguments)
|> Ash.Changeset.apply_attributes() do
{:ok, Map.take(resource, accept)}
end
end
def cast!(arguments, action, resource),
do: arguments |> cast(action, resource) |> Ash.Helpers.unwrap_or_raise!()
end
defmodule Tutorial.Profile do
use Ash.Resource,
domain: Tutorial
actions do
defaults [create: :*]
end
attributes do
uuid_primary_key :id
attribute :attr_1, :string do
public? true
allow_nil? false
constraints min_length: 8, max_length: 8, match: ~r/^[A-Za-z0-9]{8}$/
end
end
end
defmodule Tutorial do
use Ash.Domain
resources do
resource Tutorial.Profile
end
end
defmodule Test do
@args %{attr_1: "11111111"}
def run do
tracer =
spawn(fn ->
receive_loop = fn receive_loop ->
receive do
{:trace_ts, pid, :call, {:re, :import, _args}, _ts} ->
stack = Process.info(pid, :current_stacktrace)
IO.puts("\n=== re.import called by #{inspect(pid)} ===")
IO.inspect(stack)
receive_loop.(receive_loop)
_ ->
receive_loop.(receive_loop)
end
end
receive_loop.(receive_loop)
end)
:erlang.trace(:all, true, [:call, :timestamp, {:tracer, tracer}])
:erlang.trace_pattern({:re, :import, 1}, true, [])
@args |> Cast.cast(:create, Tutorial.Profile)
end
end
Test.run()
0
sabiwara
Elixir Core Team
This is more a question for Ash maintainers, since I don’t know what the macros get expanded to.
But to give a pure elixir example:
# import is called in the lambda, so n times
Enum.map(strings, fn string -> string =~ ~r/foo/ end)
# import is called once
regex = ~r/foo/
Enum.map(strings, fn string -> string =~ regex end)
This is a bit of an unfortunate state of things, but given the way it works in OTP, I don’t think there is an easy way around this. Maybe the compiler could try to be smart and translate the first into the second, but it might break if the lambda invocation is done across nodes.
The ideal fix would be to have actual constants in OTP as @michalmuskala suggested in the past, but I don’t think there’s any active plan for it at the moment.
0
sezaru
Ok, I tested your suggestion and it indeed fixed the issue, I didn’t even needed to change my constraint, I just leave it as a regex since spark will convert it into a cache regardless:
defp validate_type(:regex_as_mfa, _key, %Regex{} = regex) do
source = Regex.source(regex)
opts = Regex.opts(regex)
{:ok, {Spark.Regex, :cache, [source, opts]}}
end
So, the only change I did was change the match type in lib/ash/type/string.ex from :regex to :regex_as_mfa.
With this, now the code is at least twice as fast. Here is a comparison with my code above but looped 10k times with eprof:
with :regex:
# CALLS % TIME µS/CALL
Total 966500 100.0 146590 0.15
with :regex_as_mfa
# CALLS % TIME µS/CALL
Total 912500 100. 59629 0.07
It is almost 3x faster.
@zachdaniel would you consider reverting the types for string.ex, ci_string.ex, type.ex and match.ex from that commit from :regex to :regex_as_mfa?
1
zachdaniel
Creator of Ash
.
sezaru