[erlang-questions] Low disk logging performance in SMP
chaitanya Chalasani
chaitanya.chalasani@REDACTED
Mon Apr 27 07:36:08 CEST 2009
Thank you very much it works great.
We are using gen_event with multiple file logging handlers for each
module and also simultaneous logging into different files for debug,
normal and panic messages. In this case we have to use selective
receive.
I think this suffices our logging hunger of about 1000 transactions/sec.
I need to test more for further scaling.
On Fri, 2009-04-24 at 22:19 +0200, Hynek Vychodil wrote:
> It seems that block counting is not necessary. I'm taking same
> performance (~5MB/s measured at 10 million messages) even this
> version:
>
> -module(testLogger).
>
> -compile(inline).
>
> -export([listener/1, start/1, write/2]).
>
> start(Filename) ->
> Pid = spawn(?MODULE, listener, [Filename]),
> register(?MODULE, Pid).
>
> listener(Filename) ->
> case file:open(Filename, [append, raw]) of
> {ok, Fd} -> listener(Fd, 0, []);
> {error, Reason} -> error_logger:error_msg(Reason)
> end.
>
> listener(Fd, N, [] = SoFar) ->
> receive
> {data, Data} -> listener(Fd, N + 1, [Data]);
> {count, From} ->
> From ! {count, N}, listener(Fd, N, SoFar);
> stop -> ok;
> Msg ->
> io:format("Unexpected message: ~p~n", [Msg]),
> listener(Fd, N, SoFar)
> end;
> listener(Fd, N, SoFar) ->
> receive
> {data, Data} -> listener(Fd, N + 1, [Data | SoFar]);
> {count, From} ->
> From ! {count, N}, listener(Fd, N, SoFar);
> stop -> ok;
> Msg ->
> io:format("Unexpected message: ~p~n", [Msg]),
> listener(Fd, N, SoFar)
> after 0 -> flush(Fd, N, SoFar)
> end.
>
> flush(Fd, N, Data) ->
> file:write(Fd, lists:reverse(Data)),
> listener(Fd, N, []).
>
> write(_Data, 0) -> ok;
> write(Data, N) ->
> (?MODULE) ! {data, Data}, write(Data, N - 1).
>
>
> On Fri, Apr 24, 2009 at 8:32 PM, Hynek Vychodil
> <vychodil.hynek@REDACTED> wrote:
>
> Try this one, I guess you will be surprised ;-)
>
> -define(BS, 65536).
>
> start(Filename) ->
> Pid = spawn(?MODULE, listener, [Filename]),
> register(?MODULE, Pid).
>
> listener(Filename) ->
> case file:open(Filename, [append, raw]) of
> {ok, Fd} -> listener(Fd, 0, [], 0);
>
>
> {error, Reason} -> error_logger:error_msg(Reason)
> end.
>
>
>
> listener(Fd, N, [] = SoFar, 0) ->
> receive
> {data, Data} ->
> listener(Fd, N + 1, [Data], iolist_size(Data));
> {count, From} ->
> From ! {count, N}, listener(Fd, N, SoFar, 0);
> stop -> ok;
>
>
> Msg ->
> io:format("Unexpected message: ~p~n", [Msg]),
>
>
> listener(Fd, N, SoFar, 0)
> end;
> listener(Fd, N, SoFar, S) when S > (?BS) ->
> file:write(Fd, lists:reverse(SoFar)),
> listener(Fd, N, [], 0);
> listener(Fd, N, SoFar, S) ->
> receive
> {data, Data} ->
> listener(Fd, N + 1, [Data | SoFar],
> S + iolist_size(Data));
> {count, From} ->
> From ! {count, N}, listener(Fd, N, SoFar, S);
> stop -> ok;
>
>
> Msg ->
> io:format("Unexpected message: ~p~n", [Msg]),
>
>
> listener(Fd, N, SoFar, S)
> after 0 ->
> file:write(Fd, lists:reverse(SoFar)),
> listener(Fd, N, [], 0)
> end.
>
> write(_Data, 0) -> ok;
> write(Data, N) ->
> (?MODULE) ! {data, Data}, write(Data, N - 1).
>
>
> On Fri, Apr 24, 2009 at 4:23 PM, chaitanya Chalasani
> <chaitanya.chalasani@REDACTED> wrote:
>
>
> Hi,
>
> I am facing performance issue with my file logger. The
> file logger is an event handler holding the file
> reference is its state. The performance of the module
> is way ahead in the smp disabled erl shell compared
> with default smp enabled erl shell.
>
> I tried ...
> case#1
> Erlang R13B (erts-5.7.1) [source] [rq:1]
> [async-threads:0] [hipe] [kernel-poll:false]
>
> Eshell V5.7.1 (abort with ^G)
> 1> testLogger:start("test.log").
> true
> 2> testLogger:write("Testing...",1000000).
> {ok,done}
> 3>
>
> and
>
> case#2
> Erlang R13B (erts-5.7.1) [source] [smp:2:2] [rq:2]
> [async-threads:0] [hipe] [kernel-poll:false]
>
> Eshell V5.7.1 (abort with ^G)
> 1> testLogger:start("test.log").
> true
> 2> testLogger:write("Testing...",1000000).
> {ok,done}
> 3>
>
>
> What I observed was -
> Case 1:
> 1. The testLogger:write("Testing...",1000000) did
> not return back the control to the shell until all the
> messages are written to log.
> 2. The data was written at 400 KB/s
>
> Case 2:
> 1. The testLogger:write("Testing...",1000000)
> return back the control to the shell with {ok, done}
> after a short while but the messages where being
> written to log even after that.
> 2. The data was written at 4 KB/s
> 3. I checked in the pman tool it shows current
> funtion as io:wait_io_mon_reply/2 and the messages in
> the message pool are about 880k.
>
> Below is the code which I tested.
>
> start(Filename) ->
> register(testLogger,spawn(testLogger,listener,[Filename])).
>
> listener(Filename) ->
> case file:open(Filename,[append]) of
> {ok,Fd} -> listener(Fd,0);
> {error,Reason} -> error_logger:error_msg(Reason)
> end.
>
> listener(Fd,N) ->
> receive
> {data,Data} -> file:write(Fd,Data), listener(Fd,N+1);
> {count,From} -> From ! {count,N}, listener(Fd,N);
> {stop,From} -> From ! {stop,success}
> end.
>
> write(_Data,0) -> {ok,done};
> write(Data,N) -> testLogger ! {data,Data},
> write(Data,N-1).
>
> Is there a problem with my code or is it a known
> issue?
>
> ------
> CHAITANYA CHALASANI
>
>
>
> _______________________________________________
> erlang-questions mailing list
> erlang-questions@REDACTED
> http://www.erlang.org/mailman/listinfo/erlang-questions
>
>
>
>
>
>
>
> --
> --Hynek (Pichi) Vychodil
>
> Analyze your data in minutes. Share your insights instantly.
> Thrill your boss. Be a data hero!
> Try Good Data now for free: www.gooddata.com
>
>
>
>
>
> --
> --Hynek (Pichi) Vychodil
>
> Analyze your data in minutes. Share your insights instantly. Thrill
> your boss. Be a data hero!
> Try Good Data now for free: www.gooddata.com
------
CHAITANYA CHALASANI
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://erlang.org/pipermail/erlang-questions/attachments/20090427/79a8c1b8/attachment.htm>
More information about the erlang-questions
mailing list