This code added in 6951f0cd2a was made obsolete in aee7fbc0dc (v1.1). Correct macrocallback handling was added in 04f151b68b (v1.10) and since then macro caller arg is passed to typespecs as `term()` instead of `Macro.Env.t()`
We have used this code:
data = Base.encode64(:crypto.strong_rand_bytes(2_000_000))
Mix.Tasks.Profile.Tprof.profile(
fn -> inspect(data, printable_limit: :infinity) end,
type: :memory
)
The first result reported this:
Profile results of #PID<0.106.0>
# CALLS % WORDS PER CALL
Total 10666685 100.00 9268308211 868.90
:code.ensure_loaded/1 1 0.00 3 3.00
Inspect.BitString.inspect/2 1 0.00 4 4.00
Inspect.Algebra.group/2 1 0.00 4 4.00
Inspect.Algebra.format/2 1 0.00 6 6.00
Inspect.Algebra.format/3 3 0.00 8 2.67
:erlang.iolist_to_binary/1 2 0.00 11 5.50
anonymous fn/2 in Kernel.struct/2 1 0.00 17 17.00
Inspect.Opts.new/1 1 0.00 17 17.00
Code.Identifier.escape/5 2666669 0.06 5333344 2.00
String.recur_printable?/2 2666669 0.29 26666778 10.00
Code.Identifier.escape_map/1 2666668 28.72 2662035405 998.26
Code.Identifier.escape_char/1 2666668 70.93 6574272614 2465.35
As you can see, most of the allocations were in escape_char,
which makes sense: it will be invoked a lot for raw binaries
and it allocated lists, instead of relying on binary optimizations.
We reimplemented Code.Identifier.escape/5 to rely on binary
optimizations which then yielded this:
Profile results of #PID<0.112.0>
# CALLS % WORDS PER CALL
Total 5333350 100.00 26666864 5.00
:code.ensure_loaded/1 1 0.00 3 3.00
Inspect.BitString.inspect/2 1 0.00 4 4.00
Inspect.Algebra.group/2 1 0.00 4 4.00
Inspect.Algebra.format/2 1 0.00 6 6.00
Code.Identifier.escape/4 1 0.00 8 8.00
Code.Identifier.escape/5 2666669 0.00 8 0.00
Inspect.Algebra.format/3 3 0.00 8 2.67
:erlang.iolist_to_binary/1 2 0.00 11 5.50
anonymous fn/2 in Kernel.struct/2 1 0.00 17 17.00
Inspect.Opts.new/1 1 0.00 17 17.00
String.recur_printable?/2 2666669 100.00 26666778 10.00
Now the allocations are all on `recur_printable?/2`. By running this
command, we can find out why it is allocating so much:
ERL_COMPILER_OPTIONS=bin_opt_info elixir lib/elixir/lib/string.ex
It happens that, due to a catch all, new binary contexts had to be
allocated. By addressing that, we now get:
Profile results of #PID<0.119.0>
# CALLS % WORDS PER CALL
Total 5333350 100.00 91 0.00
:code.ensure_loaded/1 1 3.30 3 3.00
Inspect.BitString.inspect/2 1 4.40 4 4.00
Inspect.Algebra.group/2 1 4.40 4 4.00
String.recur_printable?/2 2666669 5.49 5 0.00
Inspect.Algebra.format/2 1 6.59 6 6.00
Code.Identifier.escape/4 1 8.79 8 8.00
Code.Identifier.escape/5 2666669 8.79 8 0.00
Inspect.Algebra.format/3 3 8.79 8 2.67
:erlang.iolist_to_binary/1 2 12.09 11 5.50
anonymous fn/2 in Kernel.struct/2 1 18.68 17 17.00
Inspect.Opts.new/1 1 18.68 17 17.00
Which is several orders of magnitude fewer words. We basically
allocate the new escaped binary and a few extra bytes.
Closes#14029.
The typos were detected by this app: https://pypi.org/project/typos/
running the following command
typos --exclude "lib/elixir/unicode/" --exclude "man/" --exclude "typos" --format brief
José Valim
Jonatan Kłosko
Michał Łępicki
Mathias Polligkeit
Jean Klingler
Panagiotis Nezis
Andrea Leopardi
Alex Naser
Leif Metcalf
Łukasz Samson
peter madsen-mygdal
Ray Chang
Theodor Fiedler
Eksperimental
maintenance-beam-app
