made formatting of log messages more customizable

mojolicious · May 15, 2014 · f6488e5 · f6488e5
1 parent 94b9cfe
commit f6488e5
Show file tree

Hide file tree

Showing 6 changed files with 58 additions and 30 deletions.
diff --git a/Changes b/Changes
@@ -3,9 +3,14 @@
   - Code name "Tiger Face", this is a major release.
   - Changed heuristics for number detection in Mojo::JSON to better line up
     with user expectations.
+  - Changed lock and unlock callbacks in Mojo::IOLoop to not receive an
+    invocant.
   - Removed deprecated support for "X-Forwarded-HTTPS".
   - Removed generate_port method from Mojo::IOLoop.
+  - Removed format method from Mojo::Log.
+  - Added format attribute to Mojo::Log.
   - Added no_compression method to Mojo::Transaction::WebSocket.
+  - Added append method to Mojo::Log.
   - Fixed Mojo::IOLoop::Server to work correctly with newer versions of
     IO::Socket::SSL. (noxxi)
   - Fixed warnings in Mojo::IOLoop::Delay.

diff --git a/lib/Mojo/IOLoop.pm b/lib/Mojo/IOLoop.pm
@@ -157,7 +157,7 @@ sub _accepting {
   return unless $i < $max;
 
   # Acquire accept mutex
-  if (my $cb = $self->lock) { return unless $self->$cb(!$i) }
+  if (my $cb = $self->lock) { return unless $cb->(!$i) }
   $self->_remove(delete $self->{accept});
 
   # Check if multi-accept is desirable
@@ -185,7 +185,7 @@ sub _not_accepting {
   # Release accept mutex
   return unless delete $self->{accepting};
   return unless my $cb = $self->unlock;
-  $self->$cb;
+  $cb->();
 
   $_->stop for values %{$self->{acceptors} || {}};
 }
@@ -345,7 +345,7 @@ processes. The callback should return true or false. Note that exceptions in
 this callback are not captured.
 
   $loop->lock(sub {
-    my ($loop, $blocking) = @_;
+    my $blocking = shift;
 
     # Got the accept mutex, start accepting new connections
     return 1;

diff --git a/lib/Mojo/Log.pm b/lib/Mojo/Log.pm
@@ -5,6 +5,7 @@ use Carp 'croak';
 use Fcntl ':flock';
 use Mojo::Util 'encode';
 
+has format => sub { \&_format };
 has handle => sub {
 
   # File
@@ -25,16 +26,19 @@ has 'path';
 # Supported log level
 my $LEVEL = {debug => 1, info => 2, warn => 3, error => 4, fatal => 5};
 
+sub append {
+  my ($self, $msg) = @_;
+
+  return unless my $handle = $self->handle;
+  flock $handle, LOCK_EX;
+  $handle->print(encode('UTF-8', $msg)) or croak "Can't write to log: $!";
+  flock $handle, LOCK_UN;
+}
+
 sub debug { shift->log(debug => @_) }
 sub error { shift->log(error => @_) }
 sub fatal { shift->log(fatal => @_) }
 
-sub format {
-  my ($self, $level, @lines) = @_;
-  return encode 'UTF-8',
-    '[' . localtime(time) . "] [$level] " . join("\n", @lines, '');
-}
-
 sub info { shift->log(info => @_) }
 
 sub is_debug { shift->is_level('debug') }
@@ -59,19 +63,21 @@ sub new {
 
 sub warn { shift->log(warn => @_) }
 
+sub _format {
+  '[' . localtime(shift) . '] [' . shift . '] ' . join("\n", @_, '');
+}
+
 sub _message {
   my ($self, $level) = (shift, shift);
 
-  return unless $self->is_level($level) && (my $handle = $self->handle);
+  return unless $self->is_level($level);
 
   my $max     = $self->max_history_size;
   my $history = $self->history;
-  push @$history, [time, $level, @_];
+  push @$history, my $msg = [time, $level, @_];
   shift @$history while @$history > $max;
 
-  flock $handle, LOCK_EX;
-  $handle->print($self->format($level, @_)) or croak "Can't write to log: $!";
-  flock $handle, LOCK_UN;
+  $self->append($self->format->(@$msg));
 }
 
 1;
@@ -127,6 +133,18 @@ Emitted when a new message gets logged.
 
 L<Mojo::Log> implements the following attributes.
 
+=head2 format
+
+  my $cb = $log->format;
+  $log   = $log->format(sub {...});
+
+A callback for formatting log messages.
+
+  $log->format(sub {
+    my ($time, $level, @lines) = @_;
+    ...
+  });
+
 =head2 handle
 
   my $handle = $log->handle;
@@ -171,6 +189,12 @@ Log file path used by L</"handle">.
 L<Mojo::Log> inherits all methods from L<Mojo::EventEmitter> and implements
 the following new ones.
 
+=head2 append
+
+  $log->append($msg);
+
+Append message to L</"handle">.
+
 =head2 debug
 
   $log = $log->debug('You screwed up, but that is ok.');
@@ -192,13 +216,6 @@ Log error message.
 
 Log fatal message.
 
-=head2 format
-
-  my $msg = $log->format(debug => 'Hi there!');
-  my $msg = $log->format(debug => 'Hi', 'there!');
-
-Format log message.
-
 =head2 info
 
   $log = $log->info('You are bad, but you prolly know already.');

diff --git a/lib/Mojo/Server/Prefork.pm b/lib/Mojo/Server/Prefork.pm
@@ -177,7 +177,7 @@ sub _spawn {
 
       # Blocking ("ualarm" can't be imported on Windows)
       my $lock;
-      if ($_[1]) {
+      if ($_[0]) {
         eval {
           local $SIG{ALRM} = sub { die "alarm\n" };
           my $old = Time::HiRes::ualarm $self->lock_timeout * 1000000;

diff --git a/lib/Mojolicious/templates/development.html.ep b/lib/Mojolicious/templates/development.html.ep
@@ -296,12 +296,9 @@
         <div id="log" class="box infobox spaced">
           <table>
             % for my $msg (@{app->log->history}) {
-              % my ($time, $level, @lines) = @$msg;
-              % $time = localtime $time;
-              % my $lines = join "\n", @lines;
               <tr>
                 <td class="striped value wide">
-                  <pre>[<%= $time %>] [<%= $level %>] <%= $lines %></pre>
+                  <pre><%= app->log->format->(@$msg) %></pre>
                 </td>
               </tr>
             % }

diff --git a/t/mojo/log.t b/t/mojo/log.t
@@ -37,14 +37,23 @@ like $content, qr/\[.*\] \[debug\] Works too\.\n/, 'right debug message';
 
 # Formatting
 $log = Mojo::Log->new;
-like $log->format(debug => 'Test 123.'), qr/^\[.*\] \[debug\] Test 123\.\n$/,
-  'right format';
-like $log->format(qw(debug Test 1 2 3)),
+like $log->format->(time, 'debug', 'Test 123.'),
+  qr/^\[.*\] \[debug\] Test 123\.\n$/, 'right format';
+like $log->format->(time, 'debug', qw(Test 1 2 3)),
   qr/^\[.*\] \[debug\] Test\n1\n2\n3\n$/, 'right format';
-like decode('UTF-8', $log->format(error => 'I ♥ Mojolicious.')),
+like $log->format->(time, 'error', 'I ♥ Mojolicious.'),
   qr/^\[.*\] \[error\] I ♥ Mojolicious\.\n$/, 'right format';
+$log->format(
+  sub {
+    my ($time, $level, @lines) = @_;
+    return join ':', $level, $time, @lines;
+  }
+);
+like $log->format->(time, 'debug', qw(Test 1 2 3)),
+  qr/^debug:\d+:Test:1:2:3$/, 'right format';
 
 # Events
+$log = Mojo::Log->new;
 my $msgs = [];
 $log->unsubscribe('message')->on(
   message => sub {