log4erl performance

[odi]

hi,
I tried to test performance of log4erl compared to error_logger
logging system. During test I noticed that it would be nice to be able
to turn rotation of files off - it takes some time to check file's
size each time when a message is logged.
I testes error_logger from erlang 5.6.5 (kernel-2.12.5,
stdlib-1.15.5), log4erl-0.8.4 and log4erl-0.8.6 both with and without
rotation. Below are results and source code for test. Logging time in
test is a time diff between start and end of the test while summary
log time is a time measured when all messages were actually logged to
a file on disk.

Logging system rotation logging time in test summary log
time
-----------------------------------------------------------------------------------------------------
error_logger --- 150ms 63s
log4erl-0.8.4 on 594ms 170s
log4erl-0.8.4 off 563ms 75s
log4erl-0.8.6 on 9s 34s
log4erl-0.8.6 off 5s
30s
-----------------------------------------------------------------------------------------------------

Introducing synchronous logging caused speedup in logging file to a
disk but logging time in test is much greater.

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
% log_test source code
-module(log_test).

-export([log4erl/2, error_logger/2]).

log4erl(Count, Size)->
application:start(log4erl),
%log4erl:add_logger(messages_log),
log4erl:add_file_appender(file, {"../logs", "log4erl", {size,
100000000}, 4, "txt", all}),
log4erl:change_format(file, "%j %T [%L] %l%n"),
Msg = create_msg(Size),
Now = erlang:now(),
io:format("Started logging ~p messages of ~p bytes with
log4erl...~n", [Count, Size]),
do_log(Count, log4erl, info, Msg, Now).

error_logger(Count, Size)->
error_logger:tty(false),
error_logger:logfile({open, "../logs/error_logger.txt"}),
Msg = create_msg(Size),
Now = erlang:now(),
io:format("Started logging ~p messages of ~p bytes with
error_logger...~n", [Count, Size]),
do_log(Count, error_logger, info_msg, Msg, Now).

do_log(0, Module, _Function, _Msg, StartTime) ->
Now = erlang:now(),
Diff = timer:now_diff(Now, StartTime),
io:format("~p logging took ~p ms~n", [Module, Diff/1000]);
do_log(Count, Module, Function, Msg, StartTime) ->
apply(Module, Function, ["~p", [Msg]]),
do_log(Count - 1, Module, Function, Msg, StartTime).

create_msg(Size) ->
create_msg(Size, []).

create_msg(0, Msg) ->
Msg;
create_msg(Size, Msg) ->
Letter = random:uniform(26) + 96,
create_msg(Size - 1, lists:append(Msg, [Letter])).

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%

regards,
Kuba

[Ahmed Ali]

Hi Kuba,

Thanks for the benchmark. I am not very happy with the results of them
though. I'll repeat them and report back to the list with my results
as well. It seems that we can learn/cheat from error_logger. Depending
on this, I might consider re-writing file_appender for next version
instead of the db_appender I was planning.

BTW, what hardware did you use in this benchmark? More info is appreciated.

Regards,

Ahmed

[odi]

I used my PC -
hardware: Core 2 Duo E6550 @ 2.33GHz, 4GB of RAM, Samsung HD161HJ
disk,
software: Windows XP SP2, erlang 5.6.5

I didn't know how to check when logging to disk is finished so the
results are not accurate.

have a nice day;)
Kuba

On 6 Maj, 23:16, Ahmed Ali <ahmed.naw...@gmail.com> wrote:
> Hi Kuba,
>
> Thanks for the benchmark. I am not very happy with the results of them
> though. I'll repeat them and report back to the list with my results
> as well. It seems that we can learn/cheat from error_logger. Depending
> on this, I might consider re-writing file_appender for next version
> instead of the db_appender I was planning.
>
> BTW, what hardware did you use in this benchmark? More info is appreciated.
>
> Regards,
>
> Ahmed
>