Add benchmarking tests to MooseX::Log::Log4perl to verify overhead

After a while I had the chance to get back to MooseX::Log::Log4perl, which is Role (based on Moose) that can be easily reused in classes requiring logging functionality.

While it is really simple to use, I still found myself often directly using the default logger approach by creating a class variable and using that. So instead of:

use Moose;
with MooseX::Log::Log4perl;
sub whatever {
 my $self = shift;
 $self->log->debug("Here I am") if $self->log->is_debug;
}

mostly the direct logger was used in the classes.

 
use Log::Log4perl;
use vars qw($log);
$log = Log::Log4perl->get_logger(__PACKAGE__);
sub whatever {
 my $self = shift;
 $log->debug("Here I am") if $log->is_debug;
}

One reason was that during that time I optimized for speed and found a hotspot to be the additional method call for the “log” method. As perl has some overhead in calling functions, this still holds true to some extend, so that’s why I added a benchmarking test to the testsuite of MooseX::Log::Log4perl.

So if you have the chance, I’d like to see if in your test environment still the performance limits (keep overhead lower than 5% compared to using Log::Log4perl directly). To run the test simply get the sources and run the test.

cpan> look MooseX::Log::Log4perl
shell# TEST_MAINT=1 prove -l -v t/99_bench.t
t/99bench.t .. 
1..6
ok 1 - Bench instance for MooseX::Log::Log4perl isa BenchMooseXLogLog4perl
ok 2 - Bench instance for Log::Log4perl isa BenchLogLog4perl
 Rate MooseX-L4p log MooseX-L4p logger Log4perl method Log4perl direct
MooseX-L4p log 21235/s -- -0% -4% -6%
MooseX-L4p logger 21273/s 0% -- -4% -6%
Log4perl method 22102/s 4% 4% -- -2%
Log4perl direct 22535/s 6% 6% 2% --
...

If all tests pass you stayed within the limits (around 95% compared to using Log4perl directly). I’d like to see your results. So please comment on it and add the comparison table to it.