polettix

I don't remember whether I blogged about Dancer::Logger::Log4perl or not, but a recent post by Ovid in Dancer's mailing list made me think that it would fit his use case. Unfortunately it seems that some of my messages did not make it into the mailing list (I didn't find them in the archived thread, anyway), so I'm blogging it here for a wider audience to bother.

If I understood Ovid's needs correctly, he needs an additional logging level in Dancer that allows to pass messages whatever the log level. Apart from the semantic level considerations here, the use case seemed to fit perfectly with using Log::Log4perl because it has a wide range of logging levels and the possibility to separate different logs in different parts.

A possible proof-of-concept is the following example:

#!/usr/bin/env perl
use strict;
use warnings;

use Dancer;
use Log::Log4perl qw< :easy >;

setting log4perl => {
   tiny => 0,
   config => '
      log4perl.logger                      = DEBUG, OnFile, OnScreen
      log4perl.appender.OnFile             = Log::Log4perl::Appender::File
      log4perl.appender.OnFile.filename    = sample-debug.log
      log4perl.appender.OnFile.mode        = append
      log4perl.appender.OnFile.layout      = Log::Log4perl::Layout::PatternLayout
      log4perl.appender.OnFile.layout.ConversionPattern = [%d] [%5p] %m%n
      log4perl.appender.OnScreen           = Log::Log4perl::Appender::ScreenColoredLevels
      log4perl.appender.OnScreen.color.ERROR = bold red
      log4perl.appender.OnScreen.color.FATAL = bold red
      log4perl.appender.OnScreen.color.OFF   = bold green
      log4perl.appender.OnScreen.Threshold = ERROR
      log4perl.appender.OnScreen.layout    = Log::Log4perl::Layout::PatternLayout
      log4perl.appender.OnScreen.layout.ConversionPattern = [%d] >>> %m%n
   ',
};
setting logger => 'log4perl';

get '/' => sub {
   warning 'just a plain warning here';
   error 'just a plain error here';
   content_type 'text/plain';
   return "normal here\n";
};

get '/special' => sub {
   debug 'inside special...';
   ALWAYS 'this is a special BUSINESS-LOGIC message!';
   warning 'inside special...';
   content_type 'text/plain';
   return "special here\n";
};

dance();

Having the full power of Log::Log4perl's configuration capabilities allows sending all the log messages to a file, while keeping the most important ones on the screen. Additionally, the usage of the ALWAYS stealth logger - which sends messages at the OFF logging level - also allows being sure that they are - guess what? - ALWAYS emitted whatever the log level.

As a nice add-on, these messages (that are business-logic related) can be visually distinguished on the terminal from e.g. error messages: in the example, ERRORs are shown in red, while ALWAYS messages are shown in light green. This is an example of what is shown on the screen:

$ perl sample.pl -p 3333

Dancer 1.3093 server 32177 listening on http://0.0.0.0:3333
== Entering the development dance floor ...
[2012/03/28 19:08:03] >>> just a plain error here
[2012/03/28 19:08:04] >>> this is a special BUSINESS-LOGIC message!

and, of course, the file contains the full log:

[2012/03/28 19:23:18] [ INFO] loading Dancer::Handler::Standalone handler
[2012/03/28 19:23:18] [ INFO] loading handler 'Dancer::Handler::Standalone'
[2012/03/28 19:23:25] [ INFO] request: GET / from 127.0.0.1
[2012/03/28 19:23:25] [ INFO] Trying to match 'GET /' against /^\/$/ (generated from '/')
[2012/03/28 19:23:25] [ INFO]   --> got 1
[2012/03/28 19:23:25] [ WARN] just a plain warning here
[2012/03/28 19:23:25] [ERROR] just a plain error here
[2012/03/28 19:23:25] [ INFO] response: 200
[2012/03/28 19:23:28] [ INFO] request: GET /special from 127.0.0.1
[2012/03/28 19:23:28] [ INFO] Trying to match 'GET /special' against /^\/$/ (generated from '/')
[2012/03/28 19:23:28] [ INFO] Trying to match 'GET /special' against /^\/special$/ (generated from '/special')
[2012/03/28 19:23:28] [ INFO]   --> got 1
[2012/03/28 19:23:28] [DEBUG] inside special...
[2012/03/28 19:23:28] [  OFF] this is a special BUSINESS-LOGIC message!
[2012/03/28 19:23:28] [ WARN] inside special...
[2012/03/28 19:23:28] [ INFO] response: 200

So, if you want all the power of Log::Log4perl while playing with Dancer... be sure to check Dancer::Logger::Log4perl out!