[erlang-questions] high-volume logging via a gen_server
Wed Oct 6 05:09:33 CEST 2010
On Tue, Oct 5, 2010 at 5:23 AM, Anthony Shipman <als@REDACTED> wrote:
> On Tue, 5 Oct 2010 06:42:17 am Mihai Balea wrote:
> > On Oct 4, 2010, at 2:57 PM, Dan Kelley wrote:
> > > So, what are good strategies to cope with a large incoming volume of
> > > messages that all need to wind up in the same logfile? Is there a more
> > > efficient way to write to disk than the simple io:format() call than
> > > using above? What's a good way to parallelize the logging over
> > > processes but keep all of the information in one file?
> You can have a buffer process ahead of the logger. The buffer process just
> to accept and store log requests. A separate write process can pull them
> the buffer (using an async protocol). If the buffer gets too full then you
> can have various policies such as discard oldest, youngest, low priority
> messages etc.
One thing I was surprised to find while profiling yesterday was that much of
the reason that logging was crippling my server was the CPU overhead of
io:format, io_lib:format, and the various calls required to get a high-res
timestamp. The way my router sets up right now, it takes ~15 microseconds
to parse a reasonably complicated protocol, but about ~100 microseconds to
compose and format the log line which says the parse has happened.
Per what others have suggested in this thread, I had thought that a possible
answer to my bottleneck would be to push as much of the logging work out to
the clients. That turned out to make per-transaction latency very poor for
the reason described above.
So for now, I've profiled the path which generates the log line strings and
have de-stupided my code a bit to bring the per-log-line latency down to ~60
Taking into account all the responses on the thread (thanks!), and in
conjunction with the formatting changes, I'm trying something like what you
describe: because it's an easy first step, I'm just replacing writing to
disk directly inside my logging gen_server with calls to disk_log:blog/2.
So far that's working well.
More information about the erlang-questions