[erlang-questions] server state output in gen_server error logging
Scott Lystig Fritchie
Wed Apr 29 23:21:15 CEST 2009
Sorry about joining the thread so late...
Matthias Lang <matthias@REDACTED> wrote:
ml> I don't understand how _any_ production systems can work with the
ml> default error logging setup*. On the other hand, you're only the
ml> third person I've come across who agrees it's a problem, so maybe
ml> there's a simple solution I'm unaware of.
I'm the fourth, at least. Unless I'm included in the previous three
ml> * i.e. in a crash, arbitrary terms get printed and they can be huge.
ml> The problems with 'huge' are [...]
ml> (b) creating those huge logs can eat huge amounts of RAM, so much
ml> that on memory-limited systems the VM can terminate with
ml> out-of-memory [...]
The worst case I've seen (and it's happened in a production environment)
is a few tens of megabytes in a gen_server process's state term. The
proc crashes, and the OTP standard error handler formats it. However,
it gets much worse:
* The binary includes non-printable bytes, so it gets expanded from a
more compact <<"foo...">> to <<102,111,111,255,...>>. I.e. every
byte in the original is expanded to 3-4 bytes on average, don't
forget the commas :-).
* The formatted result is a one-char-per-element list.
* The platform in question is 64-bit, so each cons cell uses 2
words. Multiply the bloated formatted string's size by 16.
It only takes a few of those messages to consume *gigabytes* of RAM. My
production boxes had 16GB of RAM, but that wasn't nearly enough.
Matt was also correct in that it takes a lot of CPU time to do the
formatting. Too bad it doesn't always slow down the producers enough.
We haven't used his solution for truncating messages. Instead, our
custom event handler checks the size of the term via erts_debug:size/1
and, if it's too big, formats the term with io_lib:format/2 using a
format string "~P" plus a depth limit of 20, instead of whatever the
specified formatting string was.
More information about the erlang-questions