Refactor Logger module, allow specifying log format

Changes

@@ -8,6 +8,7 @@
             - Added charset, charset_encode, charset_decode methods to Kelp::Request
             - Added set_charset method to Kelp::Response
             - Added Kelp::Module::Encoder, a base class for encoders (to be used by the new get_encoder method)
+            - Added log_format, date_format configuration values to Kelp::Module::Logger
             - Module::Template now inserts an 'app' parameter to render variables unless 'app' is already provided
 
             [Changes]
@@ -21,6 +22,7 @@
             - Kelp::Test now has a new import flag: '-utf8'
               * Importing with this flag will automatically set Test::More to encode wide characters on output
             - Repeatedly fetching parameters from json request with the param method is now much faster
+            - Kelp::Module::Logger now sorts keys in Data::Dumper output
             - Documentation improvements
 
             [Bug fixes]

lib/Kelp/Module/Logger.pm

@@ -4,21 +4,41 @@ use Kelp::Base 'Kelp::Module';
 
 use Carp;
 use Log::Dispatch;
+use Time::Piece;
 use Data::Dumper;
 
+attr logger => undef;
+attr date_format => '%Y-%m-%d %T';
+attr log_format => '%s - %s - %s';
+
 sub _logger
 {
     my ($self, %args) = @_;
-    Log::Dispatch->new(%args);
+
+    return Log::Dispatch->new(%args);
+}
+
+sub load_configuration
+{
+    my ($self, %args) = @_;
+
+    for my $field (qw(date_format log_format)) {
+        $self->$field(delete $args{$field})
+            if $args{$field};
+    }
+
+    return %args;
 }
 
 sub build
 {
     my ($self, %args) = @_;
-    $self->{logger} = $self->_logger(%args);
 
-    # Register a few levels
-    my @levels_to_register = qw/debug info error/;
+    # load module config
+    %args = $self->load_configuration(%args);
+
+    # load logger with the rest of the config
+    $self->logger($self->_logger(%args));
 
     # Build the registration hash
     my %LEVELS = map {
@@ -27,9 +47,9 @@ sub build
             shift;
             $self->message($level, @_);
         };
-    } @levels_to_register;
+    } qw(debug info error);
 
-    # Register the log levels
+    # Register a few levels
     $self->register(%LEVELS);
 
     # Also register the message method as 'logger'
@@ -44,22 +64,17 @@ sub build
 sub message
 {
     my ($self, $level, @messages) = @_;
-    my @a = localtime(time);
-    my $date = sprintf(
-        "%4i-%02i-%02i %02i:%02i:%02i",
-        $a[5] + 1900,
-        $a[4] + 1,
-        $a[3], $a[2], $a[1], $a[0]
-    );
+    my $date = localtime->strftime($self->date_format);
 
-    for (@messages) {
-        $self->{logger}->log(
-            level => $level,
-            message => sprintf(
-                '%s - %s - %s',
-                $date, $level, ref($_) ? Dumper($_) : $_
-            )
-        );
+    local $Data::Dumper::Sortkeys = 1;
+    for my $message (@messages) {
+        $message = sprintf $self->log_format,
+            $date,
+            $level,
+            (ref $message ? Dumper($message) : $message),
+            ;
+
+        $self->logger->log(level => $level, message => $message);
     }
 }
 
@@ -102,6 +117,26 @@ Kelp::Module::Logger - Logger for Kelp applications
 This module provides an log interface for Kelp web application. It uses
 L<Log::Dispatch> as underlying logging module.
 
+=head1 CONFIGURATION
+
+In addition to configuration passed to L<Log::Dispatch>, following keys can be configured:
+
+=head2 date_format
+
+A string in L<strftime
+format|https://www.unix.com/man-page/FreeBSD/3/strftime/> which will be used to
+generate the date.
+
+By default, value C<'%Y-%m-%d %T'> is used.
+
+=head2 log_format
+
+A string in L<sprintf format|https://perldoc.perl.org/functions/sprintf> which
+will be used to generate the log. Three string values will be used in this
+string, in order: date, log level and the message itself.
+
+By default, value C<'%s - %s - %s'> is used.
+
 =head1 REGISTERED METHODS
 
 =head2 debug
@@ -110,4 +145,9 @@ L<Log::Dispatch> as underlying logging module.
 
 =head2 error
 
+=head2 logger
+
+C<< $app->logger(info => 'message') >> is equivalent to C<< $app->info('message') >>.
+
 =cut
+

t/module_logger.t

@@ -9,14 +9,14 @@ use Kelp;
 use Kelp::Test;
 use Test::More;
 use HTTP::Request::Common;
+use Path::Tiny qw(tempfile);
 
-# Levels
-{
+subtest 'testing log levels' => sub {
     my $app = Kelp->new(mode => 'nomod');
     my $m = $app->load_module('Logger');
 
     isa_ok $m, "Kelp::Module::Logger";
-    can_ok $app, $_ for qw/error debug/;
+    can_ok $app, $_ for qw/error debug info logger/;
 
     my $t = Kelp::Test->new(app => $app);
     $app->add_route(
@@ -25,11 +25,33 @@ use HTTP::Request::Common;
             my $self = shift;
             $self->debug("Debug message");
             $self->error("Error message");
+            $self->info("Info message");
             $self->logger('critical', "Critical message");
             "ok";
         }
     );
     $t->request(GET '/log')->code_is(200);
-}
+};
+
+subtest 'testing log output' => sub {
+    my $app = Kelp->new(mode => 'nomod');
+    my $file = tempfile;
+    my $m = $app->load_module(
+        'Logger',
+        outputs => [
+            [
+                'File',
+                min_level => 'debug',
+                filename => "$file",
+            ],
+        ]
+    );
+
+    $app->logger(info => 'test logging output');
+    my $contents = $file->slurp;
+    like $contents, qr/test logging output/, 'log message ok';
+    note $contents;
+};
 
 done_testing;
+