prettier logs
[catagits/Catalyst-Runtime.git] / lib / Catalyst / Engine.pm
index e5d2b10..13fcdc0 100644 (file)
@@ -3,11 +3,13 @@ package Catalyst::Engine;
 use strict;
 use base qw/Class::Data::Inheritable Class::Accessor::Fast/;
 use UNIVERSAL::require;
+use CGI::Cookie;
 use Data::Dumper;
 use HTML::Entities;
 use HTTP::Headers;
 use Memoize;
 use Time::HiRes qw/gettimeofday tv_interval/;
+use Text::ASCIITable;
 use Tree::Simple;
 use Tree::Simple::Visitor::FindByPath;
 use Catalyst::Request;
@@ -115,6 +117,41 @@ sub error {
     return $c->{error};
 }
 
+=item $c->execute($class, $coderef)
+
+Execute a coderef in given class and catch exceptions.
+Errors are available via $c->error.
+
+=cut
+
+sub execute {
+    my ( $c, $class, $code ) = @_;
+    $class = $c->comp($class) || $class;
+    $c->state(0);
+    my $callsub = ( caller(1) )[3];
+    eval {
+        if ( $c->debug )
+        {
+            my $action = $c->actions->{reverse}->{"$code"};
+            $action = "/$action" unless $action =~ /\-\>/;
+            $action = "    $action" if $callsub =~ /forward$/;
+            my ( $elapsed, @state ) =
+              $c->benchmark( $code, $class, $c, @{ $c->req->args } );
+            push @{ $c->{stats} }, [ $action, sprintf( '%fs', $elapsed ) ];
+            $c->state(@state);
+        }
+        else { $c->state( &$code( $class, $c, @{ $c->req->args } ) ) }
+    };
+    if ( my $error = $@ ) {
+        chomp $error;
+        $error = qq/Caught exception "$error"/;
+        $c->log->error($error);
+        $c->error($error) if $c->debug;
+        $c->state(0);
+    }
+    return $c->state;
+}
+
 =item $c->finalize
 
 Finalize request.
@@ -124,26 +161,76 @@ Finalize request.
 sub finalize {
     my $c = shift;
 
-    if ( my $location = $c->res->redirect ) {
+    $c->finalize_cookies;
+
+    if ( my $location = $c->response->redirect ) {
         $c->log->debug(qq/Redirecting to "$location"/) if $c->debug;
-        $c->res->headers->header( Location => $location );
-        $c->res->headers->remove_content_headers;
-        $c->res->status(302);
-        return $c->finalize_headers;
-    }
-
-    if ( !$c->res->output || $#{ $c->error } >= 0 ) {
-        $c->res->headers->content_type('text/html');
-        my $name = $c->config->{name} || 'Catalyst Application';
-        my ( $title, $error, $infos );
-        if ( $c->debug ) {
-            $error = join '<br/>', @{ $c->error };
-            $error ||= 'No output';
-            $title = $name = "$name on Catalyst $Catalyst::VERSION";
-            my $req   = encode_entities Dumper $c->req;
-            my $res   = encode_entities Dumper $c->res;
-            my $stash = encode_entities Dumper $c->stash;
-            $infos = <<"";
+        $c->response->header( Location => $location );
+        $c->response->status(302) if $c->response->status !~ /3\d\d$/;
+    }
+
+    if ( $#{ $c->error } >= 0 ) {
+        $c->finalize_error;
+    }
+
+    if ( !$c->response->output && $c->response->status !~ /^(1|3)\d\d$/ ) {
+        $c->finalize_error;
+    }
+
+    if ( $c->response->output && !$c->response->content_length ) {
+        use bytes;    # play safe with a utf8 aware perl
+        $c->response->content_length( length $c->response->output );
+    }
+
+    my $status = $c->finalize_headers;
+    $c->finalize_output;
+    return $status;
+}
+
+=item $c->finalize_cookies
+
+Finalize cookies.
+
+=cut
+
+sub finalize_cookies {
+    my $c = shift;
+
+    while ( my ( $name, $cookie ) = each %{ $c->response->cookies } ) {
+        my $cookie = CGI::Cookie->new(
+            -name    => $name,
+            -value   => $cookie->{value},
+            -expires => $cookie->{expires},
+            -domain  => $cookie->{domain},
+            -path    => $cookie->{path},
+            -secure  => $cookie->{secure} || 0
+        );
+
+        $c->res->headers->push_header( 'Set-Cookie' => $cookie->as_string );
+    }
+}
+
+=item $c->finalize_error
+
+Finalize error.
+
+=cut
+
+sub finalize_error {
+    my $c = shift;
+
+    $c->res->headers->content_type('text/html');
+    my $name = $c->config->{name} || 'Catalyst Application';
+
+    my ( $title, $error, $infos );
+    if ( $c->debug ) {
+        $error = join '<br/>', @{ $c->error };
+        $error ||= 'No output';
+        $title = $name = "$name on Catalyst $Catalyst::VERSION";
+        my $req   = encode_entities Dumper $c->req;
+        my $res   = encode_entities Dumper $c->res;
+        my $stash = encode_entities Dumper $c->stash;
+        $infos = <<"";
 <br/>
 <b><u>Request</u></b><br/>
 <pre>$req</pre>
@@ -152,11 +239,11 @@ sub finalize {
 <b><u>Stash</u></b><br/>
 <pre>$stash</pre>
 
-        }
-        else {
-            $title = $name;
-            $error = '';
-            $infos = <<"";
+    }
+    else {
+        $title = $name;
+        $error = '';
+        $infos = <<"";
 <pre>
 (en) Please come back later
 (de) Bitte versuchen sie es spaeter nocheinmal
@@ -168,67 +255,62 @@ sub finalize {
 (it) Ritornato prego piĆ¹ successivamente
 </pre>
 
-            $name = '';
-        }
-        $c->res->{output} = <<"";
+        $name = '';
+    }
+    $c->res->output( <<"" );
 <html>
-    <head>
-        <title>$title</title>
-        <style type="text/css">
-            body {
-                font-family: "Bitstream Vera Sans", "Trebuchet MS", Verdana,
-                             Tahoma, Arial, helvetica, sans-serif;
-                color: #ddd;
-                background-color: #eee;
-                margin: 0px;
-                padding: 0px;
-            }
-            div.box {
-                background-color: #ccc;
-                border: 1px solid #aaa;
-                padding: 4px;
-                margin: 10px;
-                -moz-border-radius: 10px;
-            }
-            div.error {
-                background-color: #977;
-                border: 1px solid #755;
-                padding: 8px;
-                margin: 4px;
-                margin-bottom: 10px;
-                -moz-border-radius: 10px;
-            }
-            div.infos {
-                background-color: #797;
-                border: 1px solid #575;
-                padding: 8px;
-                margin: 4px;
-                margin-bottom: 10px;
-                -moz-border-radius: 10px;
-            }
-            div.name {
-                background-color: #779;
-                border: 1px solid #557;
-                padding: 8px;
-                margin: 4px;
-                -moz-border-radius: 10px;
-            }
-        </style>
-    </head>
-    <body>
-        <div class="box">
-            <div class="error">$error</div>
-            <div class="infos">$infos</div>
-            <div class="name">$name</div>
-        </div>
-    </body>
+<head>
+    <title>$title</title>
+    <style type="text/css">
+        body {
+            font-family: "Bitstream Vera Sans", "Trebuchet MS", Verdana,
+                         Tahoma, Arial, helvetica, sans-serif;
+            color: #ddd;
+            background-color: #eee;
+            margin: 0px;
+            padding: 0px;
+        }
+        div.box {
+            background-color: #ccc;
+            border: 1px solid #aaa;
+            padding: 4px;
+            margin: 10px;
+            -moz-border-radius: 10px;
+        }
+        div.error {
+            background-color: #977;
+            border: 1px solid #755;
+            padding: 8px;
+            margin: 4px;
+            margin-bottom: 10px;
+            -moz-border-radius: 10px;
+        }
+        div.infos {
+            background-color: #797;
+            border: 1px solid #575;
+            padding: 8px;
+            margin: 4px;
+            margin-bottom: 10px;
+            -moz-border-radius: 10px;
+        }
+        div.name {
+            background-color: #779;
+            border: 1px solid #557;
+            padding: 8px;
+            margin: 4px;
+            -moz-border-radius: 10px;
+        }
+    </style>
+</head>
+<body>
+    <div class="box">
+        <div class="error">$error</div>
+        <div class="infos">$infos</div>
+        <div class="name">$name</div>
+    </div>
+</body>
 </html>
 
-    }
-    $c->res->headers->content_length( length $c->res->output );
-    my $status = $c->finalize_headers;
-    $c->finalize_output;
-    return $status;
 }
 
 =item $c->finalize_headers
@@ -351,14 +433,16 @@ Handles the request.
 
 =cut
 
-sub handler ($$) {
-    my ( $class, $r ) = @_;
+sub handler {
+    my ( $class, $engine ) = @_;
 
     # Always expect worst case!
     my $status = -1;
     eval {
+        my @stats = ();
         my $handler = sub {
-            my $c         = $class->prepare($r);
+            my $c = $class->prepare($engine);
+            $c->{stats} = \@stats;
             my $action    = $c->req->action;
             my $namespace = '';
             $namespace = ( join( '/', @{ $c->req->args } ) || '/' )
@@ -375,7 +459,8 @@ sub handler ($$) {
                 for my $begin ( @{ $c->get_action( 'begin', $namespace ) } ) {
                     $c->state( $c->execute( @{ $begin->[0] } ) );
                 }
-                for my $result ( @{ $c->get_action( $action, $default ) }[-1] )
+                for my $result (
+                    @{ $c->get_action( $c->req->action, $default ) }[-1] )
                 {
                     $c->state( $c->execute( @{ $result->[0] } ) );
                     last unless $default;
@@ -400,7 +485,16 @@ sub handler ($$) {
             ( $elapsed, $status ) = $class->benchmark($handler);
             $elapsed = sprintf '%f', $elapsed;
             my $av = sprintf '%.3f', 1 / $elapsed;
-            $class->log->info( "Request took $elapsed" . "s ($av/s)" );
+            my $t = Text::ASCIITable->new;
+            $t->setCols( 'Action', 'Time' );
+            $t->setColWidth( 'Action', 64, 1 );
+            $t->setColWidth( 'Time',   9,  1 );
+
+            for my $stat (@stats) {
+                $t->addRow(@$stat);
+            }
+            $class->log->info( "Request took $elapsed" . "s ($av/s)",
+                $t->draw );
         }
         else { $status = &$handler }
     };
@@ -441,9 +535,9 @@ sub prepare {
     if ( $c->debug ) {
         my $secs = time - $START || 1;
         my $av = sprintf '%.3f', $COUNT / $secs;
-        $c->log->debug('********************************');
+        $c->log->debug('**********************************');
         $c->log->debug("* Request $COUNT ($av/s) [$$]");
-        $c->log->debug('********************************');
+        $c->log->debug('**********************************');
         $c->res->headers->header( 'X-Catalyst' => $Catalyst::VERSION );
     }
     $c->prepare_request($r);
@@ -461,12 +555,15 @@ sub prepare {
     $c->prepare_parameters;
 
     if ( $c->debug && keys %{ $c->req->params } ) {
-        my @params;
+        my $t = Text::ASCIITable->new;
+        $t->setCols( 'Key', 'Value' );
+        $t->setColWidth( 'Key',   37, 1 );
+        $t->setColWidth( 'Value', 36, 1 );
         for my $key ( keys %{ $c->req->params } ) {
             my $value = $c->req->params->{$key} || '';
-            push @params, " $key=$value";
+            $t->addRow( $key, $value );
         }
-        $c->log->debug( 'Parameters', @params );
+        $c->log->debug( 'Parameters are', $t->draw );
     }
     $c->prepare_uploads;
     return $c;
@@ -491,7 +588,8 @@ sub prepare_action {
             if ($#$result) {
                 my $match    = $result->[1];
                 my @snippets = @{ $result->[2] };
-                $c->log->debug(qq/Requested action "$path" matched "$match"/)
+                $c->log->debug(
+                    qq/Requested action is "$path" and matched "$match"/)
                   if $c->debug;
                 $c->log->debug(
                     'Snippets are "' . join( ' ', @snippets ) . '"' )
@@ -501,7 +599,7 @@ sub prepare_action {
             }
             else {
                 $c->req->action($path);
-                $c->log->debug(qq/Requested action "$path"/) if $c->debug;
+                $c->log->debug(qq/Requested action is "$path"/) if $c->debug;
             }
             $c->req->match($path);
             last;
@@ -530,7 +628,13 @@ Prepare cookies.
 
 =cut
 
-sub prepare_cookies { }
+sub prepare_cookies {
+    my $c = shift;
+
+    if ( my $header = $c->request->header('Cookie') ) {
+        $c->req->cookies( { CGI::Cookie->parse($header) } );
+    }
+}
 
 =item $c->prepare_headers
 
@@ -572,39 +676,6 @@ Prepare uploads.
 
 sub prepare_uploads { }
 
-=item $c->execute($class, $coderef)
-
-Execute a coderef in given class and catch exceptions.
-Errors are available via $c->error.
-
-=cut
-
-sub execute {
-    my ( $c, $class, $code ) = @_;
-    $class = $c->comp($class) || $class;
-    $c->state(0);
-    eval {
-        if ( $c->debug )
-        {
-            my $action = $c->actions->{reverse}->{"$code"} || "$code";
-            my ( $elapsed, @state ) =
-              $c->benchmark( $code, $class, $c, @{ $c->req->args } );
-            $c->log->info( sprintf qq/Processing "$action" took %fs/, $elapsed )
-              if $c->debug;
-            $c->state(@state);
-        }
-        else { $c->state( &$code( $class, $c, @{ $c->req->args } ) ) }
-    };
-    if ( my $error = $@ ) {
-        chomp $error;
-        $error = qq/Caught exception "$error"/;
-        $c->log->error($error);
-        $c->error($error) if $c->debug;
-        $c->state(0);
-    }
-    return $c->state;
-}
-
 =item $c->run
 
 Starts the engine.
@@ -682,7 +753,7 @@ sub set_action {
         if ( $flags{regex} =~ /^"(.*)"$/ ) { $flags{regex} = $1 }
     }
 
-    my $reverse = $prefix ? "$method ($prefix)" : $method;
+    my $reverse = $prefix ? "$prefix/$method" : $method;
 
     if ( $flags{local} || $flags{global} || $flags{path} ) {
         my $path = $flags{path} || $method;
@@ -787,38 +858,55 @@ sub setup_components {
         $self->components->{ ref $comp } = $comp;
         $self->setup_actions($comp);
     }
-    my @comps;
-    push @comps, " $_" for keys %{ $self->components };
-    $self->log->debug( 'Loaded components', @comps )
-      if ( @comps && $self->debug );
+    my $t = Text::ASCIITable->new;
+    $t->setCols('Class');
+    $t->setColWidth( 'Class', 75, 1 );
+    $t->addRow($_) for keys %{ $self->components };
+    $self->log->debug( 'Loaded components', $t->draw )
+      if ( @{ $t->{tbl_rows} } && $self->debug );
     my $actions  = $self->actions;
-    my @messages = ('Loaded private actions');
-    my $walker   = sub {
-        my ( $walker, $parent, $messages, $prefix ) = @_;
+    my $privates = Text::ASCIITable->new;
+    $privates->setCols( 'Action', 'Class', 'Code' );
+    $privates->setColWidth( 'Action', 28, 1 );
+    $privates->setColWidth( 'Class',  28, 1 );
+    $privates->setColWidth( 'Code',   14, 1 );
+    my $walker = sub {
+        my ( $walker, $parent, $prefix ) = @_;
         $prefix .= $parent->getNodeValue || '';
         $prefix .= '/' unless $prefix =~ /\/$/;
         my $uid = $parent->getUID;
         for my $action ( keys %{ $actions->{private}->{$uid} } ) {
             my ( $class, $code ) = @{ $actions->{private}->{$uid}->{$action} };
-            push @$messages, _prettify( "$prefix$action", $class, $code );
+            $privates->addRow( "$prefix$action", $class, $code );
         }
-        $walker->( $walker, $_, $messages, $prefix )
-          for $parent->getAllChildren;
+        $walker->( $walker, $_, $prefix ) for $parent->getAllChildren;
     };
-    $walker->( $walker, $self->tree, \@messages, '' );
-    $self->log->debug(@messages) if ( $#messages && $self->debug );
-    @messages = ('Loaded plain actions');
+    $walker->( $walker, $self->tree, '' );
+    $self->log->debug( 'Loaded private actions', $privates->draw )
+      if ( @{ $privates->{tbl_rows} } && $self->debug );
+    my $publics = Text::ASCIITable->new;
+    $publics->setCols( 'Action', 'Class', 'Code' );
+    $publics->setColWidth( 'Action', 28, 1 );
+    $publics->setColWidth( 'Class',  28, 1 );
+    $publics->setColWidth( 'Code',   14, 1 );
+
     for my $plain ( sort keys %{ $actions->{plain} } ) {
         my ( $class, $code ) = @{ $actions->{plain}->{$plain} };
-        push @messages, _prettify( "/$plain", $class, $code );
+        $publics->addRow( "/$plain", $class, $code );
     }
-    $self->log->debug(@messages) if ( $#messages && $self->debug );
-    @messages = ('Loaded regex actions');
+    $self->log->debug( 'Loaded public actions', $publics->draw )
+      if ( @{ $publics->{tbl_rows} } && $self->debug );
+    my $regexes = Text::ASCIITable->new;
+    $regexes->setCols( 'Action', 'Class', 'Code' );
+    $regexes->setColWidth( 'Action', 28, 1 );
+    $regexes->setColWidth( 'Class',  28, 1 );
+    $regexes->setColWidth( 'Code',   14, 1 );
     for my $regex ( sort keys %{ $actions->{regex} } ) {
         my ( $class, $code ) = @{ $actions->{regex}->{$regex} };
-        push @messages, _prettify( $regex, $class, $code );
+        $regexes->addRow( $regex, $class, $code );
     }
-    $self->log->debug(@messages) if ( $#messages && $self->debug );
+    $self->log->debug( 'Loaded regex actions', $regexes->draw )
+      if ( @{ $regexes->{tbl_rows} } && $self->debug );
 }
 
 =item $c->stash
@@ -858,16 +946,6 @@ sub _class2prefix {
     return $prefix;
 }
 
-sub _prettify {
-    my ( $action, $class, $code ) = @_;
-    formline
-' @<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< @<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< @|||||||||||||| ',
-      $action, $class, $code;
-    my $formatted = $^A;
-    $^A = '';
-    return $formatted;
-}
-
 =back
 
 =head1 AUTHOR