Wednesday, 11 April 2007

Zend_Log revisited

With the current Zend Framework Beta 0.9.2 release the Zend_Log component has been improved with a new fully object oriented design. There are lots of new features including Writers, Filters, Formatters and Events to discover and use in custom applications. The log Priorities have been doubled from 4 to 8 in the current release and it's now possible to add user defined log Priorities via the Zend_Log addPriority method. Due to the use of one of PHP magic functions it's even possible to send messages of the log Priority type simply by calling the 'priorityName()' method, i.e. $logger->audit('Auditional message'), of the Zend_Log object without further ado.

The Writer object allows to define how a log Event is stored to the chosen storage backend. Currently there are Writers implemented for storing log Events in a file, a database or even further sending them to a PHP stream, a Mock- or a Null Writer. The Mock Writer records the log Events in memory by using an array and the Null Writer is used for nullifing the storing of log Events. I guess these both types of Writers are supposed the support the testing of custom applications. It's also possible to add custom Writers by inheriting from Zend_Log_Writer_Abstract and implementing the desired type.

The use of Filters allow it, as the name suggests, to block log Events from being sent to the chosen Writer instance. Again it is possible to write it's own Filters simply by implementing the Zend_Log_Filter_Interface in a custom Filter class. I outlined this in an additional and short article on this blog.

The Formatter object can be used to (re)define and modify the appearance and content for the raised log Events.

Log Events are created by calling any method associated to an log Priority(i.e. log or info) and are collected in an associative array describing the Event. The following keys are always created in this array: timestamp, message, priority, and priorityName. To add other log Events which are valuable to log in a specific use case, the Zend_Log component enables you to do so via it's setEventItem method, which takes the key and the corresponding value as arguments. The additional log Event has to be added to the Formatter object of the Writter to be informed of it's existence and to actually record it.

The following code extract shows the new Zend_Log component setup and configured in the bootstrap file.

<?php

...

$writer = new Zend_Log_Writer_Stream('/path/to/logfile');
$auditWriter = new Zend_Log_Writer_Stream('/path/to/auditfile');

/* Use a customized Formatting and add custom log Events */
$formatter = new Zend_Log_Formatter_Xml('audit', array('msg' => 'message',
'level' => 'priorityName',
'ip-visitor' => 'visitorIp',
'host-visitor' => 'visitorHost'));
$auditWriter->setFormatter($formatter);

/* Use a customized Formatting */
$formatter = new Zend_Log_Formatter_Simple('[ %timestamp% ] [ %priorityName% ]: %message%' . PHP_EOL);
$writer->setFormatter($formatter);

$logger = new Zend_Log($writer);
$auditLogger = new Zend_Log($auditWriter);

/* Add a custom log Priority to the audit logger */
$auditLogger->addPriority('audit', 8);

/* Add some custom log Events to the audit logger */
$auditLogger->setEventItem('visitorIp', $_SERVER['REMOTE_ADDR']);
$auditLogger->setEventItem('visitorHost', gethostbyaddr($_SERVER['REMOTE_ADDR']));

/* Re-define the timestamp format for the default logger */
$logger->setEventItem('timestamp', date('m-d-Y H:i:s', time()));

/* Add a Filter for log Events */
$filter = new Zend_Log_Filter_Priority(8);
$auditLogger->addFilter($filter);

/* Add the loggers to Registry */
Zend_Registry::set('logger', $logger);
Zend_Registry::set('auditLogger', $auditLogger);

...

?>
Here are the defined loggers in action somewhere in the application.
<?php

...

/* Retrieve the logger from the registry */
$logger = Zend_Registry::get('logger');

/* Use the default log Priority info */
$logger->info('Informational message');

/* Retrieve the audit logger from the registry */
$auditLogger = Zend_Registry::get('auditLogger');

/* Use the custom log Priority audit */
$auditLogger->audit('Auditional message');

...

?>
And finally this is how a customized log entry of the Xml file based audit logger instance looks like.
<audit>
<msg>Auditional message</msg>
<level>AUDIT</level>
<ip-visitor>127.0.0.1</ip-visitor>
<host-visitor>localhost</host-visitor>
</audit>
This article only shortly summarized some parts of the new Zend_Log component, to dig deeper into the uncovered spots have a look at the Zend Framework Programmer's Reference Guide, as it provides more detailed information and further help.

3 comments:

Temuri said...

Hi, I've been trying to figure out this new way of logging. Zend also changed its instantiation: Zend_Log is no longer a singleton.

Question to you - do you think it's a good idea to pass logger devices around via Zend_Registry?

Or is it better to pass it in to constructors or via setter methods?

Thanks for a nice article.

Temuri

Raphael Stolt said...

Hi Temuri,

well it worked for me, but the 'retrieval' routines can really clutter up your code when making heavy use of it.

In these cases the logging device should be injected in an init method which is fetching it from the registry and assigning it to a property all the action methods can access.

Take a look at the Object initialization part of the Action Controller Zend Framework manual for more info.

An other possible approach might be the use of an Action Helper to achieve the same effect, though I didn't try this yet.

Menno said...

Thanks for your article, it contains some aspects that the Zend Framework documentation does not cover yet.

Only: be aware of the amount of time consumed by the gethostbyaddr() method when using the logger intensively. For me it caused an unacceptable delay of about 10 seconds and it took me a while to figure out what caused this, since the development environment had less difficulties with finding out who '127.0.0.1' was exactly ;)