Discussion:
[erlang-questions] Garbage Collection, BEAM memory and Erlang memory
Roberto Ostinelli
2015-01-22 16:33:57 UTC
Permalink
Dear List,
I'm having some troubles in pinpointing why a node is crashing due to
memory issues.
For info, when it crashes, it does not produce a crash dump. However I've
monitored live and I've seen the .beam process eat up all memory until it
abruptly exits.

The system is a big router that relays data coming from TCP connections,
into other TCP connections.
I'm using cowboy as the HTTP server that initiates the long-lived TCP
connections.

I've done all the obvious:

- Checked the States of my gen_servers and processes.
- Checked my processes mailboxes (the ones with the longest queue have 1
item in the inbox).
- My ETS table memory is constant (see below).

I put the system under controlled load, and I can see with
length(processes()). that my process count is stable, always around 120,000.

I check the processes that are using most memory with this call:

MostMemory = fun(N) ->
lists:sublist(
lists:sort(
fun({_, _, V1}, {_, _, V2}) -> V1 >= V2 end,
[try
[{memory, Mem}, {registered_name, RegName}] =
erlang:process_info(Pid, [memory, registered_name]),
{Pid, RegName, Mem}
catch _:_ ->
{Pid, undefined, 0}
end || Pid <- processes(), Pid =/= self()]
), N)
end.

Which always returns very similar numbers:

1> MostMemory(20).
[{<0.96.0>,[],5180448},
{<0.78.0>,tls_connection_sup,4525096},
{<0.6.0>,error_logger,743776},
{<0.7.0>,application_controller,372592},
{<0.77.0>,ssl_manager,284640},
{<0.11.0>,kernel_sup,176712},
{<0.26.0>,code_server,176272},
{<0.33.0>,[],143064},
{<0.419.0>,[],142896},
{<0.420.0>,[],142896},
{<0.421.0>,[],142896},
{<0.422.0>,[],142896},
{<0.423.0>,[],142896},
{<0.424.0>,[],142896},
{<0.425.0>,[],142896},
{<0.426.0>,[],142896},
{<0.427.0>,[],142896},
{<0.428.0>,[],142896},
{<0.429.0>,[],142896},
{<0.430.0>,[],142896}]

See the last processes there with all identical memory? These are the
processes handling the connections, and they stay stable with the same
identical number throughout all test.

I get the pid of the .beam process, and I check its reported RES memory
with top -p beam-pid-here.
I get my erlang memory with this simple call (I just convert everything to
GB, thanks to Ferd and his article
https://blog.heroku.com/archives/2013/11/7/logplex-down-the-rabbit-hole):

[{K,V / math:pow(1024,3)} || {K,V} <- erlang:memory()].

This is what I get (at random time intervals):

- BEAM process RES memory:* 2.751 GB*
- Erlang memory:
[{total,2.11871287971735},
{processes,1.6582859307527542},
{processes_used,1.6581560596823692},
{system,0.4604269489645958},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.29880597442388535},
{code,0.009268132038414478},
{ets,0.004808835685253143}]

- BEAM process RES memory:* 3.039 GB*
- Erlang memory:
[{total,2.2570599243044853},
{processes,1.7243007272481918},
{processes_used,1.7241046279668808},
{system,0.5327591970562935},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.37129393219947815},
{code,0.009268132038414478},
{ets,0.004808835685253143}]

- BEAM process RES memory:* 3.630 GB*
- Erlang memory:
[{total,2.677028402686119},
{processes,2.1421403884887695},
{processes_used,2.142106533050537},
{system,0.5348880141973495},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.37329262495040894},
{code,0.009268132038414478},
{ets,0.004808835685253143}]

- BEAM process RES memory:* 3.807 GB*
- Erlang memory:
[{total,2.9233806803822517},
{processes,2.277688652276993},
{processes_used,2.277618482708931},
{system,0.6456920281052589},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.48407071083784103},
{code,0.009268132038414478},
{ets,0.004808835685253143}]


- BEAM process RES memory:* 4.026 GB*
- Erlang memory:
[{total,2.8762372359633446},
{processes,2.100425034761429},
{processes_used,2.1003194376826286},
{system,0.7758122012019157},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.6143399104475975},
{code,0.009268132038414478},
{ets,0.004808835685253143}]


- BEAM process RES memory:* 4.136 GB*
- Erlang memory:
[{total,2.9030912443995476},
{processes,2.028559662401676},
{processes_used,2.0283572375774384},
{system,0.8745315819978714},
{atom,4.000673070549965e-4},
{atom_used,3.847004845738411e-4},
{binary,0.7129654437303543},
{code,0.00929991528391838},
{ets,0.004809550940990448}]


- BEAM process RES memory:* 4.222 GB*
- Erlang memory:
[{total,2.785604253411293},
{processes,1.875294029712677},
{processes_used,1.8752291351556778},
{system,0.910310223698616},
{atom,4.000673070549965e-4},
{atom_used,3.847004845738411e-4},
{binary,0.7487552836537361},
{code,0.00929991528391838},
{ets,0.004809550940990448}]


As you can see, at the beginning both the BEAM RES memory and the total
Erlang memory increase, but after a while it becomes clear that the BEAM
process memory keeps increasing while the memory reported as used by Erlang
stabilizes, and even decreases.
Erlang reported memory never surpasses 3 GB.

At this point I tried forcing a Garbage Collection:

[erlang:garbage_collect(Pid) || Pid <- processes()]

After that, we went back to:

- BEAM process RES memory:* 3.336 GB*
- Erlang memory:
[{total,1.9107630401849747},
{processes,1.5669479593634605},
{processes_used,1.5668926388025284},
{system,0.34381508082151413},
{atom,4.000673070549965e-4},
{atom_used,3.847004845738411e-4},
{binary,0.18235664814710617},
{code,0.00929991528391838},
{ets,0.004809550940990448}]

However after that, I let the system go and it kept on having the same
behavior (and increasing the BEAM memory).

What puzzles me is that you can clearly see that:

- The total memory used by processes is increasing, however the top
processes always use the same amount of memory (and the process count is
always stable).
- Binary consumption also increases, but in proportion with process
memory (and my data is <64K so I don't anticipate it being an issue of
Refc-binaries not being garbage collected).

I already hibernate most of the long-term open connections.
I also added a periodic garbage collector on the main router, since it
touches all the binaries that go through it, to ensure that all
Refc-binaries that hold a reference to the router are garbage collected.

So I tried the hard approach, and I've set fullsweep_after to 0 as a system
flag (passed in as an environment variable -env ERL_FULLSWEEP_AFTER 0).

After this, I could see notable improvements:

- BEAM process RES memory:* 2.049 GB*
- Erlang memory:
[{total,1.597476489841938},
{processes,1.2037805244326591},
{processes_used,1.2036690935492516},
{system,0.39369596540927887},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.2321353331208229},
{code,0.009268132038414478},
{ets,0.004821933805942535}]

- BEAM process RES memory:* 1.919 GB*
- Erlang memory:
[{total,1.549286112189293},
{processes,1.1740453317761421},
{processes_used,1.1739420965313911},
{system,0.3752407804131508},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.2134672999382019},
{code,0.009268132038414478},
{ets,0.004821933805942535}]

- BEAM process RES memory:* 2.004 GB*
- Erlang memory:
[{total,1.6023957282304764},
{processes,1.2192133665084839},
{processes_used,1.219102293252945},
{system,0.3831823617219925},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.22155668586492538},
{code,0.009268132038414478},
{ets,0.004821933805942535}]

- BEAM process RES memory:* 2.456 GB*
- Erlang memory:
[{total,1.7860298827290535},
{processes,1.4158401936292648},
{processes_used,1.4157484397292137},
{system,0.37018968909978867},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.20867645740509033},
{code,0.009268132038414478},
{ets,0.004821933805942535}]

- BEAM process RES memory:* 2.455 GB*
- Erlang memory:
[{total,1.8919306173920631},
{processes,1.4726912006735802},
{processes_used,1.4726523533463478},
{system,0.41923941671848297},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.25766071677207947},
{code,0.009268132038414478},
{ets,0.004821933805942535}]


However, the down size to this is obviously that the CPU load increased
almost of a point.

I also have a GC "guardian" similar to the one that Fred implemented in
Heroku's logplex:
https://github.com/heroku/logplex/blob/master/src/logplex_leak.erl

But this obviously is a guard, not a solution per se.

Can anyone give me some pointers on how I can process to identify what is
going on?

Thank you,
r.
Robert Virding
2015-01-22 17:00:37 UTC
Permalink
One thing you can see is that the size of the binary data is growing. This
space contains the large binaries (> 64 bytes) which are sent in messages
between processes. While this means that the messages become (much) smaller
and faster to send it takes a much longer time to detect that they are no
longer alive and can be reclaimed. Basically it takes until all the
processes they have passed through does a full garbage collection. Setting
fullsweep_after to 0 and doing explicit garbage collects speeds up
reclaiming the binaries.

You could be much more selective in which processes you set fullsweep_after
to 0 and which ones you explicitly garbage collect.

I don't know if the is *the* problem but it is *a* problem you have.

Robert
Post by Roberto Ostinelli
Dear List,
I'm having some troubles in pinpointing why a node is crashing due to
memory issues.
For info, when it crashes, it does not produce a crash dump. However I've
monitored live and I've seen the .beam process eat up all memory until it
abruptly exits.
The system is a big router that relays data coming from TCP connections,
into other TCP connections.
I'm using cowboy as the HTTP server that initiates the long-lived TCP
connections.
- Checked the States of my gen_servers and processes.
- Checked my processes mailboxes (the ones with the longest queue have
1 item in the inbox).
- My ETS table memory is constant (see below).
I put the system under controlled load, and I can see with
length(processes()). that my process count is stable, always around 120,000.
MostMemory = fun(N) ->
lists:sublist(
lists:sort(
fun({_, _, V1}, {_, _, V2}) -> V1 >= V2 end,
[try
[{memory, Mem}, {registered_name, RegName}] =
erlang:process_info(Pid, [memory, registered_name]),
{Pid, RegName, Mem}
catch _:_ ->
{Pid, undefined, 0}
end || Pid <- processes(), Pid =/= self()]
), N)
end.
1> MostMemory(20).
[{<0.96.0>,[],5180448},
{<0.78.0>,tls_connection_sup,4525096},
{<0.6.0>,error_logger,743776},
{<0.7.0>,application_controller,372592},
{<0.77.0>,ssl_manager,284640},
{<0.11.0>,kernel_sup,176712},
{<0.26.0>,code_server,176272},
{<0.33.0>,[],143064},
{<0.419.0>,[],142896},
{<0.420.0>,[],142896},
{<0.421.0>,[],142896},
{<0.422.0>,[],142896},
{<0.423.0>,[],142896},
{<0.424.0>,[],142896},
{<0.425.0>,[],142896},
{<0.426.0>,[],142896},
{<0.427.0>,[],142896},
{<0.428.0>,[],142896},
{<0.429.0>,[],142896},
{<0.430.0>,[],142896}]
See the last processes there with all identical memory? These are the
processes handling the connections, and they stay stable with the same
identical number throughout all test.
I get the pid of the .beam process, and I check its reported RES memory
with top -p beam-pid-here.
I get my erlang memory with this simple call (I just convert everything to
GB, thanks to Ferd and his article
[{K,V / math:pow(1024,3)} || {K,V} <- erlang:memory()].
- BEAM process RES memory:* 2.751 GB*
[{total,2.11871287971735},
{processes,1.6582859307527542},
{processes_used,1.6581560596823692},
{system,0.4604269489645958},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.29880597442388535},
{code,0.009268132038414478},
{ets,0.004808835685253143}]
- BEAM process RES memory:* 3.039 GB*
[{total,2.2570599243044853},
{processes,1.7243007272481918},
{processes_used,1.7241046279668808},
{system,0.5327591970562935},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.37129393219947815},
{code,0.009268132038414478},
{ets,0.004808835685253143}]
- BEAM process RES memory:* 3.630 GB*
[{total,2.677028402686119},
{processes,2.1421403884887695},
{processes_used,2.142106533050537},
{system,0.5348880141973495},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.37329262495040894},
{code,0.009268132038414478},
{ets,0.004808835685253143}]
- BEAM process RES memory:* 3.807 GB*
[{total,2.9233806803822517},
{processes,2.277688652276993},
{processes_used,2.277618482708931},
{system,0.6456920281052589},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.48407071083784103},
{code,0.009268132038414478},
{ets,0.004808835685253143}]
- BEAM process RES memory:* 4.026 GB*
[{total,2.8762372359633446},
{processes,2.100425034761429},
{processes_used,2.1003194376826286},
{system,0.7758122012019157},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.6143399104475975},
{code,0.009268132038414478},
{ets,0.004808835685253143}]
- BEAM process RES memory:* 4.136 GB*
[{total,2.9030912443995476},
{processes,2.028559662401676},
{processes_used,2.0283572375774384},
{system,0.8745315819978714},
{atom,4.000673070549965e-4},
{atom_used,3.847004845738411e-4},
{binary,0.7129654437303543},
{code,0.00929991528391838},
{ets,0.004809550940990448}]
- BEAM process RES memory:* 4.222 GB*
[{total,2.785604253411293},
{processes,1.875294029712677},
{processes_used,1.8752291351556778},
{system,0.910310223698616},
{atom,4.000673070549965e-4},
{atom_used,3.847004845738411e-4},
{binary,0.7487552836537361},
{code,0.00929991528391838},
{ets,0.004809550940990448}]
As you can see, at the beginning both the BEAM RES memory and the total
Erlang memory increase, but after a while it becomes clear that the BEAM
process memory keeps increasing while the memory reported as used by Erlang
stabilizes, and even decreases.
Erlang reported memory never surpasses 3 GB.
[erlang:garbage_collect(Pid) || Pid <- processes()]
- BEAM process RES memory:* 3.336 GB*
[{total,1.9107630401849747},
{processes,1.5669479593634605},
{processes_used,1.5668926388025284},
{system,0.34381508082151413},
{atom,4.000673070549965e-4},
{atom_used,3.847004845738411e-4},
{binary,0.18235664814710617},
{code,0.00929991528391838},
{ets,0.004809550940990448}]
However after that, I let the system go and it kept on having the same
behavior (and increasing the BEAM memory).
- The total memory used by processes is increasing, however the top
processes always use the same amount of memory (and the process count is
always stable).
- Binary consumption also increases, but in proportion with process
memory (and my data is <64K so I don't anticipate it being an issue of
Refc-binaries not being garbage collected).
I already hibernate most of the long-term open connections.
I also added a periodic garbage collector on the main router, since it
touches all the binaries that go through it, to ensure that all
Refc-binaries that hold a reference to the router are garbage collected.
So I tried the hard approach, and I've set fullsweep_after to 0 as a
system flag (passed in as an environment variable -env
ERL_FULLSWEEP_AFTER 0).
- BEAM process RES memory:* 2.049 GB*
[{total,1.597476489841938},
{processes,1.2037805244326591},
{processes_used,1.2036690935492516},
{system,0.39369596540927887},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.2321353331208229},
{code,0.009268132038414478},
{ets,0.004821933805942535}]
- BEAM process RES memory:* 1.919 GB*
[{total,1.549286112189293},
{processes,1.1740453317761421},
{processes_used,1.1739420965313911},
{system,0.3752407804131508},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.2134672999382019},
{code,0.009268132038414478},
{ets,0.004821933805942535}]
- BEAM process RES memory:* 2.004 GB*
[{total,1.6023957282304764},
{processes,1.2192133665084839},
{processes_used,1.219102293252945},
{system,0.3831823617219925},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.22155668586492538},
{code,0.009268132038414478},
{ets,0.004821933805942535}]
- BEAM process RES memory:* 2.456 GB*
[{total,1.7860298827290535},
{processes,1.4158401936292648},
{processes_used,1.4157484397292137},
{system,0.37018968909978867},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.20867645740509033},
{code,0.009268132038414478},
{ets,0.004821933805942535}]
- BEAM process RES memory:* 2.455 GB*
[{total,1.8919306173920631},
{processes,1.4726912006735802},
{processes_used,1.4726523533463478},
{system,0.41923941671848297},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.25766071677207947},
{code,0.009268132038414478},
{ets,0.004821933805942535}]
However, the down size to this is obviously that the CPU load increased
almost of a point.
I also have a GC "guardian" similar to the one that Fred implemented in
https://github.com/heroku/logplex/blob/master/src/logplex_leak.erl
But this obviously is a guard, not a solution per se.
Can anyone give me some pointers on how I can process to identify what is
going on?
Thank you,
r.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Roberto Ostinelli
2015-01-22 17:11:07 UTC
Permalink
Thank you Robert.
I'm going to try a selective fullsweep_after.

Could this also justify the process memory increase (which is more
significant)?
Post by Robert Virding
One thing you can see is that the size of the binary data is growing. This
space contains the large binaries (> 64 bytes) which are sent in messages
between processes. While this means that the messages become (much) smaller
and faster to send it takes a much longer time to detect that they are no
longer alive and can be reclaimed. Basically it takes until all the
processes they have passed through does a full garbage collection. Setting
fullsweep_after to 0 and doing explicit garbage collects speeds up
reclaiming the binaries.
You could be much more selective in which processes you set
fullsweep_after to 0 and which ones you explicitly garbage collect.
I don't know if the is *the* problem but it is *a* problem you have.
Robert
Roberto Ostinelli
2015-01-22 17:38:56 UTC
Permalink
Here's something I've tried which is successful in avoiding the memory
increase for binaries.

Inside a loop, I used to have:

[...]
<<Body:Len/binary, "\r\n", Rest/binary>> = Data,
loop(Body, Rest);

Now I force a binary copy to ensure that the reference to the original full
binary is easily removed:

[...]
<<Body0:Len/binary, "\r\n", Rest0/binary>> = Data,
Body = binary:copy(Body0),
Rest = binary:copy(Rest0),
loop(Body, Rest);

This seems to have stabilized the memory usage reported by erlang:memory/0.

However:

- I believe this can only work if the copied binary are *heap* and not
*ref-c*, is this correct?
- Unfortunately, the BEAM process reported RES memory sill keeps growing.

Any other ideas?
r.
Post by Roberto Ostinelli
Thank you Robert.
I'm going to try a selective fullsweep_after.
Could this also justify the process memory increase (which is more
significant)?
Post by Robert Virding
One thing you can see is that the size of the binary data is growing.
This space contains the large binaries (> 64 bytes) which are sent in
messages between processes. While this means that the messages become
(much) smaller and faster to send it takes a much longer time to detect
that they are no longer alive and can be reclaimed. Basically it takes
until all the processes they have passed through does a full garbage
collection. Setting fullsweep_after to 0 and doing explicit garbage
collects speeds up reclaiming the binaries.
You could be much more selective in which processes you set
fullsweep_after to 0 and which ones you explicitly garbage collect.
I don't know if the is *the* problem but it is *a* problem you have.
Robert
Valentin Micic
2015-01-22 17:48:15 UTC
Permalink
If you going to copy, you may just as well use lists instead of binary…

V/
Here's something I've tried which is successful in avoiding the memory increase for binaries.
[...]
<<Body:Len/binary, "\r\n", Rest/binary>> = Data,
loop(Body, Rest);
[...]
<<Body0:Len/binary, "\r\n", Rest0/binary>> = Data,
Body = binary:copy(Body0),
Rest = binary:copy(Rest0),
loop(Body, Rest);
This seems to have stabilized the memory usage reported by erlang:memory/0.
I believe this can only work if the copied binary are heap and not ref-c, is this correct?
Unfortunately, the BEAM process reported RES memory sill keeps growing.
Any other ideas?
r.
Thank you Robert.
I'm going to try a selective fullsweep_after.
Could this also justify the process memory increase (which is more significant)?
One thing you can see is that the size of the binary data is growing. This space contains the large binaries (> 64 bytes) which are sent in messages between processes. While this means that the messages become (much) smaller and faster to send it takes a much longer time to detect that they are no longer alive and can be reclaimed. Basically it takes until all the processes they have passed through does a full garbage collection. Setting fullsweep_after to 0 and doing explicit garbage collects speeds up reclaiming the binaries.
You could be much more selective in which processes you set fullsweep_after to 0 and which ones you explicitly garbage collect.
I don't know if the is *the* problem but it is *a* problem you have.
Robert
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Roberto Ostinelli
2015-01-22 17:56:04 UTC
Permalink
It's an interesting point, though as stated I'm using cowboy. Don't tell me
I have to revive misultin, I won't ^^_

Do you have an alternative suggestion?

Best,
r.
If you going to copy, you may just as well use lists instead of binary

V/
Sergej Jurecko
2015-01-22 18:14:54 UTC
Permalink
How about regular respawning of processes? Sockets can easily be transfered to new processes. I’m not sure how difficult that would be to achieve with cowboy however.


Sergej
It's an interesting point, though as stated I'm using cowboy. Don't tell me I have to revive misultin, I won't ^^_
Do you have an alternative suggestion?
Best,
r.
If you going to copy, you may just as well use lists instead of binary…
V/
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Dan Gudmundsson
2015-01-23 06:14:05 UTC
Permalink
Post by Roberto Ostinelli
Here's something I've tried which is successful in avoiding the memory
increase for binaries.
[...]
<<Body:Len/binary, "\r\n", Rest/binary>> = Data,
loop(Body, Rest);
Now I force a binary copy to ensure that the reference to the original
[...]
<<Body0:Len/binary, "\r\n", Rest0/binary>> = Data,
Body = binary:copy(Body0),
Rest = binary:copy(Rest0),
loop(Body, Rest);
This seems to have stabilized the memory usage reported by erlang:memory/0
.
- I believe this can only work if the copied binary are *heap* and not
*ref-c*, is this correct?
Binary copy makes a new copy of the binary regardless of size, but it is
only useful on ref-c binaries,
and should be used to avoid keeping references to large binaries, when you
keep and use a small part
of the original binary. But in this case you make a copy of Data (-2 bytes)
and thus will double up the memory until Data is gc'ed and refc reaches
zero. So I do not see the point of the above nor of making it a list which
will
only explode your memory even more.
Post by Roberto Ostinelli
- Unfortunately, the BEAM process reported RES memory sill keeps growing.
Any other ideas?
r.
Post by Roberto Ostinelli
Thank you Robert.
I'm going to try a selective fullsweep_after.
Could this also justify the process memory increase (which is more
significant)?
Post by Robert Virding
One thing you can see is that the size of the binary data is growing.
This space contains the large binaries (> 64 bytes) which are sent in
messages between processes. While this means that the messages become
(much) smaller and faster to send it takes a much longer time to detect
that they are no longer alive and can be reclaimed. Basically it takes
until all the processes they have passed through does a full garbage
collection. Setting fullsweep_after to 0 and doing explicit garbage
collects speeds up reclaiming the binaries.
You could be much more selective in which processes you set
fullsweep_after to 0 and which ones you explicitly garbage collect.
I don't know if the is *the* problem but it is *a* problem you have.
Robert
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Mahesh Paolini-Subramanya
2015-01-23 09:09:19 UTC
Permalink
In our case, a key insight is something Robert mentioned earlier.
To paraphrase it, "Your memory is not going to be reclaimed till *every*
process that touched it has either been GC'd, or sleeps with the fishes".
And our code had a few router processes that, quite literally, did nothing
but pass binaries on from point A to point B - no reason to worry about
*those* right? (hint: wrong)

In the short run, walking the process chain and doing full-sweeps on
*every* process that might (!!!) touch the binary. (we did that)
In the longer run, see if you can swap out the routing processes with
versions that respawn themselves in some form or the other (we did that
too. eventually. was harder)

Cheers
Post by Dan Gudmundsson
Post by Roberto Ostinelli
Here's something I've tried which is successful in avoiding the memory
increase for binaries.
[...]
<<Body:Len/binary, "\r\n", Rest/binary>> = Data,
loop(Body, Rest);
Now I force a binary copy to ensure that the reference to the original
[...]
<<Body0:Len/binary, "\r\n", Rest0/binary>> = Data,
Body = binary:copy(Body0),
Rest = binary:copy(Rest0),
loop(Body, Rest);
This seems to have stabilized the memory usage reported by
erlang:memory/0.
- I believe this can only work if the copied binary are *heap* and
not *ref-c*, is this correct?
Binary copy makes a new copy of the binary regardless of size, but it is
only useful on ref-c binaries,
and should be used to avoid keeping references to large binaries, when you
keep and use a small part
of the original binary. But in this case you make a copy of Data (-2
bytes) and thus will double up the memory until Data is gc'ed and refc
reaches zero. So I do not see the point of the above nor of making it a
list which will
only explode your memory even more.
Post by Roberto Ostinelli
- Unfortunately, the BEAM process reported RES memory sill keeps growing.
Any other ideas?
r.
Post by Roberto Ostinelli
Thank you Robert.
I'm going to try a selective fullsweep_after.
Could this also justify the process memory increase (which is more
significant)?
Post by Robert Virding
One thing you can see is that the size of the binary data is growing.
This space contains the large binaries (> 64 bytes) which are sent in
messages between processes. While this means that the messages become
(much) smaller and faster to send it takes a much longer time to detect
that they are no longer alive and can be reclaimed. Basically it takes
until all the processes they have passed through does a full garbage
collection. Setting fullsweep_after to 0 and doing explicit garbage
collects speeds up reclaiming the binaries.
You could be much more selective in which processes you set
fullsweep_after to 0 and which ones you explicitly garbage collect.
I don't know if the is *the* problem but it is *a* problem you have.
Robert
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
--
*Mahesh Paolini-Subramanya
<Loading Image...>That
tall bald Indian guy..*
*Google+ <https://plus.google.com/u/0/108074935470209044442/posts> | Blog
<http://dieswaytoofast.blogspot.com/> | Twitter
<https://twitter.com/dieswaytoofast> | LinkedIn
<http://www.linkedin.com/in/dieswaytoofast>*
Roberto Ostinelli
2015-01-23 12:30:08 UTC
Permalink
Thank you Mahesh.

I even have a fullsweep_after 0 in the router process, even though it is
literally never touching the data: the router API will lookup an element in
a router ETS table, and will immediately send the data to that process -
without being sent to the router itself.

The swapping seems an interesting option and has also been suggested here
above. Not sure how easily it can be done.

On Fri, Jan 23, 2015 at 10:09 AM, Mahesh Paolini-Subramanya <
Post by Mahesh Paolini-Subramanya
In our case, a key insight is something Robert mentioned earlier.
To paraphrase it, "Your memory is not going to be reclaimed till *every*
process that touched it has either been GC'd, or sleeps with the fishes".
And our code had a few router processes that, quite literally, did nothing
but pass binaries on from point A to point B - no reason to worry about
*those* right? (hint: wrong)
In the short run, walking the process chain and doing full-sweeps on
*every* process that might (!!!) touch the binary. (we did that)
In the longer run, see if you can swap out the routing processes with
versions that respawn themselves in some form or the other (we did that
too. eventually. was harder)
Cheers
Roberto Ostinelli
2015-01-23 12:27:59 UTC
Permalink
Correct, however just after this call the process gets hibernated so Data
(I assume) is getting gc'ed right away).
Post by Roberto Ostinelli
Binary copy makes a new copy of the binary regardless of size, but it is
only useful on ref-c binaries,
and should be used to avoid keeping references to large binaries, when you
keep and use a small part
of the original binary. But in this case you make a copy of Data (-2
bytes) and thus will double up the memory until Data is gc'ed and refc
reaches zero. So I do not see the point of the above nor of making it a
list which will
only explode your memory even more.
Tony Rogvall
2015-01-23 12:55:40 UTC
Permalink
Correct, however just after this call the process gets hibernated so Data (I assume) is getting gc'ed right away).
hibernate will garbage collect before going to sleep.
Binary copy makes a new copy of the binary regardless of size, but it is only useful on ref-c binaries,
and should be used to avoid keeping references to large binaries, when you keep and use a small part
of the original binary. But in this case you make a copy of Data (-2 bytes) and thus will double up the memory until Data is gc'ed and refc reaches zero. So I do not see the point of the above nor of making it a list which will
only explode your memory even more.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Anton Lebedevich
2015-01-22 18:41:12 UTC
Permalink
Hello.

Do you have any external monitoring system in place (like statsderl or
exometer + graphite) that watches erlang memory consumption (process,
binary, ... total)? What is the long-term growth trend? Is it linear
or similar to capacitor charge (like
Loading Image...)

From the data provided it looks like some subpopulation of processes
is growing their heaps. It might happen for mid- or small-sized
processes since top processes always have the same size.
Can you measure [memory, message_queue_len, total_heap_size,
heap_size, stack_size] for all processes several times (with the same
interval as you measured total memory growth) and compare histograms
of their memory consumption? Or upload that data somewhere and I'll
play with it in R to find what's changing inside.


Regards,
Anton Lebedevich.

PS forgot to reply to the list
Roberto Ostinelli
2015-01-23 12:26:27 UTC
Permalink
Thank you Anton,
I do not have such system yet in place, as this isn't a production
environment (yet).

Will definitely add one asap.

Thanks,
r.
Post by Anton Lebedevich
Hello.
Do you have any external monitoring system in place (like statsderl or
exometer + graphite) that watches erlang memory consumption (process,
binary, ... total)? What is the long-term growth trend? Is it linear
or similar to capacitor charge (like
http://hades.mech.northwestern.edu/index.php/File:RC_charge_voltage.gif)
From the data provided it looks like some subpopulation of processes
is growing their heaps. It might happen for mid- or small-sized
processes since top processes always have the same size.
Can you measure [memory, message_queue_len, total_heap_size,
heap_size, stack_size] for all processes several times (with the same
interval as you measured total memory growth) and compare histograms
of their memory consumption? Or upload that data somewhere and I'll
play with it in R to find what's changing inside.
Regards,
Anton Lebedevich.
PS forgot to reply to the list
Jesper Louis Andersen
2015-01-23 13:58:05 UTC
Permalink
Post by Roberto Ostinelli
I do not have such system yet in place, as this isn't a production
environment (yet).
Will definitely add one asap.
In my experience, instrumentation of the running production/development
system is one of the most important things to add early on. The views of
the system it gives and the depth at which it explains what is going on
will help in so many debugging scenarios you can't fathom it.

My hunch is you are holding on to binary values for too long in some
processes, or are storing a ref-c binary in ETS which keeps the underlying
binary alive. The two major ways to handle this has already been mentioned.

If you are picking apart a large binary, and you need to reference *binary*
data in it, then it may be beneficial to break that binary data off:

<<Payload:Len/binary, "\r\n", Rest/binary>> = Packet,
CPayload = binary:copy(Payload),
...
recurse_on(Rest).

but as Dan says, copying `Rest` in this case is a bad idea. You just copy
the very binary you are running over and processing. Also note that it is
important you are picking out binary data. If you had something like

<<I:32/integer, "\r\n", Rest/binary>>

then the integer conversion already excises the data from the binary, so
you don't have to keep the binary around anymore.
--
J.
Roberto Ostinelli
2015-01-23 14:09:50 UTC
Permalink
Hi Jesper, thank you for your input.


My hunch is you are holding on to binary values for too long in some
Post by Jesper Louis Andersen
processes, or are storing a ref-c binary in ETS which keeps the underlying
binary alive. The two major ways to handle this has already been mentioned.
I'm not storing binaries in a ETS. Also, I don't see anywhere I'm holding
binary values for too long.
Post by Jesper Louis Andersen
If you are picking apart a large binary, and you need to reference
*binary* data in it, then it may be beneficial to break that binary data
<<Payload:Len/binary, "\r\n", Rest/binary>> = Packet,
CPayload = binary:copy(Payload),
...
recurse_on(Rest).
but as Dan says, copying `Rest` in this case is a bad idea. You just copy
the very binary you are running over and processing. Also note that it is
important you are picking out binary data. If you had something like
<<I:32/integer, "\r\n", Rest/binary>>
then the integer conversion already excises the data from the binary, so
you don't have to keep the binary around anymore.
Ok, as per this suggestion I removed copying the Rest.

Thanks,
r.
Jesper Louis Andersen
2015-01-23 14:26:36 UTC
Permalink
Post by Roberto Ostinelli
I'm not storing binaries in a ETS. Also, I don't see anywhere I'm holding
binary values for too long.
It is only a hunch. Clearly, something is using more memory than you
expect, and I assume you have made calculations which shows that this
memory usage is excessive given the number of processes and the specific
profile of the system. Running 20000 SSL sockets will have some overhead
due to SSL, so it is important to figure out if the memory usage is normal
or unexpected in the first place.

Also, check the operating system. If you are out of memory, and being
killed by the OS, then there should be a log line in the kernels log about
it. It is highly suspicious you get killed suddenly with no message at all.
If Erlang terminates, you can arrange that it crash-dumps so you can go
inspect the system afterwards. Alternatively, you can force it to terminate
with a SIGUSR1 signal which will have it crash-dump. Luckily, you are in
development mode, so being mean to the system is an option :)

Other typical OS limitations are resources such as file descriptors. You
need to verify that you are not being killed by the OS and debug from the
bottom-up. Otherwise you will end up making a wrong conclusion somewhere
along the way. Your goal should be to verify that what you *expect* is
*reality*. So seek those conclusions.

Another common thing I do, is to run mem_sup on the machine and then add in
an alert for processes which take up more than 5% of the memory of the
system. If such a process occurs, you go inspect it with process_info and
figure out if it has a rather small backtrace. In that case, you log the
backtrace fully and if it is too long, you log only the topmost parts of
the call chain. All of this is possible by installing a custom
alarm_handler.

It is yet another of those things I like to have in production systems,
because it quickly finds and reports odd processes that are doing nasty
things to the system.
--
J.
Roberto Ostinelli
2015-01-23 16:25:05 UTC
Permalink
Post by Jesper Louis Andersen
It is only a hunch. Clearly, something is using more memory than you
expect, and I assume you have made calculations which shows that this
memory usage is excessive given the number of processes and the specific
profile of the system. Running 20000 SSL sockets will have some overhead
due to SSL, so it is important to figure out if the memory usage is normal
or unexpected in the first place.
The main question here is: why is there such a difference between what the
BEAM uses, and what Erlang VM uses.

In another (bigger) test I am now seeing erlang:memory reporting a total of
10 GB, while the BEAM eats up to 15 GB.
Post by Jesper Louis Andersen
Also, check the operating system. If you are out of memory, and being
killed by the OS, then there should be a log line in the kernels log about
it. It is highly suspicious you get killed suddenly with no message at all.
If Erlang terminates, you can arrange that it crash-dumps so you can go
inspect the system afterwards. Alternatively, you can force it to terminate
with a SIGUSR1 signal which will have it crash-dump. Luckily, you are in
development mode, so being mean to the system is an option :)
Other typical OS limitations are resources such as file descriptors. You
need to verify that you are not being killed by the OS and debug from the
bottom-up. Otherwise you will end up making a wrong conclusion somewhere
along the way. Your goal should be to verify that what you *expect* is
*reality*. So seek those conclusions.
File descriptors are ok. I have 2M available, only using 220k.
Post by Jesper Louis Andersen
Another common thing I do, is to run mem_sup on the machine and then add
in an alert for processes which take up more than 5% of the memory of the
system. If such a process occurs, you go inspect it with process_info and
figure out if it has a rather small backtrace. In that case, you log the
backtrace fully and if it is too long, you log only the topmost parts of
the call chain. All of this is possible by installing a custom
alarm_handler.
Doing this. No process is taking such a huge amount of memory.
Lukas Larsson
2015-01-23 17:03:16 UTC
Permalink
Hello Roberto
Post by Jesper Louis Andersen
It is only a hunch. Clearly, something is using more memory than you
Post by Jesper Louis Andersen
expect, and I assume you have made calculations which shows that this
memory usage is excessive given the number of processes and the specific
profile of the system. Running 20000 SSL sockets will have some overhead
due to SSL, so it is important to figure out if the memory usage is normal
or unexpected in the first place.
The main question here is: why is there such a difference between what the
BEAM uses, and what Erlang VM uses.
In another (bigger) test I am now seeing erlang:memory reporting a total
of 10 GB, while the BEAM eats up to 15 GB.
With a recon_alloc:memory(usage, current) value of 65 - 70%, this
difference is expected. What is happening is that the memory allocators of
the VM is not finding any good slots to put new heaps in, so it keeps
requesting more memory from the OS. erlang:memory reports used memory,
which is not the same as the memory requested from the OS.
recon_alloc:memory(allocated, current) reports something very close to what
has actually been requested from the OS, which is why this value is much
closer to what you see with top.

It would be interesting to see if you get the same results if you start the
VM with "+Muacul 0", or if you get better utlization if you use that. If
you want to know what it is that you are disabling you can read this:
https://github.com/erlang/otp/blob/master/erts/emulator/internal_doc/CarrierMigration.md
.

Lukas
Roberto Ostinelli
2015-01-23 18:07:03 UTC
Permalink
Post by Lukas Larsson
With a recon_alloc:memory(usage, current) value of 65 - 70%, this
difference is expected. What is happening is that the memory allocators of
the VM is not finding any good slots to put new heaps in, so it keeps
requesting more memory from the OS. erlang:memory reports used memory,
which is not the same as the memory requested from the OS.
recon_alloc:memory(allocated, current) reports something very close to what
has actually been requested from the OS, which is why this value is much
closer to what you see with top.
It would be interesting to see if you get the same results if you start
the VM with "+Muacul 0", or if you get better utlization if you use that.
https://github.com/erlang/otp/blob/master/erts/emulator/internal_doc/CarrierMigration.md
.
Lukas
Thank you Lukas I will try this option.

I have an update though, which is interesting. I am using lager as the
logger, and in the logger I was printing out the body of the original
request that I received. Since the requests are short lived (and the
processes die after the logging), I imagined that the data would be freed.
Instead, it looks like for some reason it is not.

I have disabled the logging and the BEAM size usage is much more stable
(even though it periodically goes through the forced GC that I've set up
when thresholds are hit).

I'll keep you posted on the "+Muacul 0" option.

Thanks,
r.
Roberto Ostinelli
2015-01-27 18:48:59 UTC
Permalink
Post by Lukas Larsson
With a recon_alloc:memory(usage, current) value of 65 - 70%, this
difference is expected. What is happening is that the memory allocators of
the VM is not finding any good slots to put new heaps in, so it keeps
requesting more memory from the OS. erlang:memory reports used memory,
which is not the same as the memory requested from the OS.
recon_alloc:memory(allocated, current) reports something very close to what
has actually been requested from the OS, which is why this value is much
closer to what you see with top.
It would be interesting to see if you get the same results if you start
the VM with "+Muacul 0", or if you get better utlization if you use that.
https://github.com/erlang/otp/blob/master/erts/emulator/internal_doc/CarrierMigration.md
.
Lukas
Hi again,
I had the time to try the +Muacul 0 option you suggested. It actually works
pretty well since the RAM usage ratio (erlang / VM) improves considerably.

Unfortunately both with or without the option I am getting the same
problem: the machine seems stable, but at a certain moment *within 30
seconds* the VM memory usage suddenly increases from 11GB to 15GB until it
crashes.

I don't get it because the erlang usage is *very* stable now, I always get
this kind of data:

1> [{K,V / math:pow(1024,3)} || {K,V} <- erlang:memory()].
[{total,8.803221724927425},
{processes,7.404303453862667},
{processes_used,7.404133327305317},
{system,1.3989182710647583},
{atom,0.0015203068032860756},
{atom_used,0.0015129167586565018},
{binary,0.9653719812631607},
{code,0.049161157570779324},
{ets,0.007966354489326477}]

I see consistent total, process and binary usage. Unfortunately the ratio
falls:

2> recon_alloc:memory(usage, current).
0.7353255106318904

..after a while:

3> recon_alloc:memory(usage, current).
0.5630988225908702

Why is the VM so eager on memory if the underlying erlang usage is stable?

Is there anything I can do? I honestly don't know where else to look.

- Binaries are optimized (checked with +bin_opt_info).
- Erlang reported memory for total, process and binary is linear.
- I'm using some gimmicks like fullsweep_after 10 as a system flag.
- I hibernate the long living TCP connections (which is where the
problem comes from, since I ran tests on short lived connections and had no
issues).

Any help would be greatly appreciated.

Best,
r.
Fred Hebert
2015-01-27 19:09:44 UTC
Permalink
Post by Roberto Ostinelli
I see consistent total, process and binary usage. Unfortunately the ratio
2> recon_alloc:memory(usage, current).
0.7353255106318904
3> recon_alloc:memory(usage, current).
0.5630988225908702
Yeah that does look like some good indication there's an allocator
'leak' (or bad usage). You can possibly look at other recon functions to
try and figure things are wrong in specific ways (a given allocator is
worse than others -- if it's allocator 0, that's for NIFs and drivers --
or other ones)
Post by Roberto Ostinelli
Why is the VM so eager on memory if the underlying erlang usage is stable?
Is there anything I can do? I honestly don't know where else to look.
- Binaries are optimized (checked with +bin_opt_info).
- Erlang reported memory for total, process and binary is linear.
- I'm using some gimmicks like fullsweep_after 10 as a system flag.
- I hibernate the long living TCP connections (which is where the
problem comes from, since I ran tests on short lived connections and had no
issues).
Any help would be greatly appreciated.
What this looks like from the usage metrics is possibly the need for
different memory allocation strategy. There'S unfortunately no super
easy way to do it, but if the problem shows up quickly, that at least
makes it a lot easier to experiment.

I have covered the topic in Section 7.3 of Erlang in Anger
(http://erlang-in-anger.com), Memory Fragmentation.

The steps are usually:

1. Find that you have fragmentation issues (done)
2. Find which allocator is to blame
3. Take note of what your usage pattern is for that allocator. Is data
held for a long time? Only some of it? Does it get released in large
blocks? What's the variation in datasize type? Max, min, p95 or p99
size?
4. Check the different strategies available (p.71-73) and see if one
could make sense for your usage.
5. Check your average block size (in recon_alloc) and see if you need to
tweak yours up or down so more or less data gets to be used in the
same operation (and may hold them back if they need to be released)
6. Experiment a lot and report back.

If you tend to see lots of holes, doing things like reducing block sizes
(while making sure your sbcs/mbcs ratio remains low enough) and looking
for some address-order strategy (rather than best fit) might end up
helping by reusing already-allocated blocks more, and also reducing how
much spread there is.

Anyway, that's more or less the extent of the experimenting I've done
that can be applied in a generic manner.
Roberto Ostinelli
2015-01-28 11:47:56 UTC
Permalink
Hi Fred,
Thank you for this.

I was collecting allocator and other data to go down this route. Then I
plotted all of this in a graph, and I'm actually seeing that the problem
does not seem to be fragmentation at all.

This is what I see:

erlang memory and recon allocated:
Loading Image...

allocator memory:
Loading Image...

recon usage:
Loading Image...

I've got my system under controlled load, so the incoming requests are all
the same at any given time.
I'm using the +Muacul 0 option Lukas suggested, so that's why the recon
usage never goes down to the 50% that I experienced before.

As you can see, it looks that my problem comes from eheap memory, allocated
for processes. Binary usage is now definitely stable.

The last allocator info that I've got before the VM blew up where:


*recon_alloc:fragmentation(current)*

[{{eheap_alloc,1},
[{sbcs_usage,0.9998089938211238},
{mbcs_usage,0.8436328764998643},
{sbcs_block_size,11515752},
{sbcs_carriers_size,11517952},
{mbcs_block_size,1398905280},
{mbcs_carriers_size,1658191992}]},
{{eheap_alloc,6},
[{sbcs_usage,0.6174983671623794},
{mbcs_usage,0.8458609176542206},
{sbcs_block_size,3146416},
{sbcs_carriers_size,5095424},
{mbcs_block_size,1402599800},
{mbcs_carriers_size,1658191992}]},
{{eheap_alloc,7},
[{sbcs_usage,0.9996959805427548},
{mbcs_usage,0.8455184225713416},
{sbcs_block_size,7997056},
{sbcs_carriers_size,7999488},
{mbcs_block_size,1409124600},
{mbcs_carriers_size,1666580600}]},
{{eheap_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.8449706854053697},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1401788136},
{mbcs_carriers_size,1658978424}]},
{{eheap_alloc,3},
[{sbcs_usage,0.997382155987395},
{mbcs_usage,0.8450586945061064},
{sbcs_block_size,972296},
{sbcs_carriers_size,974848},
{mbcs_block_size,1401269560},
{mbcs_carriers_size,1658191992}]},
{{eheap_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.8460061373569331},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1409937416},
{mbcs_carriers_size,1666580600}]},
{{eheap_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.8445225737274885},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1393296200},
{mbcs_carriers_size,1649803384}]},
{{eheap_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.8437420231923147},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1384930624},
{mbcs_carriers_size,1641414776}]},
{{binary_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.6716575320561889},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,99502200},
{mbcs_carriers_size,148144248}]},
{{binary_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.6781073538541975},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,100457704},
{mbcs_carriers_size,148144248}]},
{{binary_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.6796450983368588},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,100685512},
{mbcs_carriers_size,148144248}]},
{{binary_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.6840474562333329},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,101337696},
{mbcs_carriers_size,148144248}]},
{{binary_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.7055153695407212},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,98599752},
{mbcs_carriers_size,139755640}]},
{{binary_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7102128257578728},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,99256248},
{mbcs_carriers_size,139755640}]},
{{binary_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.7147085012096829},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,99884544},
{mbcs_carriers_size,139755640}]},
{{binary_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.7225102042050122},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,102300688},
{mbcs_carriers_size,141590648}]},
{{ll_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.8925413646389566},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,211512896},
{mbcs_carriers_size,236978256}]},
{{driver_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.8187761906238381},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25139488},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.8188191821347083},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25140808},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.8218319751055703},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25233312},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.8219393236054401},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25236608},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.8316551445074958},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25534920},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.8330978353904555},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25579216},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.8339579261624709},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25605624},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.844592202069481},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25932136},
{mbcs_carriers_size,30703736}]},
{{fix_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.9433490069813972},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,68531264},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.9573151050777532},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,69545856},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.9603094292856162},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,69763384},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.9669017658815307},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70242296},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.9680059580345314},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70322512},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.9682964595703463},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70343616},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.9716501114929037},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70587248},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.9716850201308314},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70589784},
{mbcs_carriers_size,72646776}]},
{{std_alloc,7},
[{sbcs_usage,0.8571690150669643},
{mbcs_usage,0.7343726386030993},
{sbcs_block_size,1572912},
{sbcs_carriers_size,1835008},
{mbcs_block_size,2526800},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.669268417442658},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2302792},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.6742580127646217},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2319960},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.6778409421174392},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2332288},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.6785849637870703},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2334848},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.6792173822062567},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2337024},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.679821899812832},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2339104},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.6809565328590195},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2343008},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.6915890675315919},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2379592},
{mbcs_carriers_size,3440760}]},
{{std_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.7155860914449134},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2462160},
{mbcs_carriers_size,3440760}]},
{{std_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7317499622176495},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2517776},
{mbcs_carriers_size,3440760}]},
{{std_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.7326009370022902},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2520704},
{mbcs_carriers_size,3440760}]},
{{std_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.7368139597065765},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2535200},
{mbcs_carriers_size,3440760}]},
{{std_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.7383717550773666},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2540560},
{mbcs_carriers_size,3440760}]},
{{std_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.7468582522465966},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2569760},
{mbcs_carriers_size,3440760}]},
{{std_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.7473279159255514},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2571376},
{mbcs_carriers_size,3440760}]},
{{ets_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.643050651678168},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,864008},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.6700704372108531},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,900312},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.6724282677685753},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,903480},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.6745300712707873},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,906304},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.6789420723901615},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,912232},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.6872540205178892},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,923400},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.7930825062071676},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1065592},
{mbcs_carriers_size,1343608}]},
{{eheap_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.33664856509447394},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,132416},
{mbcs_carriers_size,393336}]},
{{ets_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.8979523789676751},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1206496},
{mbcs_carriers_size,1343608}]},
{{temp_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{temp_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{temp_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{temp_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{temp_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{temp_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{temp_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{temp_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{temp_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,131192}]},
{{std_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.8726646601046666},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,257464},
{mbcs_carriers_size,295032}]},
{{sl_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.0},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,0},
{mbcs_carriers_size,32888}]},
{{fix_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.02456823157382632},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,808},
{mbcs_carriers_size,32888}]},
{{driver_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.039649720262709805},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1304},
{mbcs_carriers_size,32888}]},
{{binary_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.41303819022135735},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,13584},
{mbcs_carriers_size,32888}]},
{{ets_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.4582826562880078},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,15072},
{mbcs_carriers_size,32888}]}]


and *recon_alloc:fragmentation(max)*

[{{eheap_alloc,1},
[{sbcs_usage,0.9995836942360554},
{mbcs_usage,0.8438346046481209},
{sbcs_block_size,35747288},
{sbcs_carriers_size,35762176},
{mbcs_block_size,1399239784},
{mbcs_carriers_size,1658191992}]},
{{eheap_alloc,5},
[{sbcs_usage,0.947959190616155},
{mbcs_usage,0.8462006049992422},
{sbcs_block_size,17833888},
{sbcs_carriers_size,18812928},
{mbcs_block_size,1410261512},
{mbcs_carriers_size,1666580600}]},
{{eheap_alloc,2},
[{sbcs_usage,0.9996057750948681},
{mbcs_usage,0.8451859214776624},
{sbcs_block_size,22658328},
{sbcs_carriers_size,22667264},
{mbcs_block_size,1402145208},
{mbcs_carriers_size,1658978424}]},
{{eheap_alloc,7},
[{sbcs_usage,0.9994766588528468},
{mbcs_usage,0.8459256516006487},
{sbcs_block_size,24231536},
{sbcs_carriers_size,24244224},
{mbcs_block_size,1409803280},
{mbcs_carriers_size,1666580600}]},
{{eheap_alloc,3},
[{sbcs_usage,0.9996129234481453},
{mbcs_usage,0.8454477688733163},
{sbcs_block_size,27043608},
{sbcs_carriers_size,27054080},
{mbcs_block_size,1401914720},
{mbcs_carriers_size,1658191992}]},
{{eheap_alloc,8},
[{sbcs_usage,0.9996057750948681},
{mbcs_usage,0.8446861617056788},
{sbcs_block_size,22658328},
{sbcs_carriers_size,22667264},
{mbcs_block_size,1393566088},
{mbcs_carriers_size,1649803384}]},
{{eheap_alloc,4},
[{sbcs_usage,0.9996057750948681},
{mbcs_usage,0.8443270209723029},
{sbcs_block_size,22658328},
{sbcs_carriers_size,22667264},
{mbcs_block_size,1385890848},
{mbcs_carriers_size,1641414776}]},
{{eheap_alloc,6},
[{sbcs_usage,0.999511325925181},
{mbcs_usage,0.8462386302490357},
{sbcs_block_size,25444200},
{sbcs_carriers_size,25456640},
{mbcs_block_size,1403226120},
{mbcs_carriers_size,1658191992}]},
{{ll_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.9004818737462563},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,213394624},
{mbcs_carriers_size,236978256}]},
{{binary_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.8944150703711425},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,132502448},
{mbcs_carriers_size,148144248}]},
{{binary_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.8954607538998072},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,132657360},
{mbcs_carriers_size,148144248}]},
{{binary_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.8966842101085153},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,132838608},
{mbcs_carriers_size,148144248}]},
{{binary_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.8991528310974315},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,133204320},
{mbcs_carriers_size,148144248}]},
{{binary_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.9407874487212108},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,131480352},
{mbcs_carriers_size,139755640}]},
{{binary_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.9438688842897504},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,131911000},
{mbcs_carriers_size,139755640}]},
{{binary_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.9512322593509142},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,134685592},
{mbcs_carriers_size,141590648}]},
{{binary_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.9556126965609403},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,133552264},
{mbcs_carriers_size,139755640}]},
{{driver_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.8197313838289907},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25168816},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.8225703868740925},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25255984},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.825497196823214},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25345848},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.8260857896902188},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25363920},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.8351752373066261},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25643000},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.8361403315870095},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25672632},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.8387523915656387},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25752832},
{mbcs_carriers_size,30703736}]},
{{driver_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.8461701207957234},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25980584},
{mbcs_carriers_size,30703736}]},
{{fix_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.9439967439160686},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,68578320},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.9576758643769684},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,69572064},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.9603094292856162},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,69763384},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.9676070965626885},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70293536},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.9680071693752796},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70322600},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.9685851991559818},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70364592},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.9718468993035562},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70601544},
{mbcs_carriers_size,72646776}]},
{{fix_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.9719647297217979},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,70610104},
{mbcs_carriers_size,72646776}]},
{{std_alloc,4},
[{sbcs_usage,0.7500457763671875},
{mbcs_usage,0.7213592345877073},
{sbcs_block_size,786480},
{sbcs_carriers_size,1048576},
{mbcs_block_size,2482024},
{mbcs_carriers_size,3440760}]},
{{std_alloc,7},
[{sbcs_usage,0.8571690150669643},
{mbcs_usage,0.7376068077982771},
{sbcs_block_size,1572912},
{sbcs_carriers_size,1835008},
{mbcs_block_size,2537928},
{mbcs_carriers_size,3440760}]},
{{std_alloc,3},
[{sbcs_usage,0.80003662109375},
{mbcs_usage,0.7450307490205652},
{sbcs_block_size,1048624},
{sbcs_carriers_size,1310720},
{mbcs_block_size,2563472},
{mbcs_carriers_size,3440760}]},
{{std_alloc,5},
[{sbcs_usage,0.8333638509114584},
{mbcs_usage,0.7537404526906846},
{sbcs_block_size,1310768},
{sbcs_carriers_size,1572864},
{mbcs_block_size,2593440},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.6812471663237192},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2344008},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.6843627570652995},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2354728},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.6919796789081482},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2380936},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.7003545728269336},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2409752},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.7007591346097956},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2411144},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.7018333158953255},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2414840},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.7091782048152152},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2440112},
{mbcs_carriers_size,3440760}]},
{{std_alloc,6},
[{sbcs_usage,0.90003662109375},
{mbcs_usage,0.7518385472976901},
{sbcs_block_size,1179696},
{sbcs_carriers_size,1310720},
{mbcs_block_size,2586896},
{mbcs_carriers_size,3440760}]},
{{std_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.7386042618491263},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2541360},
{mbcs_carriers_size,3440760}]},
{{sl_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7387228403027238},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2541768},
{mbcs_carriers_size,3440760}]},
{{std_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7394575617014846},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,2544296},
{mbcs_carriers_size,3440760}]},
{{std_alloc,2},
[{sbcs_usage,0.9938373447204969},
{mbcs_usage,0.7439193666515538},
{sbcs_block_size,655392},
{sbcs_carriers_size,659456},
{mbcs_block_size,2559648},
{mbcs_carriers_size,3440760}]},
{{temp_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.2534939072766849},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,299064},
{mbcs_carriers_size,1179768}]},
{{binary_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.39198933022131455},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,526680},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.6432173669701282},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,864232},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.6702371525028133},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,900536},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.6746967865627475},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,906528},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.6770010300623396},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,909624},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.6791087876821216},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,912456},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.6874207358098493},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,923624},
{mbcs_carriers_size,1343608}]},
{{ets_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.7939398991372484},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1066744},
{mbcs_carriers_size,1343608}]},
{{eheap_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.3466756157585372},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,136360},
{mbcs_carriers_size,393336}]},
{{sl_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.1492448276797093},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,44032},
{mbcs_carriers_size,295032}]},
{{driver_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.4211610943897611},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,124256},
{mbcs_carriers_size,295032}]},
{{ets_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.8981190942596352},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,1206720},
{mbcs_carriers_size,1343608}]},
{{temp_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.07579730471370205},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,9944},
{mbcs_carriers_size,131192}]},
{{temp_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.11823891700713458},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,15512},
{mbcs_carriers_size,131192}]},
{{temp_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.11823891700713458},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,15512},
{mbcs_carriers_size,131192}]},
{{temp_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.11823891700713458},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,15512},
{mbcs_carriers_size,131192}]},
{{temp_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.11823891700713458},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,15512},
{mbcs_carriers_size,131192}]},
{{temp_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.11823891700713458},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,15512},
{mbcs_carriers_size,131192}]},
{{temp_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.12494664308799316},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,16392},
{mbcs_carriers_size,131192}]},
{{temp_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.2140984206354046},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,28088},
{mbcs_carriers_size,131192}]},
{{fix_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.02627098029676478},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,864},
{mbcs_carriers_size,32888}]},
{{std_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.90007863553784},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,265552},
{mbcs_carriers_size,295032}]},
{{ets_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.4582826562880078},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,15072},
{mbcs_carriers_size,32888}]}]


Both of these look fine to me, unless I've missed a spot.

What I do not understand is why, in a system under stable load, suddenly
the eheap blows up like that, eventually crashing the system (this box only
has 15GB of RAM).

Any suggestions on the steps I could make to debug this?

Best,
r.
Post by Fred Hebert
Post by Roberto Ostinelli
I see consistent total, process and binary usage. Unfortunately the ratio
2> recon_alloc:memory(usage, current).
0.7353255106318904
3> recon_alloc:memory(usage, current).
0.5630988225908702
Yeah that does look like some good indication there's an allocator
'leak' (or bad usage). You can possibly look at other recon functions to
try and figure things are wrong in specific ways (a given allocator is
worse than others -- if it's allocator 0, that's for NIFs and drivers --
or other ones)
Post by Roberto Ostinelli
Why is the VM so eager on memory if the underlying erlang usage is
stable?
Post by Roberto Ostinelli
Is there anything I can do? I honestly don't know where else to look.
- Binaries are optimized (checked with +bin_opt_info).
- Erlang reported memory for total, process and binary is linear.
- I'm using some gimmicks like fullsweep_after 10 as a system flag.
- I hibernate the long living TCP connections (which is where the
problem comes from, since I ran tests on short lived connections and
had no
Post by Roberto Ostinelli
issues).
Any help would be greatly appreciated.
What this looks like from the usage metrics is possibly the need for
different memory allocation strategy. There'S unfortunately no super
easy way to do it, but if the problem shows up quickly, that at least
makes it a lot easier to experiment.
I have covered the topic in Section 7.3 of Erlang in Anger
(http://erlang-in-anger.com), Memory Fragmentation.
1. Find that you have fragmentation issues (done)
2. Find which allocator is to blame
3. Take note of what your usage pattern is for that allocator. Is data
held for a long time? Only some of it? Does it get released in large
blocks? What's the variation in datasize type? Max, min, p95 or p99
size?
4. Check the different strategies available (p.71-73) and see if one
could make sense for your usage.
5. Check your average block size (in recon_alloc) and see if you need to
tweak yours up or down so more or less data gets to be used in the
same operation (and may hold them back if they need to be released)
6. Experiment a lot and report back.
If you tend to see lots of holes, doing things like reducing block sizes
(while making sure your sbcs/mbcs ratio remains low enough) and looking
for some address-order strategy (rather than best fit) might end up
helping by reusing already-allocated blocks more, and also reducing how
much spread there is.
Anyway, that's more or less the extent of the experimenting I've done
that can be applied in a generic manner.
Lukas Larsson
2015-01-28 12:35:53 UTC
Permalink
Hello,

On Wed, Jan 28, 2015 at 12:47 PM, Roberto Ostinelli <***@widetag.com>
wrote:

What I do not understand is why, in a system under stable load, suddenly
Post by Roberto Ostinelli
the eheap blows up like that, eventually crashing the system (this box only
has 15GB of RAM).
Could it be that you at this point trigger a lot of garbage collections due
to calling erlang:garbage_collect/1? If you do that on a lot of processes
at the same time you might get an explosion in eheap memory usage.
Post by Roberto Ostinelli
Any suggestions on the steps I could make to debug this?
If you cannot get a crash dump, I would look for changes in
erlang:statistics/1 counters, to see if that can indicate if something in
the system is changing drastically at that point, i.e. the number of
reductions executed, the number of gc's done etc etc.

Lukas
Roberto Ostinelli
2015-01-28 13:42:57 UTC
Permalink
Post by Lukas Larsson
Could it be that you at this point trigger a lot of garbage collections
due to calling erlang:garbage_collect/1? If you do that on a lot of
processes at the same time you might get an explosion in eheap memory usage.
I constantly hibernate long term processes, all along the run. Nothing
specific happens after a while.
Post by Lukas Larsson
If you cannot get a crash dump, I would look for changes in
erlang:statistics/1 counters, to see if that can indicate if something in
the system is changing drastically at that point, i.e. the number of
reductions executed, the number of gc's done etc etc.
The number of reductions stay constant:
Loading Image...

So does the number of GC:
Loading Image...

The process count is always the same:
Loading Image...

And the maximum message box length of any process in the system is always
between 1-3 (despite the peak at the start):
Loading Image...

...Any other ideas? I'm getting appalled.

Best,
r.
Anton Lebedevich
2015-01-28 14:08:07 UTC
Permalink
Post by Roberto Ostinelli
https://cldup.com/SiwAVf1VT5-3000x3000.png
https://cldup.com/9Q5ac7Q5eK-3000x3000.png
https://cldup.com/tsuorbj06u-3000x3000.png
And the maximum message box length of any process in the system is always
https://cldup.com/x4KYsykOrH-3000x3000.png
...Any other ideas? I'm getting appalled.
Time scale is different so it's not possible to correlate process
memory with number of reductions or number of GCs.

It seems that some process (or processes) starts allocating memory
much faster than before and linux OOM kills the beam when it runs out
of memory on the box. You can try setting a watchdog process
(something like "while true; check memory usage and kill -USR1
beam.smp when it's close to the limit; sleep 1") to get crash dump
before OOM kills beam.smp

Is there anything unusual in logs at the momeng when memory usage is
jumping? Maybe something gets printed to stdout.

Regards,
Anton.
Roberto Ostinelli
2015-01-28 14:15:59 UTC
Permalink
Post by Anton Lebedevich
Time scale is different so it's not possible to correlate process
memory with number of reductions or number of GCs.
Time scale is different from previous test, but the graph is the same.
Things get ugly at 140.
Post by Anton Lebedevich
It seems that some process (or processes) starts allocating memory
much faster than before and linux OOM kills the beam when it runs out
of memory on the box.
How can you see that?
Post by Anton Lebedevich
You can try setting a watchdog process
(something like "while true; check memory usage and kill -USR1
beam.smp when it's close to the limit; sleep 1") to get crash dump
before OOM kills beam.smp
I did that, I'm currently waiting for the crash dump to finish (it is 2.9GB
right now, and still piling up).
Post by Anton Lebedevich
Is there anything unusual in logs at the momeng when memory usage is
jumping? Maybe something gets printed to stdout.
Nothing unfortunately.

Thank you for your help,
r.
Roberto Ostinelli
2015-01-28 14:45:46 UTC
Permalink
Here's the erl_crash.dump analysis, done with the nice Fred's script:

analyzing erl_crash.dump, generated on: Wed Jan 28 13:59:36 2015

Slogan: Received SIGUSR1

Memory:
===
processes: 8870 Mb
processes_used: 8869 Mb
system: 1138 Mb
atom: 0 Mb
atom_used: 0 Mb
binary: 750 Mb
code: 9 Mb
ets: 7 Mb
---
total: 10008 Mb

Different message queue lengths (5 largest different):
===
540314 0

Error logger queue length:
===

File descriptors open:
===
UDP: 0
TCP: 180071
Files: 6
---
Total: 180077

Number of processes:
===
540314

Processes Heap+Stack memory sizes (words) used in the VM (5 largest
different):
===
2 196650
1 28690
1 17731
1 10958
4677 6772

Processes OldHeap memory sizes (words) used in the VM (5 largest different):
===
1 1439468
1 999631
1 75113
1 28690
1 17731

Process States when crashing (sum):
===
540314 Waiting


Do you see anything wrong there? I honestly don't.

Best,
r.
Post by Roberto Ostinelli
Post by Anton Lebedevich
Time scale is different so it's not possible to correlate process
memory with number of reductions or number of GCs.
Time scale is different from previous test, but the graph is the same.
Things get ugly at 140.
Post by Anton Lebedevich
It seems that some process (or processes) starts allocating memory
much faster than before and linux OOM kills the beam when it runs out
of memory on the box.
How can you see that?
Post by Anton Lebedevich
You can try setting a watchdog process
(something like "while true; check memory usage and kill -USR1
beam.smp when it's close to the limit; sleep 1") to get crash dump
before OOM kills beam.smp
I did that, I'm currently waiting for the crash dump to finish (it is
2.9GB right now, and still piling up).
Post by Anton Lebedevich
Is there anything unusual in logs at the momeng when memory usage is
jumping? Maybe something gets printed to stdout.
Nothing unfortunately.
Thank you for your help,
r.
Fred Hebert
2015-01-28 16:19:37 UTC
Permalink
This post might be inappropriate. Click to display it.
Roberto Ostinelli
2015-01-28 16:34:15 UTC
Permalink
Post by Fred Hebert
Post by Roberto Ostinelli
analyzing erl_crash.dump, generated on: Wed Jan 28 13:59:36 2015
Slogan: Received SIGUSR1
===
UDP: 0
TCP: 180071
Files: 6
---
Total: 180077
So uh, is 180,000 TCP ports the number you have or expect? Could you be
running out of these and then massive erroring takes place or anything
like that? What are the limits in place for your system?
That's exactly the number of long lived connections to the system, so yes
it's expected.
ulimit (hard and soft) are set to 1M.
Post by Fred Hebert
Do you see anything wrong there? I honestly don't.
Nothing looks obviously wrong. At this point my number one suspsicion
would be some process(es) that suddenly get lots of messages (links,
monitors, node monitors, general events) and fill their mailboxes. This
then prompts for GCs, which suspends the process, copies the mailbox to
the heap, and then runs again.
This kind of stuff can sometimes spiral out of control.
So, here's the thing. I got a bigger box, a 30GB. I'm launching the same
test, and What I have is the following:
Loading Image...

Basically what happens is that the memory "ramp-up" happens in two phases.
The second phase was the one previously making my VM blowup.
With this bigger box, this phase continues but then stabilizes.

Not sure why this happens in this way, but with a bigger box, as you can
see, when 22.3 GB of memory are reached, everything is stable.
This was confusing, but it simply looks like there's some time needed
before the memory gets allocated. I'm assuming this has to do with
fullsweep_after. With it set to 10, we get to the 22.3GB illustrated; with
it set to 5, we get to 19.3GB (3GB less).

I guess this is it for now. I can only thank you for your time.

Any additional remarks?

Best,
r.
Michael Truog
2015-01-28 18:37:49 UTC
Permalink
Post by Fred Hebert
Post by Roberto Ostinelli
analyzing erl_crash.dump, generated on: Wed Jan 28 13:59:36 2015
Slogan: Received SIGUSR1
===
UDP: 0
TCP: 180071
Files: 6
---
Total: 180077
So uh, is 180,000 TCP ports the number you have or expect? Could you be
running out of these and then massive erroring takes place or anything
like that? What are the limits in place for your system?
That's exactly the number of long lived connections to the system, so yes it's expected.
ulimit (hard and soft) are set to 1M.
Post by Roberto Ostinelli
Do you see anything wrong there? I honestly don't.
Nothing looks obviously wrong. At this point my number one suspsicion
would be some process(es) that suddenly get lots of messages (links,
monitors, node monitors, general events) and fill their mailboxes. This
then prompts for GCs, which suspends the process, copies the mailbox to
the heap, and then runs again.
This kind of stuff can sometimes spiral out of control.
https://cldup.com/1M4qzvbLp_-3000x3000.png
Basically what happens is that the memory "ramp-up" happens in two phases. The second phase was the one previously making my VM blowup.
With this bigger box, this phase continues but then stabilizes.
Not sure why this happens in this way, but with a bigger box, as you can see, when 22.3 GB of memory are reached, everything is stable.
This was confusing, but it simply looks like there's some time needed before the memory gets allocated. I'm assuming this has to do with fullsweep_after. With it set to 10, we get to the 22.3GB illustrated; with it set to 5, we get to 19.3GB (3GB less).
I guess this is it for now. I can only thank you for your time.
Any additional remarks?
Best,
r.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
As I mentioned previously, your long-lived processes are generating too much garbage with your current architecture to be able to scale as high as you are attempting. You should be able to see the problem with less load and usage of http://www.erlang.org/doc/man/instrument.html which would then lead to source code changes that split monolithic Erlang processes that generate too much garbage (long-lived) into smaller ones that are able to trigger garbage collection faster (short-lived). The Erlang process message queues are a secondary concern due to the possibility of overloading bottleneck processes, but that problem can be discovered and solved with this approach.
Anton Lebedevich
2015-01-28 19:02:14 UTC
Permalink
Post by Roberto Ostinelli
So, here's the thing. I got a bigger box, a 30GB. I'm launching the same
https://cldup.com/1M4qzvbLp_-3000x3000.png
Basically what happens is that the memory "ramp-up" happens in two phases.
The second phase was the one previously making my VM blowup.
With this bigger box, this phase continues but then stabilizes.
Not sure why this happens in this way, but with a bigger box, as you can
see, when 22.3 GB of memory are reached, everything is stable.
This was confusing, but it simply looks like there's some time needed before
the memory gets allocated. I'm assuming this has to do with fullsweep_after.
With it set to 10, we get to the 22.3GB illustrated; with it set to 5, we
get to 19.3GB (3GB less).
I guess this is it for now. I can only thank you for your time.
Any additional remarks?
The graph looks really weird for me assuming that the load applied to
the system is stable. Why does it go down for a short time and then
jumps higher than it was?
Usually memory graphs increase up to some level and then remain stable
under controlled constant load.
I've tried to multiply 120000 (number of processes) by 142896 (memory
usage of connection handling process) and got 16Gb. So it looks like
not all connection handling processes reach size of 142896 after
applying load.
In this situation I'd:
1) double check that all processes get the same load over time
2) compare process size histograms and allocator stats/fragmentation
before/after drop down and before/after jump up

Regards,
Anton.
Roberto Ostinelli
2015-01-28 19:09:45 UTC
Permalink
That's a valid point, and I can clarify.

During the first phase, all the long lived connections are made. During the second phase, newly-created short lived connections send messages to the long lived ones.

The long lived connection are all connected when the first memory increase phase ends, which is when the short-lived connections start sending messages.

What is unclear to me is why the second memory increase phase happens quite some time after these short lived processes have started sending messages.
Post by Anton Lebedevich
The graph looks really weird for me assuming that the load applied to
the system is stable. Why does it go down for a short time and then
jumps higher than it was?
Roberto Ostinelli
2015-02-20 14:11:20 UTC
Permalink
Dear List,
Given the amount of answers I got in this post, I want to follow up and
give some additional information.

After struggling for quite a while, I just did a comparison between using
SSL connections vs standard TCP connections.
The results are quite impressive.

This is the diagram of memory evolution for a system under load, with SSL:
Loading Image...

This is the same system, but without SSL:
Loading Image...

You can clearly see that using standard TCP connections the system is
extremely stable.
Using SSL connections, on the other hand, results in RAM memory having very
erratic behavior that ends up blowing up the node.

Not sure what to do with this information, except that I'm going to use a
SSL termination (HAProxy or ELB) and have my Erlang node run without SSL.

If anyone is curious just ping me.

Best,
r.





On Wed, Jan 28, 2015 at 8:09 PM, Roberto Ostinelli <
Post by Roberto Ostinelli
That's a valid point, and I can clarify.
During the first phase, all the long lived connections are made. During
the second phase, newly-created short lived connections send messages to
the long lived ones.
The long lived connection are all connected when the first memory increase
phase ends, which is when the short-lived connections start sending
messages.
What is unclear to me is why the second memory increase phase happens
quite some time after these short lived processes have started sending
messages.
Post by Anton Lebedevich
The graph looks really weird for me assuming that the load applied to
the system is stable. Why does it go down for a short time and then
jumps higher than it was?
Garrett Smith
2015-02-20 17:11:10 UTC
Permalink
Post by Roberto Ostinelli
Dear List,
Given the amount of answers I got in this post, I want to follow up and give
some additional information.
After struggling for quite a while, I just did a comparison between using
SSL connections vs standard TCP connections.
The results are quite impressive.
https://cldup.com/cNOc8hS004-2000x2000.png
https://cldup.com/sx3RrdMR8o-3000x3000.png
You can clearly see that using standard TCP connections the system is
extremely stable.
Using SSL connections, on the other hand, results in RAM memory having very
erratic behavior that ends up blowing up the node.
Not sure what to do with this information, except that I'm going to use a
SSL termination (HAProxy or ELB) and have my Erlang node run without SSL.
This is my standard practice now - motivated by a number of production
issues. Fronting Erlang with an SSL proxy is completely trivial and
makes the pain go away. I guess it'd be nice if Erlang kept up with
the Nginxes and HAProxies, but not a must have.
Michael Martin
2015-02-20 17:48:24 UTC
Permalink
I came to the same conclusions. HAProxy is my friend.
Post by Garrett Smith
Post by Roberto Ostinelli
Dear List,
Given the amount of answers I got in this post, I want to follow up and
give
Post by Roberto Ostinelli
some additional information.
After struggling for quite a while, I just did a comparison between using
SSL connections vs standard TCP connections.
The results are quite impressive.
This is the diagram of memory evolution for a system under load, with
https://cldup.com/cNOc8hS004-2000x2000.png
https://cldup.com/sx3RrdMR8o-3000x3000.png
You can clearly see that using standard TCP connections the system is
extremely stable.
Using SSL connections, on the other hand, results in RAM memory having
very
Post by Roberto Ostinelli
erratic behavior that ends up blowing up the node.
Not sure what to do with this information, except that I'm going to use a
SSL termination (HAProxy or ELB) and have my Erlang node run without SSL.
This is my standard practice now - motivated by a number of production
issues. Fronting Erlang with an SSL proxy is completely trivial and
makes the pain go away. I guess it'd be nice if Erlang kept up with
the Nginxes and HAProxies, but not a must have.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Jesper Louis Andersen
2015-02-21 14:19:14 UTC
Permalink
Post by Garrett Smith
This is my standard practice now - motivated by a number of production
issues. Fronting Erlang with an SSL proxy is completely trivial and
makes the pain go away. I guess it'd be nice if Erlang kept up with
the Nginxes and HAProxies, but not a must have.
Another tool, which WhatsApp aimed on was stud:

https://github.com/bumptech/stud

though the 200k buffer space per connection sound awfully large for a large
installation with lots of connections going on.
--
J.
Roberto Ostinelli
2015-02-26 11:54:58 UTC
Permalink
Post by Jesper Louis Andersen
https://github.com/bumptech/stud
though the 200k buffer space per connection sound awfully large for a
large installation with lots of connections going on.
And that's exactly why I haven't considered stud in the first place. I have
200k connections on a box, so that would be.. 38GB?
Roberto Ostinelli
2015-02-20 19:19:49 UTC
Permalink
As an addendum: I apologise because this cannot be clearly seen in the
charts (I forgot to "humanise" the axis), but we're talking about a steady
RAM usage of 4.5GB without SSL, in comparison to blowing up a node with
30GB with SSL.

Best,
r.
Post by Roberto Ostinelli
Dear List,
Given the amount of answers I got in this post, I want to follow up and
give some additional information.
After struggling for quite a while, I just did a comparison between using
SSL connections vs standard TCP connections.
The results are quite impressive.
https://cldup.com/cNOc8hS004-2000x2000.png
https://cldup.com/sx3RrdMR8o-3000x3000.png
You can clearly see that using standard TCP connections the system is
extremely stable.
Using SSL connections, on the other hand, results in RAM memory having
very erratic behavior that ends up blowing up the node.
Not sure what to do with this information, except that I'm going to use a
SSL termination (HAProxy or ELB) and have my Erlang node run without SSL.
If anyone is curious just ping me.
Best,
r.
On Wed, Jan 28, 2015 at 8:09 PM, Roberto Ostinelli <
Post by Roberto Ostinelli
That's a valid point, and I can clarify.
During the first phase, all the long lived connections are made. During
the second phase, newly-created short lived connections send messages to
the long lived ones.
The long lived connection are all connected when the first memory
increase phase ends, which is when the short-lived connections start
sending messages.
What is unclear to me is why the second memory increase phase happens
quite some time after these short lived processes have started sending
messages.
Post by Anton Lebedevich
The graph looks really weird for me assuming that the load applied to
the system is stable. Why does it go down for a short time and then
jumps higher than it was?
Ingela Andin
2015-02-24 09:59:00 UTC
Permalink
Hi!

Did you try observing your system with the observer application? You should
be able to get much better information of what Erlang processes consume a
lot of memory and
why.


Regards Ingela Erlang/OTP Team - Ericsson AB
Post by Roberto Ostinelli
As an addendum: I apologise because this cannot be clearly seen in the
charts (I forgot to "humanise" the axis), but we're talking about a steady
RAM usage of 4.5GB without SSL, in comparison to blowing up a node with
30GB with SSL.
Best,
r.
Post by Roberto Ostinelli
Dear List,
Given the amount of answers I got in this post, I want to follow up and
give some additional information.
After struggling for quite a while, I just did a comparison between using
SSL connections vs standard TCP connections.
The results are quite impressive.
https://cldup.com/cNOc8hS004-2000x2000.png
https://cldup.com/sx3RrdMR8o-3000x3000.png
You can clearly see that using standard TCP connections the system is
extremely stable.
Using SSL connections, on the other hand, results in RAM memory having
very erratic behavior that ends up blowing up the node.
Not sure what to do with this information, except that I'm going to use a
SSL termination (HAProxy or ELB) and have my Erlang node run without SSL.
If anyone is curious just ping me.
Best,
r.
On Wed, Jan 28, 2015 at 8:09 PM, Roberto Ostinelli <
Post by Roberto Ostinelli
That's a valid point, and I can clarify.
During the first phase, all the long lived connections are made. During
the second phase, newly-created short lived connections send messages to
the long lived ones.
The long lived connection are all connected when the first memory
increase phase ends, which is when the short-lived connections start
sending messages.
What is unclear to me is why the second memory increase phase happens
quite some time after these short lived processes have started sending
messages.
Post by Anton Lebedevich
The graph looks really weird for me assuming that the load applied to
the system is stable. Why does it go down for a short time and then
jumps higher than it was?
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Roberto Ostinelli
2015-02-25 18:49:19 UTC
Permalink
It's the processes handling the ssl sockets.

Best,
r.
Hi!
Did you try observing your system with the observer application? You should be able to get much better information of what Erlang processes consume a lot of memory and
why.
Regards Ingela Erlang/OTP Team - Ericsson AB
As an addendum: I apologise because this cannot be clearly seen in the charts (I forgot to "humanise" the axis), but we're talking about a steady RAM usage of 4.5GB without SSL, in comparison to blowing up a node with 30GB with SSL.
Best,
r.
Post by Roberto Ostinelli
Dear List,
Given the amount of answers I got in this post, I want to follow up and give some additional information.
After struggling for quite a while, I just did a comparison between using SSL connections vs standard TCP connections.
The results are quite impressive.
https://cldup.com/cNOc8hS004-2000x2000.png
https://cldup.com/sx3RrdMR8o-3000x3000.png
You can clearly see that using standard TCP connections the system is extremely stable.
Using SSL connections, on the other hand, results in RAM memory having very erratic behavior that ends up blowing up the node.
Not sure what to do with this information, except that I'm going to use a SSL termination (HAProxy or ELB) and have my Erlang node run without SSL.
If anyone is curious just ping me.
Best,
r.
Post by Roberto Ostinelli
That's a valid point, and I can clarify.
During the first phase, all the long lived connections are made. During the second phase, newly-created short lived connections send messages to the long lived ones.
The long lived connection are all connected when the first memory increase phase ends, which is when the short-lived connections start sending messages.
What is unclear to me is why the second memory increase phase happens quite some time after these short lived processes have started sending messages.
Post by Anton Lebedevich
The graph looks really weird for me assuming that the load applied to
the system is stable. Why does it go down for a short time and then
jumps higher than it was?
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Erik Søe Sørensen
2015-02-25 19:28:54 UTC
Permalink
Are you using the 'hibernate_after' ssl option? It made quite a difference
in our application.
Den 25/02/2015 19.49 skrev "Roberto Ostinelli" <
Post by Roberto Ostinelli
It's the processes handling the ssl sockets.
Best,
r.
Hi!
Did you try observing your system with the observer application? You
should be able to get much better information of what Erlang processes
consume a lot of memory and
why.
Regards Ingela Erlang/OTP Team - Ericsson AB
Post by Roberto Ostinelli
As an addendum: I apologise because this cannot be clearly seen in the
charts (I forgot to "humanise" the axis), but we're talking about a steady
RAM usage of 4.5GB without SSL, in comparison to blowing up a node with
30GB with SSL.
Best,
r.
Post by Roberto Ostinelli
Dear List,
Given the amount of answers I got in this post, I want to follow up and
give some additional information.
After struggling for quite a while, I just did a comparison between
using SSL connections vs standard TCP connections.
The results are quite impressive.
https://cldup.com/cNOc8hS004-2000x2000.png
https://cldup.com/sx3RrdMR8o-3000x3000.png
You can clearly see that using standard TCP connections the system is extremely stable.
Using SSL connections, on the other hand, results in RAM memory having
very erratic behavior that ends up blowing up the node.
Not sure what to do with this information, except that I'm going to use
a SSL termination (HAProxy or ELB) and have my Erlang node run without SSL.
If anyone is curious just ping me.
Best,
r.
On Wed, Jan 28, 2015 at 8:09 PM, Roberto Ostinelli <
Post by Roberto Ostinelli
That's a valid point, and I can clarify.
During the first phase, all the long lived connections are made. During
the second phase, newly-created short lived connections send messages to
the long lived ones.
The long lived connection are all connected when the first memory
increase phase ends, which is when the short-lived connections start
sending messages.
What is unclear to me is why the second memory increase phase happens
quite some time after these short lived processes have started sending
messages.
Post by Anton Lebedevich
The graph looks really weird for me assuming that the load applied to
the system is stable. Why does it go down for a short time and then
jumps higher than it was?
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Roberto Ostinelli
2015-02-26 08:13:12 UTC
Permalink
I'm using the regular hibernate. Even so, the issue here is not only ram consumption, rather the inconsistency - going up and down, spikes, etc - that are not seen on the same system running without SSL.

Thanks,
r.
Are you using the 'hibernate_after' ssl option? It made quite a difference in our application.
Benoit Chesneau
2015-02-26 10:20:22 UTC
Permalink
On Thu, Feb 26, 2015 at 9:13 AM, Roberto Ostinelli <
Post by Roberto Ostinelli
I'm using the regular hibernate. Even so, the issue here is not only ram
consumption, rather the inconsistency - going up and down, spikes, etc -
that are not seen on the same system running without SSL.
Thanks,
r.
Nice trick :). How much time do you pass to the setting? Or rather which
method did you use to find it? We have a similar issue there too using
plain HTTP vs HTTPs makes a real difference and we observe a lot of spikes
and so on in the memory too.

- benoit
Post by Roberto Ostinelli
Post by Erik Søe Sørensen
Are you using the 'hibernate_after' ssl option? It made quite a
difference in our application.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Loïc Hoguin
2015-02-26 10:17:46 UTC
Permalink
He makes a good point, you are using hibernate yes, but that doesn't
hibernate SSL processes themselves. With hibernate_after the SSL
processes would hibernate too.

Not sure if that would solve anything though, and SSL can probably be
made more stable without the need to hibernate, which has a cost on its own.
Post by Roberto Ostinelli
I'm using the regular hibernate. Even so, the issue here is not only ram consumption, rather the inconsistency - going up and down, spikes, etc - that are not seen on the same system running without SSL.
Thanks,
r.
Are you using the 'hibernate_after' ssl option? It made quite a difference in our application.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
--
Loïc Hoguin
http://ninenines.eu
Roberto Ostinelli
2015-02-26 11:56:55 UTC
Permalink
Ah yes, indeed. The SSL processes I keep forgetting about.
I'm tempted to do another run with this option in.
Post by Loïc Hoguin
He makes a good point, you are using hibernate yes, but that doesn't
hibernate SSL processes themselves. With hibernate_after the SSL processes
would hibernate too.
Not sure if that would solve anything though, and SSL can probably be made
more stable without the need to hibernate, which has a cost on its own.
Benoit Chesneau
2015-03-04 12:08:13 UTC
Permalink
Post by Roberto Ostinelli
Ah yes, indeed. The SSL processes I keep forgetting about.
I'm tempted to do another run with this option in.
Did you have any success with it? In our own tests it just mitigate the
issue for some times, but it is still growing over the time.

- benoit
Post by Roberto Ostinelli
Post by Loïc Hoguin
He makes a good point, you are using hibernate yes, but that doesn't
hibernate SSL processes themselves. With hibernate_after the SSL processes
would hibernate too.
Not sure if that would solve anything though, and SSL can probably be
made more stable without the need to hibernate, which has a cost on its own.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Roberto Ostinelli
2015-03-04 15:56:45 UTC
Permalink
Yes.
It stabilized impressively the whole thing.

I also tried HAproxy (single CPU), and stud. Both were far from being able
to handle the load that I'm throwing at them. I mean, *far*.

Best,
r.
Post by Benoit Chesneau
Post by Roberto Ostinelli
Ah yes, indeed. The SSL processes I keep forgetting about.
I'm tempted to do another run with this option in.
Did you have any success with it? In our own tests it just mitigate the
issue for some times, but it is still growing over the time.
- benoit
Post by Roberto Ostinelli
Post by Loïc Hoguin
He makes a good point, you are using hibernate yes, but that doesn't
hibernate SSL processes themselves. With hibernate_after the SSL processes
would hibernate too.
Not sure if that would solve anything though, and SSL can probably be
made more stable without the need to hibernate, which has a cost on its own.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Rick Reed
2015-03-04 17:12:23 UTC
Permalink
Interesting. What kind of load were you throwing at stud that it couldn’t handle? We terminate all our SSL using stud. We easily do >2000 handshakes per second and as much as 8Gb/s per server. Granted, these are pretty beefy boxes, but the only part of the stud setup that doesn’t scale for us is when we’re trying to scale up past 1.5M external connections (which means 4.5M sockets).

Rr

From: Roberto Ostinelli <***@widetag.com<mailto:***@widetag.com>>
Date: Wednesday, March 4, 2015 at 7:56 AM
To: Benoit Chesneau <***@gmail.com<mailto:***@gmail.com>>
Cc: Erlang Questions <erlang-***@erlang.org<mailto:erlang-***@erlang.org>>
Subject: Re: [erlang-questions] Garbage Collection, BEAM memory and Erlang memory

Yes.
It stabilized impressively the whole thing.

I also tried HAproxy (single CPU), and stud. Both were far from being able to handle the load that I'm throwing at them. I mean, *far*.

Best,
r.

On Wed, Mar 4, 2015 at 1:08 PM, Benoit Chesneau <***@gmail.com<mailto:***@gmail.com>> wrote:


On Thu, Feb 26, 2015 at 12:56 PM, Roberto Ostinelli <***@widetag.com<mailto:***@widetag.com>> wrote:
Ah yes, indeed. The SSL processes I keep forgetting about.
I'm tempted to do another run with this option in.


Did you have any success with it? In our own tests it just mitigate the issue for some times, but it is still growing over the time.

- benoit


On Thu, Feb 26, 2015 at 11:17 AM, Loïc Hoguin <***@ninenines.eu<mailto:***@ninenines.eu>> wrote:
He makes a good point, you are using hibernate yes, but that doesn't hibernate SSL processes themselves. With hibernate_after the SSL processes would hibernate too.

Not sure if that would solve anything though, and SSL can probably be made more stable without the need to hibernate, which has a cost on its own.
Roberto Ostinelli
2015-03-04 18:22:45 UTC
Permalink
Interesting. What kind of load were you throwing at stud that it couldn’t handle? We terminate all our SSL using stud. We easily do >2000 handshakes per second and as much as 8Gb/s per server. Granted, these are pretty beefy boxes, but the only part of the stud setup that doesn’t scale for us is when we’re trying to scale up past 1.5M external connections (which means 4.5M sockets).
Rr
Hi Rick,
I didn't use a separate box for SSL termination with stud. I basically wanted to see if stud could offload SSL from my Erlang application, so I just set my app to run in non-ssl mode, and had stud handle the SSL frontend on the same box.

On a single Erlang box with SSL-enabled I handle around 180k always-connected devices, each sending heartbeats every minute, plus around 4k/s short-lived incoming https requests.

Sure, I'd be better off having stud on a separate box, but I'd rather have 2 Erlang boxes than 1 Erlang + 1 stud box. Also, I read on stud's readme file that every connection has a 200k bytes overhead. Erlang uses around 8GB for everything so stud's ram consumption is order of magnitude higher for my 180k online + 20k short-lived connections (unless I mis-read that info).

Anything you believe I should try?

Best,
r.
Rick Reed
2015-03-04 21:30:14 UTC
Permalink
Post by Roberto Ostinelli
I didn't use a separate box for SSL termination with stud. I basically
wanted to see if stud could offload SSL from my Erlang application, so I
just set my app to run in non-ssl mode, and had stud handle the SSL
frontend on the same box.
That¹s exactly what we do.
Post by Roberto Ostinelli
Also, I read on stud's readme file that every connection has a 200k bytes
overhead.
We patched a config option to reduce the size of the per-conn buffer space
(from 96k). On one service, we run 4K buffering per user.

Rr

Erik Søe Sørensen
2015-03-04 19:52:25 UTC
Permalink
Good to hear.
Although... Graphs or it didn't happen? :-)
Post by Roberto Ostinelli
Yes.
It stabilized impressively the whole thing.
I also tried HAproxy (single CPU), and stud. Both were far from being able
to handle the load that I'm throwing at them. I mean, *far*.
Best,
r.
Post by Benoit Chesneau
Post by Roberto Ostinelli
Ah yes, indeed. The SSL processes I keep forgetting about.
I'm tempted to do another run with this option in.
Did you have any success with it? In our own tests it just mitigate the
issue for some times, but it is still growing over the time.
- benoit
Post by Roberto Ostinelli
Post by Loïc Hoguin
He makes a good point, you are using hibernate yes, but that doesn't
hibernate SSL processes themselves. With hibernate_after the SSL processes
would hibernate too.
Not sure if that would solve anything though, and SSL can probably be
made more stable without the need to hibernate, which has a cost on its own.
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
_______________________________________________
erlang-questions mailing list
http://erlang.org/mailman/listinfo/erlang-questions
Roberto Ostinelli
2015-03-04 20:03:44 UTC
Permalink
Here you go:
Loading Image...

^^_

r.
Post by Erik Søe Sørensen
Good to hear.
Although... Graphs or it didn't happen? :-)
Anton Lebedevich
2015-01-28 07:16:43 UTC
Permalink
On Tue, Jan 27, 2015 at 9:48 PM, Roberto Ostinelli <***@widetag.com> wrote:
...
the machine seems stable, but at a certain moment *within 30 seconds* the VM
memory usage suddenly increases from 11GB to 15GB until it crashes.
One way to catch it is to run a shell script that checks beam memory
usage every second and forces crash dump via kill -USR1 when it passes
some threshold. Then you can analyse obtained dump file for big
processes or allocator usage.

Regards,
Anton Lebedevich.
Roberto Ostinelli
2015-01-28 11:50:00 UTC
Permalink
Post by Anton Lebedevich
One way to catch it is to run a shell script that checks beam memory
usage every second and forces crash dump via kill -USR1 when it passes
some threshold. Then you can analyse obtained dump file for big
processes or allocator usage.
Regards,
Anton Lebedevich.
Hi Anton,
Yes I'm also puzzled why no crash dump is generated for me.

Best,
r.
Anton Lebedevich
2015-01-28 12:21:03 UTC
Permalink
Post by Roberto Ostinelli
Post by Anton Lebedevich
One way to catch it is to run a shell script that checks beam memory
usage every second and forces crash dump via kill -USR1 when it passes
some threshold. Then you can analyse obtained dump file for big
processes or allocator usage.
Hi Anton,
Yes I'm also puzzled why no crash dump is generated for me.
Crash with no dump might be caused by system OOM killer.

Regards,
Anton
Lukas Larsson
2015-01-23 09:40:22 UTC
Permalink
Hello Roberto,

I cannot find any information about which version of Erlang/OTP that you
are running, nor which setting you have given to VM at startup?
Post by Roberto Ostinelli
I get my erlang memory with this simple call (I just convert everything to
GB, thanks to Ferd and his article
Have you also read the part about the memory fragmentation issues that Mr
Hebert described? Specifically running
recon_alloc:memory(allocated,current) and recon_alloc:memory(usage,
current) and checking those values during the test.

Lukas
Roberto Ostinelli
2015-01-23 13:33:04 UTC
Permalink
Hi Lucas,
I'm using 17.4 on ubuntu LTS 14.04. The settings I use are:

+K true
+P 2000000
+Q 1000000

Please find here below an additional set of data with the changes I've
stated here above (binary:copy/0 and the fullsweep_after 0 in the router).

Of the recon library I'm using the following calls:

recon_alloc:memory(allocated, current).
recon_alloc:memory(used, current).
recon_alloc:memory(usage, current).


All of this data is taken at random intervals of time.

- BEAM process RES memory:* 2.732 GB*
- Erlang memory:
[{total,1.7860298827290535},
{processes,1.4158401936292648},
{processes_used,1.4157484397292137},
{system,0.37018968909978867},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.20867645740509033},
{code,0.009268132038414478},
{ets,0.004821933805942535}]
- recon_alloc:
allocated: 3015796080 (2.808 GB)
used: 2161850416
usage: 0.7187714029859935


- BEAM process RES memory:* 2.813 GB*
- Erlang memory:
[{total,2.026990756392479},
{processes,1.6270370781421661},
{processes_used,1.6269719526171684},
{system,0.3999536782503128},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.23845425993204117},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
- recon_alloc:
allocated: 3098895728 (2.886 GB)
used: 2176172480
usage: 0.7023218278482198


- BEAM process RES memory:* 3.029 GB*
- Erlang memory:
[{total,2.351852521300316},
{processes,1.9361207410693169},
{processes_used,1.9360847249627113},
{system,0.415731780230999},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2539009377360344},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
- recon_alloc:
allocated: 3337524592 (3.108 GB)
used: 2525365352
usage: 0.7548030747173055


- BEAM process RES memory:* 3.099 GB*
- Erlang memory:
[{total,2.0704088881611824},
{processes,1.6625376418232918},
{processes_used,1.6624245047569275},
{system,0.4078712463378906},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.24636883288621902},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
- recon_alloc:
allocated: 3400623472 (3.167 GB)
used: 2222575336
usage: 0.6552131374790817


- BEAM process RES memory:* 3.132 GB*
- Erlang memory:
[{total,2.367126949131489},
{processes,1.9388784170150757},
{processes_used,1.938723236322403},
{system,0.4282485321164131},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2667432576417923},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
- recon_alloc:
allocated: 3435644272 (3.200 GB)
used: 2541469864
usage: 0.7397146313173368


- BEAM process RES memory:* 3.307 GB*
- Erlang memory:
[{total,2.379016488790512},
{processes,1.9780860394239426},
{processes_used,1.9779272973537445},
{system,0.4009304493665695},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.23943009227514267},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
- recon_alloc:
allocated: 3619329392 (3.371 GB)
used: 2554804000
usage: 0.704330124232303


- BEAM process RES memory:* 3.351 GB*
- Erlang memory:
[{total,2.607522390782833},
{processes,2.168950654566288},
{processes_used,2.1688189953565598},
{system,0.4385717362165451},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2771267145872116},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
- recon_alloc:
allocated: 3669321072 (3.417 GB)
used: 2799919616
usage: 0.7629933213977411


- BEAM process RES memory:* 3.469 GB*
- Erlang memory:
[{total,2.2596140429377556},
{processes,1.8098593652248383},
{processes_used,1.8098137602210045},
{system,0.44975467771291733},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.2881493419408798},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
- recon_alloc:
allocated: 3789014384 (3.528 GB)
used: 2425613912
usage: 0.6401929098614897


- BEAM process RES memory:* 3.660 GB*
- Erlang memory:
[{total,2.692381367087364},
{processes,2.2282255738973618},
{processes_used,2.228082850575447},
{system,0.46415579319000244},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.30247989296913147},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
- recon_alloc:
allocated: 3993933168 (3.719 GB)
used: 2890714704
usage: 0.7233507625681828


- BEAM process RES memory:* 3.667 GB*
- Erlang memory:
[{total,2.4165985733270645},
{processes,1.9264011159539223},
{processes_used,1.9263720959424973},
{system,0.49019745737314224},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.3284950777888298},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
- recon_alloc:
allocated: 4001830256 (3.727 GB)
used: 2594872464
usage: 0.6483950197811689


It looks like the memory allocated has some mismatch with the memory
reported by the OS, but maybe this is just a timing issue (since top
provides an average during a period of time)?

Anyway, the BEAM process keeps on increasing. Also, it looks like memory
usage bounces anywhere from 64-72% and I don't know if that's a good figure
or not.

This is what I get from a check on memory fragmentation:

1> recon_alloc:fragmentation(current).
[{{eheap_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.6252789717100151},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,391670536},
{mbcs_carriers_size,626393264}]},
{{eheap_alloc,2},
[{sbcs_usage,0.6168021896258503},
{mbcs_usage,0.6893887270883688},
{sbcs_block_size,371384},
{sbcs_carriers_size,602112},
{mbcs_block_size,370926112},
{mbcs_carriers_size,538050736}]},
{{eheap_alloc,3},
[{sbcs_usage,0.9991333400321544},
{mbcs_usage,0.7006580932915004},
{sbcs_block_size,5091008},
{sbcs_carriers_size,5095424},
{mbcs_block_size,324091688},
{mbcs_carriers_size,462553264}]},
{{eheap_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.6924985776876923},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,305976264},
{mbcs_carriers_size,441843888}]},
{{eheap_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.6397496430493375},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,207536944},
{mbcs_carriers_size,324403376}]},
{{eheap_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.6660125315617468},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,166472816},
{mbcs_carriers_size,249954480}]},
{{eheap_alloc,6},
[{sbcs_usage,0.9980070153061225},
{mbcs_usage,0.6770963446791575},
{sbcs_block_size,600912},
{sbcs_carriers_size,602112},
{mbcs_block_size,169065768},
{mbcs_carriers_size,249692336}]},
{{eheap_alloc,7},
[{sbcs_usage,0.997382155987395},
{mbcs_usage,0.6925225022824623},
{sbcs_block_size,972296},
{sbcs_carriers_size,974848},
{mbcs_block_size,167834424},
{mbcs_carriers_size,242352304}]},
{{ll_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.7387279228243809},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,112706224},
{mbcs_carriers_size,152567976}]},
{{binary_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7614033191804973},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,58507096},
{mbcs_carriers_size,76841136}]},
{{binary_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.7179048085736076},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,46131288},
{mbcs_carriers_size,64258224}]},
{{binary_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.6128136272843548},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,27651200},
{mbcs_carriers_size,45121712}]},
{{binary_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.6492102167567332},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,32186648},
{mbcs_carriers_size,49578160}]},
{{binary_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.7715637758298944},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,56051664},
{mbcs_carriers_size,72646832}]},
{{binary_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.7514879308127178},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,49077272},
{mbcs_carriers_size,65306800}]},
{{binary_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.6757064168943689},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25706456},
{mbcs_carriers_size,38043824}]},
{{binary_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.7016146506167494},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25956408},
{mbcs_carriers_size,36995248}]},
{{fix_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.7409146075507547},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,22748888},
{mbcs_carriers_size,30703792}]},
{{fix_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.8581522751225302},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,33547232},
{mbcs_carriers_size,39092400}]},
{{fix_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.8630094940716118},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,26497664},
{mbcs_carriers_size,...}]},
{{driver_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7615924083651237},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,...},
{...}]},
{{fix_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.8947156992151927},
{sbcs_block_size,0},
{sbcs_carriers_size,...},
{...}|...]},
{{fix_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.7166474590927997},
{sbcs_block_size,...},
{...}|...]},
{{ll_alloc,7},[{sbcs_usage,1.0},{mbcs_usage,...},{...}|...]},
{{driver_alloc,2},[{sbcs_usage,...},{...}|...]},
{{driver_alloc,4},[{...}|...]},
{{ll_alloc,...},[...]},
{{...},...},
{...}|...]


Unless I'm mistaken reading this data, everything looks fine there, with
normal usages.

What can I do else to address this issue?

Thank you for your help.
r.
Post by Lukas Larsson
Hello Roberto,
I cannot find any information about which version of Erlang/OTP that you
are running, nor which setting you have given to VM at startup?
Post by Roberto Ostinelli
I get my erlang memory with this simple call (I just convert everything
to GB, thanks to Ferd and his article
Have you also read the part about the memory fragmentation issues that Mr
Hebert described? Specifically running
recon_alloc:memory(allocated,current) and recon_alloc:memory(usage,
current) and checking those values during the test.
Lukas
Сергей Прохоров
2015-01-23 17:29:06 UTC
Permalink
Hi, Roberto.

Looks like you have some sort of multiblock allocator fragmentation.
As you can see in `recon_alloc:fragmentation(current).` output, your
mbcs_usage ~0.7 is correlating with `recon_alloc:memory(usage, current).`

So, problem isn't in refcounted binaries, but in multiblock allocator
fragmantation.
Also, note that worst utilized allocators is allocators for erlang process
heaps (eheap_alloc), allocators for refc binaries (binary_alloc) are on
2'nd place.

Erlang MBCS allocate large chunks of memory (carrier) and then return
chunks of it (so called blocks) by-demand
[ busy1 | busy2 | busy3 | free ....... ]

When some erlang sybsystem releases used memory (eg, process dies or binary
released), this space is marked as free on carrier and pointer to it is
placed to binary tree for being reused

[ busy1 | busy2 | busy3 | free1 | busy4 | free2 ]

*--------------------^ ^
a b*-------------------------------|
\ /
free_blocks_tree

Whole carrier will be deallocated and released to OS only when all blocks
on it are free. There is no such thing like carrier defragmentation. But,
AFAIK, erlang may terurn (shrink) to OS free blocks from carrier's tail
(eg, free2 from pic). Plus 2 free neighbours will be merged to one (eg, if
busy4 will be freed, ti will be merged to single block with free1 and
free2).

As you can see, carrier on my "picture" has some holes. It's memory
utilization is ~ `sum(busy) / (sum(free) + sum(busy))`.

Also, if beam asks free_blocks_tree for a free block of certain size, but
it has only bigger one, it splits it to 2 blocks, leading to additional
fragmentation.

There are some strategies to improve this situation:
1) make less alloc/dealloc operations (you may try to make larger
min_heap_size for new processes to reduce GC frequency)
2) change `free_blocks_tree` sorting order so it will be address-ordered
and blocks from tail may be returned to OS faster
3) tune mbcs_block_size and mbcs_carrier_size to fit better to your most
common data's size to reduce fragmentation by helping free blocks reusage.

Which one fits your needs I don't know. You may consult this doc
http://erlang.org/doc/man/erts_alloc.html for more details.

Hi Lucas,
Post by Roberto Ostinelli
+K true
+P 2000000
+Q 1000000
Please find here below an additional set of data with the changes I've
stated here above (binary:copy/0 and the fullsweep_after 0 in the router).
recon_alloc:memory(allocated, current).
recon_alloc:memory(used, current).
recon_alloc:memory(usage, current).
All of this data is taken at random intervals of time.
- BEAM process RES memory:* 2.732 GB*
[{total,1.7860298827290535},
{processes,1.4158401936292648},
{processes_used,1.4157484397292137},
{system,0.37018968909978867},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.20867645740509033},
{code,0.009268132038414478},
{ets,0.004821933805942535}]
allocated: 3015796080 (2.808 GB)
used: 2161850416
usage: 0.7187714029859935
- BEAM process RES memory:* 2.813 GB*
[{total,2.026990756392479},
{processes,1.6270370781421661},
{processes_used,1.6269719526171684},
{system,0.3999536782503128},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.23845425993204117},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3098895728 (2.886 GB)
used: 2176172480
usage: 0.7023218278482198
- BEAM process RES memory:* 3.029 GB*
[{total,2.351852521300316},
{processes,1.9361207410693169},
{processes_used,1.9360847249627113},
{system,0.415731780230999},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2539009377360344},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3337524592 (3.108 GB)
used: 2525365352
usage: 0.7548030747173055
- BEAM process RES memory:* 3.099 GB*
[{total,2.0704088881611824},
{processes,1.6625376418232918},
{processes_used,1.6624245047569275},
{system,0.4078712463378906},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.24636883288621902},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3400623472 (3.167 GB)
used: 2222575336
usage: 0.6552131374790817
- BEAM process RES memory:* 3.132 GB*
[{total,2.367126949131489},
{processes,1.9388784170150757},
{processes_used,1.938723236322403},
{system,0.4282485321164131},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2667432576417923},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3435644272 (3.200 GB)
used: 2541469864
usage: 0.7397146313173368
- BEAM process RES memory:* 3.307 GB*
[{total,2.379016488790512},
{processes,1.9780860394239426},
{processes_used,1.9779272973537445},
{system,0.4009304493665695},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.23943009227514267},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3619329392 (3.371 GB)
used: 2554804000
usage: 0.704330124232303
- BEAM process RES memory:* 3.351 GB*
[{total,2.607522390782833},
{processes,2.168950654566288},
{processes_used,2.1688189953565598},
{system,0.4385717362165451},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2771267145872116},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3669321072 (3.417 GB)
used: 2799919616
usage: 0.7629933213977411
- BEAM process RES memory:* 3.469 GB*
[{total,2.2596140429377556},
{processes,1.8098593652248383},
{processes_used,1.8098137602210045},
{system,0.44975467771291733},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.2881493419408798},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
allocated: 3789014384 (3.528 GB)
used: 2425613912
usage: 0.6401929098614897
- BEAM process RES memory:* 3.660 GB*
[{total,2.692381367087364},
{processes,2.2282255738973618},
{processes_used,2.228082850575447},
{system,0.46415579319000244},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.30247989296913147},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
allocated: 3993933168 (3.719 GB)
used: 2890714704
usage: 0.7233507625681828
- BEAM process RES memory:* 3.667 GB*
[{total,2.4165985733270645},
{processes,1.9264011159539223},
{processes_used,1.9263720959424973},
{system,0.49019745737314224},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.3284950777888298},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
allocated: 4001830256 (3.727 GB)
used: 2594872464
usage: 0.6483950197811689
It looks like the memory allocated has some mismatch with the memory
reported by the OS, but maybe this is just a timing issue (since top
provides an average during a period of time)?
Anyway, the BEAM process keeps on increasing. Also, it looks like memory
usage bounces anywhere from 64-72% and I don't know if that's a good figure
or not.
1> recon_alloc:fragmentation(current).
[{{eheap_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.6252789717100151},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,391670536},
{mbcs_carriers_size,626393264}]},
{{eheap_alloc,2},
[{sbcs_usage,0.6168021896258503},
{mbcs_usage,0.6893887270883688},
{sbcs_block_size,371384},
{sbcs_carriers_size,602112},
{mbcs_block_size,370926112},
{mbcs_carriers_size,538050736}]},
{{eheap_alloc,3},
[{sbcs_usage,0.9991333400321544},
{mbcs_usage,0.7006580932915004},
{sbcs_block_size,5091008},
{sbcs_carriers_size,5095424},
{mbcs_block_size,324091688},
{mbcs_carriers_size,462553264}]},
{{eheap_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.6924985776876923},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,305976264},
{mbcs_carriers_size,441843888}]},
{{eheap_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.6397496430493375},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,207536944},
{mbcs_carriers_size,324403376}]},
{{eheap_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.6660125315617468},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,166472816},
{mbcs_carriers_size,249954480}]},
{{eheap_alloc,6},
[{sbcs_usage,0.9980070153061225},
{mbcs_usage,0.6770963446791575},
{sbcs_block_size,600912},
{sbcs_carriers_size,602112},
{mbcs_block_size,169065768},
{mbcs_carriers_size,249692336}]},
{{eheap_alloc,7},
[{sbcs_usage,0.997382155987395},
{mbcs_usage,0.6925225022824623},
{sbcs_block_size,972296},
{sbcs_carriers_size,974848},
{mbcs_block_size,167834424},
{mbcs_carriers_size,242352304}]},
{{ll_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.7387279228243809},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,112706224},
{mbcs_carriers_size,152567976}]},
{{binary_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7614033191804973},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,58507096},
{mbcs_carriers_size,76841136}]},
{{binary_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.7179048085736076},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,46131288},
{mbcs_carriers_size,64258224}]},
{{binary_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.6128136272843548},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,27651200},
{mbcs_carriers_size,45121712}]},
{{binary_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.6492102167567332},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,32186648},
{mbcs_carriers_size,49578160}]},
{{binary_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.7715637758298944},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,56051664},
{mbcs_carriers_size,72646832}]},
{{binary_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.7514879308127178},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,49077272},
{mbcs_carriers_size,65306800}]},
{{binary_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.6757064168943689},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25706456},
{mbcs_carriers_size,38043824}]},
{{binary_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.7016146506167494},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25956408},
{mbcs_carriers_size,36995248}]},
{{fix_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.7409146075507547},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,22748888},
{mbcs_carriers_size,30703792}]},
{{fix_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.8581522751225302},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,33547232},
{mbcs_carriers_size,39092400}]},
{{fix_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.8630094940716118},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,26497664},
{mbcs_carriers_size,...}]},
{{driver_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7615924083651237},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,...},
{...}]},
{{fix_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.8947156992151927},
{sbcs_block_size,0},
{sbcs_carriers_size,...},
{...}|...]},
{{fix_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.7166474590927997},
{sbcs_block_size,...},
{...}|...]},
{{ll_alloc,7},[{sbcs_usage,1.0},{mbcs_usage,...},{...}|...]},
{{driver_alloc,2},[{sbcs_usage,...},{...}|...]},
{{driver_alloc,4},[{...}|...]},
{{ll_alloc,...},[...]},
{{...},...},
{...}|...]
Unless I'm mistaken reading this data, everything looks fine there, with
normal usages.
What can I do else to address this issue?
Thank you for your help.
r.
Roberto Ostinelli
2015-01-23 18:40:12 UTC
Permalink
Thank you Cepren,
Yes it looks like I have also some fragmentation issue. Will try some options there as I was suggested.

Thanks,
r.
Post by Сергей Прохоров
Hi, Roberto.
Looks like you have some sort of multiblock allocator fragmentation.
As you can see in `recon_alloc:fragmentation(current).` output, your mbcs_usage ~0.7 is correlating with `recon_alloc:memory(usage, current).`
So, problem isn't in refcounted binaries, but in multiblock allocator fragmantation.
Also, note that worst utilized allocators is allocators for erlang process heaps (eheap_alloc), allocators for refc binaries (binary_alloc) are on 2'nd place.
Erlang MBCS allocate large chunks of memory (carrier) and then return chunks of it (so called blocks) by-demand
[ busy1 | busy2 | busy3 | free ....... ]
When some erlang sybsystem releases used memory (eg, process dies or binary released), this space is marked as free on carrier and pointer to it is placed to binary tree for being reused
[ busy1 | busy2 | busy3 | free1 | busy4 | free2 ]
*--------------------^ ^
a b*-------------------------------|
\ /
free_blocks_tree
Whole carrier will be deallocated and released to OS only when all blocks on it are free. There is no such thing like carrier defragmentation. But, AFAIK, erlang may terurn (shrink) to OS free blocks from carrier's tail (eg, free2 from pic). Plus 2 free neighbours will be merged to one (eg, if busy4 will be freed, ti will be merged to single block with free1 and free2).
As you can see, carrier on my "picture" has some holes. It's memory utilization is ~ `sum(busy) / (sum(free) + sum(busy))`.
Also, if beam asks free_blocks_tree for a free block of certain size, but it has only bigger one, it splits it to 2 blocks, leading to additional fragmentation.
1) make less alloc/dealloc operations (you may try to make larger min_heap_size for new processes to reduce GC frequency)
2) change `free_blocks_tree` sorting order so it will be address-ordered and blocks from tail may be returned to OS faster
3) tune mbcs_block_size and mbcs_carrier_size to fit better to your most common data's size to reduce fragmentation by helping free blocks reusage.
Which one fits your needs I don't know. You may consult this doc http://erlang.org/doc/man/erts_alloc.html for more details.
Post by Roberto Ostinelli
Hi Lucas,
+K true
+P 2000000
+Q 1000000
Please find here below an additional set of data with the changes I've
stated here above (binary:copy/0 and the fullsweep_after 0 in the router).
recon_alloc:memory(allocated, current).
recon_alloc:memory(used, current).
recon_alloc:memory(usage, current).
All of this data is taken at random intervals of time.
- BEAM process RES memory:* 2.732 GB*
[{total,1.7860298827290535},
{processes,1.4158401936292648},
{processes_used,1.4157484397292137},
{system,0.37018968909978867},
{atom,4.000673070549965e-4},
{atom_used,3.846092149615288e-4},
{binary,0.20867645740509033},
{code,0.009268132038414478},
{ets,0.004821933805942535}]
allocated: 3015796080 (2.808 GB)
used: 2161850416
usage: 0.7187714029859935
- BEAM process RES memory:* 2.813 GB*
[{total,2.026990756392479},
{processes,1.6270370781421661},
{processes_used,1.6269719526171684},
{system,0.3999536782503128},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.23845425993204117},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3098895728 (2.886 GB)
used: 2176172480
usage: 0.7023218278482198
- BEAM process RES memory:* 3.029 GB*
[{total,2.351852521300316},
{processes,1.9361207410693169},
{processes_used,1.9360847249627113},
{system,0.415731780230999},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2539009377360344},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3337524592 (3.108 GB)
used: 2525365352
usage: 0.7548030747173055
- BEAM process RES memory:* 3.099 GB*
[{total,2.0704088881611824},
{processes,1.6625376418232918},
{processes_used,1.6624245047569275},
{system,0.4078712463378906},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.24636883288621902},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3400623472 (3.167 GB)
used: 2222575336
usage: 0.6552131374790817
- BEAM process RES memory:* 3.132 GB*
[{total,2.367126949131489},
{processes,1.9388784170150757},
{processes_used,1.938723236322403},
{system,0.4282485321164131},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2667432576417923},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3435644272 (3.200 GB)
used: 2541469864
usage: 0.7397146313173368
- BEAM process RES memory:* 3.307 GB*
[{total,2.379016488790512},
{processes,1.9780860394239426},
{processes_used,1.9779272973537445},
{system,0.4009304493665695},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.23943009227514267},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3619329392 (3.371 GB)
used: 2554804000
usage: 0.704330124232303
- BEAM process RES memory:* 3.351 GB*
[{total,2.607522390782833},
{processes,2.168950654566288},
{processes_used,2.1688189953565598},
{system,0.4385717362165451},
{atom,4.000673070549965e-4},
{atom_used,3.8593634963035583e-4},
{binary,0.2771267145872116},
{code,0.009311830624938011},
{ets,0.004802137613296509}]
allocated: 3669321072 (3.417 GB)
used: 2799919616
usage: 0.7629933213977411
- BEAM process RES memory:* 3.469 GB*
[{total,2.2596140429377556},
{processes,1.8098593652248383},
{processes_used,1.8098137602210045},
{system,0.44975467771291733},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.2881493419408798},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
allocated: 3789014384 (3.528 GB)
used: 2425613912
usage: 0.6401929098614897
- BEAM process RES memory:* 3.660 GB*
[{total,2.692381367087364},
{processes,2.2282255738973618},
{processes_used,2.228082850575447},
{system,0.46415579319000244},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.30247989296913147},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
allocated: 3993933168 (3.719 GB)
used: 2890714704
usage: 0.7233507625681828
- BEAM process RES memory:* 3.667 GB*
[{total,2.4165985733270645},
{processes,1.9264011159539223},
{processes_used,1.9263720959424973},
{system,0.49019745737314224},
{atom,4.000673070549965e-4},
{atom_used,3.86836938560009e-4},
{binary,0.3284950777888298},
{code,0.009375222958624363},
{ets,0.00480380654335022}]
allocated: 4001830256 (3.727 GB)
used: 2594872464
usage: 0.6483950197811689
It looks like the memory allocated has some mismatch with the memory
reported by the OS, but maybe this is just a timing issue (since top
provides an average during a period of time)?
Anyway, the BEAM process keeps on increasing. Also, it looks like memory
usage bounces anywhere from 64-72% and I don't know if that's a good figure
or not.
1> recon_alloc:fragmentation(current).
[{{eheap_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.6252789717100151},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,391670536},
{mbcs_carriers_size,626393264}]},
{{eheap_alloc,2},
[{sbcs_usage,0.6168021896258503},
{mbcs_usage,0.6893887270883688},
{sbcs_block_size,371384},
{sbcs_carriers_size,602112},
{mbcs_block_size,370926112},
{mbcs_carriers_size,538050736}]},
{{eheap_alloc,3},
[{sbcs_usage,0.9991333400321544},
{mbcs_usage,0.7006580932915004},
{sbcs_block_size,5091008},
{sbcs_carriers_size,5095424},
{mbcs_block_size,324091688},
{mbcs_carriers_size,462553264}]},
{{eheap_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.6924985776876923},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,305976264},
{mbcs_carriers_size,441843888}]},
{{eheap_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.6397496430493375},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,207536944},
{mbcs_carriers_size,324403376}]},
{{eheap_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.6660125315617468},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,166472816},
{mbcs_carriers_size,249954480}]},
{{eheap_alloc,6},
[{sbcs_usage,0.9980070153061225},
{mbcs_usage,0.6770963446791575},
{sbcs_block_size,600912},
{sbcs_carriers_size,602112},
{mbcs_block_size,169065768},
{mbcs_carriers_size,249692336}]},
{{eheap_alloc,7},
[{sbcs_usage,0.997382155987395},
{mbcs_usage,0.6925225022824623},
{sbcs_block_size,972296},
{sbcs_carriers_size,974848},
{mbcs_block_size,167834424},
{mbcs_carriers_size,242352304}]},
{{ll_alloc,0},
[{sbcs_usage,1.0},
{mbcs_usage,0.7387279228243809},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,112706224},
{mbcs_carriers_size,152567976}]},
{{binary_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7614033191804973},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,58507096},
{mbcs_carriers_size,76841136}]},
{{binary_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.7179048085736076},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,46131288},
{mbcs_carriers_size,64258224}]},
{{binary_alloc,7},
[{sbcs_usage,1.0},
{mbcs_usage,0.6128136272843548},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,27651200},
{mbcs_carriers_size,45121712}]},
{{binary_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.6492102167567332},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,32186648},
{mbcs_carriers_size,49578160}]},
{{binary_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.7715637758298944},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,56051664},
{mbcs_carriers_size,72646832}]},
{{binary_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.7514879308127178},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,49077272},
{mbcs_carriers_size,65306800}]},
{{binary_alloc,6},
[{sbcs_usage,1.0},
{mbcs_usage,0.6757064168943689},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25706456},
{mbcs_carriers_size,38043824}]},
{{binary_alloc,8},
[{sbcs_usage,1.0},
{mbcs_usage,0.7016146506167494},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,25956408},
{mbcs_carriers_size,36995248}]},
{{fix_alloc,4},
[{sbcs_usage,1.0},
{mbcs_usage,0.7409146075507547},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,22748888},
{mbcs_carriers_size,30703792}]},
{{fix_alloc,2},
[{sbcs_usage,1.0},
{mbcs_usage,0.8581522751225302},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,33547232},
{mbcs_carriers_size,39092400}]},
{{fix_alloc,3},
[{sbcs_usage,1.0},
{mbcs_usage,0.8630094940716118},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,26497664},
{mbcs_carriers_size,...}]},
{{driver_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.7615924083651237},
{sbcs_block_size,0},
{sbcs_carriers_size,0},
{mbcs_block_size,...},
{...}]},
{{fix_alloc,1},
[{sbcs_usage,1.0},
{mbcs_usage,0.8947156992151927},
{sbcs_block_size,0},
{sbcs_carriers_size,...},
{...}|...]},
{{fix_alloc,5},
[{sbcs_usage,1.0},
{mbcs_usage,0.7166474590927997},
{sbcs_block_size,...},
{...}|...]},
{{ll_alloc,7},[{sbcs_usage,1.0},{mbcs_usage,...},{...}|...]},
{{driver_alloc,2},[{sbcs_usage,...},{...}|...]},
{{driver_alloc,4},[{...}|...]},
{{ll_alloc,...},[...]},
{{...},...},
{...}|...]
Unless I'm mistaken reading this data, everything looks fine there, with
normal usages.
What can I do else to address this issue?
Thank you for your help.
r.
Michael Truog
2015-01-23 18:47:29 UTC
Permalink
Post by Roberto Ostinelli
Dear List,
I'm having some troubles in pinpointing why a node is crashing due to memory issues.
For info, when it crashes, it does not produce a crash dump. However I've monitored live and I've seen the .beam process eat up all memory until it abruptly exits.
The system is a big router that relays data coming from TCP connections, into other TCP connections.
I'm using cowboy as the HTTP server that initiates the long-lived TCP connections.
You have an Erlang architectural problem due to how your processes hold onto old binary references based on your other posts (you are using long-lived processes which process binaries quick enough that they cause excessive memory consumption). For an architectural problem fullsweep_after, hibernate, and calling erlang:garbage_collect/0 are not solutions, they are just delaying the inevitable death of your Erlang node due to the throughput overloading your source code (in addition to the Erlang VM memory tweaks described at https://blog.heroku.com/archives/2013/11/7/logplex-down-the-rabbit-hole). Those things are what you think about once you get source code (an architecture) that works. You need to make sure you use temporary Erlang processes when excessive binary garbage is created, so that GC is done quickly (the Erlang node will not be overloaded then, accumulating memory).

If you don't believe me, this is already proven in CloudI. The 1.4.0 loadtests shows a situation similar to your scenario: many HTTP cowboy connections sending data into other TCP connections (http://cloudi.org/faq.html#5_LoadTesting). The cowboy connections are handled by a CloudI service called cloudi_service_http_cowboy and I use Tsung to send HTTP traffic (20000 connections doing 10000 requests/second) to a single TCP connection bottleneck because it is most useful to test bottlenecks (in CloudI, this is a service that is configured with a process count and thread count of 1). The service process count and the thread count (used by non-Erlang (external) services) can easily be increased to increase the number of TCP connections used by an external service (where the service instance total TCP connections count is count_process * count_thread). These TCP connections are what the CloudI API uses in OS processes to facilitate external services, so I am describing CloudI
details that relate to your problem.

If you were to solve this problem using CloudI's service abstraction you would be using either cloudi_service_tcp or your own internal CloudI service (an Erlang or Elixir service) to facilitate your own TCP connections with your specific configuration and processing you need (so that depends on business logic). The reason CloudI doesn't have problems in internal services when creating lots of binary garbage is due to using temporary processes for service request processing. That is controlled by a service configuration option called 'request_pid_uses' (after processing X service requests, create a new temporary process... the setting defaults to 1 so each service request uses a new temporary process while still keeping the service's processing transactional: http://cloudi.org/api.html#2_services_add_config_opts). To see this benefit in a simpler way, there are some results that show how an Erlang service can facilitate large throughput based on how many service processes
are used: https://github.com/CloudI/CloudI/blob/develop/src/tests/request_rate/results/results_v1_4_0/results.txt#L26-L46 . That testing is separate from the Tsung/HTTP loadtests and is focused on service request traffic between two CloudI services, both internal Erlang services, showing the maximum throughput facilitated with specific service configuration options. The higher throughput is using a 'lazy' destination refresh method to avoid contention on process lookup, so using cached data (the 'lazy' setting is set on the sending service in its service configuration: http://cloudi.org/api.html#1_Intro_dest).

Reusing CloudI is easier and simpler than experiencing these NIH-syndrome problems you have described.
Ulf Wiger
2015-01-23 19:55:44 UTC
Permalink
This post might be inappropriate. Click to display it.
Roberto Ostinelli
2015-01-23 20:40:28 UTC
Permalink
Hey Ulf!
Thank you for your input.

What do you mean with "are you using min_heap_size"?
Post by Ulf Wiger
Post by Roberto Ostinelli
{<0.428.0>,[],142896},
{<0.429.0>,[],142896},
{<0.430.0>,[],142896}]
See the last processes there with all identical memory? These are the processes handling the connections, and they stay stable with the same identical number throughout all test.
Are you using min_heap_size on these?
One thing we stumbled across fairly early on in the exometer development was that memory increased until the node ran out of memory. What was needed was to lower the fullsweep_after threshold for processes that had an increased min_heap_size. The default fullsweep_after is very high, and what can happen is that the old_heap grows a lot between the fullsweeps.
In our case, {fullsweep_after, 10} was sufficient to solve the problem.
You did say that you’d try applying fullsweep_after selectively, but wasn’t sure if you tried this.
BR,
Ulf W
Ulf Wiger, Co-founder & Developer Advocate, Feuerlabs Inc.
http://feuerlabs.com
Tuncer Ayaz
2015-01-23 20:53:55 UTC
Permalink
Post by Roberto Ostinelli
Hey Ulf!
Thank you for your input.
What do you mean with "are you using min_heap_size"?
See erlang:spawn_opt/3 or erlang:process_flag/2.
Roberto Ostinelli
2015-01-23 21:14:07 UTC
Permalink
oh ok so the question was if I'm setting it to a custom value?

No I'm not. Only fullsweep_after.
Post by Tuncer Ayaz
Post by Roberto Ostinelli
Hey Ulf!
Thank you for your input.
What do you mean with "are you using min_heap_size"?
See erlang:spawn_opt/3 or erlang:process_flag/2.
Loading...