Commit 768fa49
committed
Optimize inspection of binaries
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.1 parent eadbd8b commit 768fa49
2 files changed
+36
-30
lines changed| Original file line number | Diff line number | Diff line change | |
|---|---|---|---|
| |||
71 | 71 | | |
72 | 72 | | |
73 | 73 | | |
74 | | - | |
| 74 | + | |
75 | 75 | | |
76 | | - | |
| 76 | + | |
77 | 77 | | |
78 | | - | |
| 78 | + | |
79 | 79 | | |
80 | 80 | | |
81 | 81 | | |
82 | 82 | | |
83 | 83 | | |
84 | 84 | | |
85 | 85 | | |
86 | | - | |
| 86 | + | |
87 | 87 | | |
88 | 88 | | |
89 | 89 | | |
90 | | - | |
| 90 | + | |
91 | 91 | | |
92 | 92 | | |
93 | 93 | | |
94 | | - | |
95 | | - | |
| 94 | + | |
| 95 | + | |
| 96 | + | |
| 97 | + | |
| 98 | + | |
| 99 | + | |
96 | 100 | | |
97 | 101 | | |
98 | 102 | | |
99 | | - | |
| 103 | + | |
100 | 104 | | |
101 | 105 | | |
102 | 106 | | |
103 | 107 | | |
104 | 108 | | |
105 | 109 | | |
106 | | - | |
| 110 | + | |
107 | 111 | | |
108 | | - | |
| 112 | + | |
109 | 113 | | |
110 | 114 | | |
111 | 115 | | |
| |||
131 | 135 | | |
132 | 136 | | |
133 | 137 | | |
134 | | - | |
| 138 | + | |
135 | 139 | | |
136 | 140 | | |
137 | | - | |
| 141 | + | |
138 | 142 | | |
139 | 143 | | |
140 | 144 | | |
141 | 145 | | |
142 | | - | |
| 146 | + | |
143 | 147 | | |
144 | 148 | | |
145 | | - | |
| 149 | + | |
146 | 150 | | |
147 | | - | |
| 151 | + | |
148 | 152 | | |
149 | 153 | | |
150 | | - | |
| 154 | + | |
151 | 155 | | |
152 | | - | |
| 156 | + | |
153 | 157 | | |
154 | 158 | | |
155 | | - | |
| 159 | + | |
156 | 160 | | |
157 | | - | |
| 161 | + | |
| 162 | + | |
| 163 | + | |
158 | 164 | | |
159 | 165 | | |
160 | | - | |
161 | | - | |
162 | | - | |
163 | | - | |
164 | | - | |
165 | | - | |
166 | | - | |
167 | | - | |
168 | | - | |
169 | | - | |
| 166 | + | |
| 167 | + | |
| 168 | + | |
| 169 | + | |
| 170 | + | |
| 171 | + | |
| 172 | + | |
| 173 | + | |
| 174 | + | |
| 175 | + | |
170 | 176 | | |
171 | 177 | | |
172 | 178 | | |
| |||
| Original file line number | Diff line number | Diff line change | |
|---|---|---|---|
| |||
326 | 326 | | |
327 | 327 | | |
328 | 328 | | |
329 | | - | |
| 329 | + | |
330 | 330 | | |
331 | 331 | | |
332 | 332 | | |
| |||
0 commit comments