sezaru

sezaru OP

@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 :slight_smile:

0
Post #11
zachdaniel

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
Post #12
sezaru

sezaru OP

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
Post #13
sabiwara

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
Post #14
sezaru

sezaru OP

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
Post #15
sabiwara

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
Post #16
sezaru

sezaru OP

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
Post #17
zachdaniel

zachdaniel

Creator of Ash

Hmm… yes. I would accept a PR that does that :person_bowing:.

0
Post #18
sezaru

sezaru OP

The PR was merged, so I’m closing this :slight_smile:

0
Post #20
— All posts loaded —