Logging design pattern in a Zend framework application

Question

I'm building an application using Zend Framework. The application requires intensive logging for every action or function in the code.

so my code most of the time looks like this:

function SendMailsAction(){
      $logger->log('Started sending mails.')
...
...
...Some Code...
...
...

foreach ($mails as $mail){
  try{      
       $logger->log('Trying to send')
       $mail->send()
       $logger->log('Mail sent successfully.')
  }catch(Exception $e){
       $logger->log('Failed to send mail.')
      }      
 }

...
...
...Some Code...
...
...
       $logger->log('Finished sending mails.')
}

Sometimes I even have to log in 2 tables, so most of the logging code is doubled and the functions start to get complicated and long.

I use Zend framework's Zend_Log for logging so my problem is not the logging class itself, But it's how to separate the logging code from the code functionality itself and maintain separation of concerns.

Some people suggested Aspect Oriented Programming (AOP), but unfortunately AOP for PHP isn't acceptable for my costumer, so I'm looking for an Object Oriented solution or best practice.

Note:

Just to make things clear my problem isn't how to use Zend_Log, but how to add logging to my application code in general.

What do you think your code should look like? Is there some desirable bit of code? — akond
– akond, Commented Feb 16, 2012 at 12:44
@akond well I was thinking about "attaching" log functions to certain functions in the Models or Controllers. something like registering functions to run at certain points in the code. If any of this is even applicable in PHP of course. — Songo
– Songo, Commented Feb 16, 2012 at 13:19
Good question and I think ZF2 will handle this kind of problem much more elegantly with the EventManager. — Richard Ayotte
– Richard Ayotte, Commented Feb 16, 2012 at 13:41
EventManager could be a solution, but I personally think Dependency Injection is more appropriate. — akond
– akond, Commented Feb 16, 2012 at 13:47
I'm curious as to why AOP isn't acceptable to the customer; would you mind elaborating? — Matthew Groves
– Matthew Groves, Commented Feb 17, 2012 at 1:10

Berry Langerak · Accepted Answer · 2012-02-16 14:14:50Z

Sometimes I even have to log in 2 tables, so most of the logging code is doubled and the functions start to get complicated and long.

It'll be long. If your code does a lot of logging, it will be long, as it will have to log, and each line action it logs, will mean there's a line in your code. It shouldn't, however, be complicated in any case as logging is one of the most straightforward thing you can do. What worries me, is that you mention "sometimes I even have to log in 2 tables". In my book, one, two, five, sixty or one thousand tables is performed by one line. Code is not doubled for each logger. If you're copy-pasting a line, and changing $log to $log2, you're clearly doing it wrong (tm).

Some people suggested Aspect Oriented Programming (AOP), but unfortunately AOP for PHP isn't acceptable for my costumer, so I'm looking for an Object Oriented solution or best practice.

It is nice, AOP. It has downsides though; as with the debug_backtrace approach, there's a heavy performance hit. That, plus the code becomes increasingly more "magical" in that it does things that aren't clear when you're looking at the code itself. That increases the time you're debugging your application.

My $0.02? First of all, don't repeat yourself: one log entry per action should be enough. Use flexible loggers that can be attached to certain classes at runtime. Decide whether or not to actually log the message in the logger, based on "severity" or "type". All in all, just implement the Observer pattern:

<?php

namespace Foo;

class MailService {
    public function attach( Observes $observer ) {
        $this->observers[] = $observer;
    }

    public function notify( $message, $type = 'notice' ) {
        foreach( $this->observers as $observer ) {
            $observer->notify( $message, $type );
        }
    }

    public function sendMail( ) {
        $this->notify( 'Started sending mails', 'debug' );
        $mails = array( );
        foreach( $mails as $mail ) {
            try {
                $this->notify( 'Trying to send', 'debug' );
                $mail->send( );
                $this->notify( 'Mail sent succesfully', 'debug' );
            }
            catch( Exception $e ) {
                $this->notify( 'Failed to send mail', 'notice' );
            }
        }
        $this->notify( 'Finished sending mail', 'debug' );
    }
}

interface Observes {
    public function notify( $message, $type = 'notice' );
}

abstract class Logger implements Observes {
    protected $types = array(
        'debug' => 0,
        'notice' => 1,
        'warning' => 2,
        'error' => 3
    );

    protected function code( $type ) {
        return isset( $this->types[$type] ) ? $this->types[$type] : 0;
    }
}

class FileLogger extends Logger implements Observes {

    public function __construct( $filename ) {
        $this->filename = $filename;
    }

    /**
     * @todo replace the method body with a call to, say, file_put_contents.
     */
    public function notify( $message, $type = 'notice' ) {
        if( $this->code( $type ) > $this->code( 'notice' ) ) { // only for warning and error.
            echo $message . "\n";
        }
    }


}

class DebugLogger extends Logger implements Observes {
    public function notify( $message, $type = 'notice' ) {
        if( $this->code( $type ) === $this->code( 'debug' ) ) { // only show "debug" notices.
            echo $message . "\n";
        }
    }
}


$service = new MailService( );
$service->attach( new FileLogger( 'yourlog.txt' ) );
$service->attach( new DebugLogger( ) );
$service->sendMail( );

+1 for the working code and great explanation. Just wondering though, why did you make the abstract class implement the interface in abstract class Logger implements Observes?
@Songo Mostly because I already wrote the interface, then found both have common behaviour which could just as easily be abstracted to the parent class. But, if you ever write a Observer that doesn't log stuff, you might find the interface useful anyway.

markus · Accepted Answer · 2012-02-16 13:44:18Z

4

If you don't want to use any external tools you can write some sort of observer wrapper around debug_backtrace that loops through the backtrace and compares all function calls to an array map provided by the wrapper and if it's a hit, writes the respective log message with your custom message text. This would be a complete separation of code where you would just need to run this observer class at the end of every script.

As for an example I think all you need is in the examples of the PHP manual. Still, here is some pseudo-code to illuminate what I mean:

//use register_shutdown_function to register your logger function

function scanTrace(Zend_Log $logger, array $eventMap)
{
    $trace = array_reverse(debug_backtrace());

    foreach ($trace as $step)
    {
        //1. extract the needed info
        //2. check if the event is in your eventMap
        //3. if yes, log it
    }
}

The eventMap should already contain the message you want to log for every event.

If you don't mind using an external tool (which I think is the better option) then you could work with xdebug and WebGrind or similar.

Btw: You may be interested in monitorix, which is an extension of Zend_Log with a lot of nice automated logging to a db table (like slow query logging, php error and exception logging, javascript error logging).

edited Feb 16, 2012 at 13:44

answered Feb 16, 2012 at 12:26

markus

40.8k23 gold badges100 silver badges143 bronze badges

1 Comment

Songo Over a year ago

Could you please explain more about the first part in your answer?. Would you post some code examples about using the debug_bactrace, please ?

lisachenko · Accepted Answer · 2012-11-24 20:05:12Z

I have logging in my Zend2 service with the help of my Go! AOP PHP library. It fast enough and allows me to debug original source code with XDebug in development mode. However, it's only beta, be aware!

use Go\Aop\Aspect;
use Go\Aop\Intercept\MethodInvocation;
use Go\Lang\Annotation\After;
use Go\Lang\Annotation\AfterThrowing;
use Go\Lang\Annotation\Before;
use Go\Lang\Annotation\Around;

/**
 * Logging aspect
 */
class LoggingAspect implements Aspect
{

    /**
     * @var Zend\Log\Logger
     */
    protected $logger = null;

    /**
     * Constructs a logging aspect
     */
    public function __construct()
    {
        $logger = new Zend\Log\Logger;
        $writer = new Zend\Log\Writer\Stream('php://output');

        $logger->addWriter($writer);
        $this->logger = $logger;
    }

    /**
     * Method that will be called before real method
     *
     * @param MethodInvocation $invocation Invocation
     * @Before("execution(public ClassName->*(*))")
     */
    public function beforeMethodExecution(MethodInvocation $invocation)
    {
        $msg = 'Before: '. $this->formatMessage($invocation);
        $this->logger->log(Zend\Log\Logger::INFO, $msg);
    }

    /**
     * Method that will be called after throwing an exception in the real method
     *
     * @param MethodInvocation $invocation Invocation
     * @AfterThrowing("execution(public ClassName->*(*))")
     */
    public function afterThrowingMethodExecution(MethodInvocation $invocation)
    {
        $msg = 'After throwing: '. $this->formatMessage($invocation);
        $this->logger->log(Zend\Log\Logger::ERR, $msg);
    }

    /**
     * Format a message from invocation
     *
     * @param MethodInvocation $invocation
     * @return string
     */
    protected function formatMessage(MethodInvocation $invocation)
    {
        $obj = $invocation->getThis();
        return is_object($obj) ? get_class($obj) : $obj .
            $invocation->getMethod()->isStatic() ? '::' : '->' .
            $invocation->getMethod()->getName() .
            '()' .
            ' with arguments: ' .
            json_encode($invocation->getArguments()) .
            PHP_EOL;
    }
}

```

tawfekov · Accepted Answer · 2012-02-16 12:10:50Z

1

you know that zend log can have more than one writer http://framework.zend.com/manual/en/zend.log.writers.html#zend.log.writers.compositing

its simple as creating a class single function

class logger {
  public function log ($value , $type  , $bothlogger = false){
      $writer1 = new Zend_Log_Writer_Stream('/path/to/first/logfile');
      $writer2 = new Zend_Log_Writer_Stream('/path/to/second/logfile');

      $logger = new Zend_Log();
      $logger->addWriter($writer1);

      if($bothlogger === true){
        $logger->addWriter($writer2);
      }
      // goes to both writers
       $logger->info('Informational message');

       return true;
  }

}

of course you can modify this sample to be faster with many ways , but it should explain the idea

answered Feb 16, 2012 at 12:10

tawfekov

5,1124 gold badges30 silver badges51 bronze badges

3 Comments

Songo Over a year ago

Actually my problem isn't about using Zend_Log class. It's about keeping my code clean and maintaining separation of concerns in used classes.

Songo Over a year ago

+1 for reminding me that I could attach more than one writer to the log. :)

Erik Over a year ago

I noticed you instanciated the logger within a function. I've tried to do this at the class scope and it failed. Is this normal? Do I instantiate for each function a new logger + writer?

Collectives™ on Stack Overflow

Logging design pattern in a Zend framework application

4 Answers 4

2 Comments

1 Comment

Comments

3 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

4 Answers 4

2 Comments

1 Comment

Comments

3 Comments

Your Answer

Sign up or log in

Post as a guest

Related