March 2012 Archives

Logging in Dancer

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!

Sets operations

To help some coworkers I whipped up a program to perform set operations in Perl. It's quite basic but it's been pretty effective so far and it's on github.

Sets are assumed to be files where each line is a different element. It is assumed that equal lines are either not present or can be filtered out with no consequence. The inner working assumes that at a certain point the input files are sorted, and in general the external sort program is used automatically, which limits the applicability in some platforms.

The three basic operations that are supported are union, intersection and difference.

# intersect two files, also with "intersect", "i",
# "I" (uppercase "i") and "^"
sets file1 & file2

# union of two files, also with "union", "u", "U",
# "v", "V" and "|"
sets file1 + file2

# subtraction of second file from first one, also
# with "minus", "less" and "\"
sets file1 - file2

Other operations, e.g. symmetric difference, can be obtained with a combination of the predefined ones. Operations can be grouped and in general the expression will be provided as a single string to avoid the shell to creep in:

# symmetric difference, alternative 1
sets '(file1 - file2) + (file2 - file1)'

# symmetric difference, how you probably saw it somewhere
sets '(file1 + file2) - (file1 & file2)'

Operations associate from left to right, so the first group above is not needed. Anyway I usually prefer to be explicit.

As anticipated, at some point the program needs to work with a sorted input. The basic motivation for the program is handling operations on files with a few million elements, so putting all the stuff in memory is not an option; on the other hand, sort is quite efficient and reinventing the wheel is not an option as well!

Sorting is usually handled automatically with a call to the external sort utility (with the -u option, because sets are assumed to not contain duplicates); anyway, this can be a time consuming activity that is not necessary if you already know that your inputs are sorted, so you can tell the program when this is actually the case:

sets -s sorted-file1 ^ sorted-file2

When sorting is performed, it is usually done on the fly without saving the intermediate sorted files. They can be useful for following sets operations, or when the same input is used multiple times (e.g. in the case of the symmetric difference examples above), so it is possible to save the sorted files with the same name and a suffix appended:

sets -S .sorted '(file1 - file2) + (file2 - file1)'

If the sorted version of a file is found (i.e. file1.sorted and/or file2.sorted in the example above) it is used with no further sorting, speeding things up automatically.

Sometimes inputs might come from different platforms, so the line terminator would be different. In our case we don't need leading or trailing whitespaces, so there is a trimming options to avoid problems:

sets -t file1-unix - file2-dos

If you think that it can be useful for you, it's possible to download a bundled version that does not need external modules installed anywhere: enjoy sets!

About Flavio Poletti

user-pic I blog about Perl.