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

Random May 20th, 2009

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.

Bringing logging to Moose with MooseX::Log::Log4perl

Random July 13th, 2008

Finally after some playing around and discovering the main concepts behind moose and failing to find a logging role using my favorite logging system log4perl I sat down an did a little coding (it is really just a few lines) and uploaded to CPAN as MooseX::Log::Log4perl.

As I already received some valuable feedback by Michael Schilli of Log4perl fame, the interface might change a little (staying backwards compatible) to be easier to use for small projects by using something like with MooseX::Log::Log4perl qw(:easy) to give you methods for log_error, log_warn, log_debug, … directly on your class instance.

If your interested see the open RT ticket 37655.

This module was actually written as part of my other project called QuikPlan, a course scheduling and management web application.