16.1. Logging

The only way to understand what went wrong during the execution of a request is to review a trace of the execution process. Fortunately, as you'll learn in this section, both PHP and symfony tend to log large amounts of this sort of data.

16.1.1. PHP Logs

PHP has an error_reporting parameter, defined in php.ini, that specifies which PHP events are logged. Symfony allows you to override this value, per application and environment, in the settings.yml file, as shown in Listing 16-1.

Listing 16-1 - Setting the Error Reporting Level, in frontend/config/settings.yml

prod:
 .settings:
    error_reporting:  <?php echo (E_PARSE | E_COMPILE_ERROR | E_ERROR | E_CORE_ERROR | E_USER_ERROR)."\n" ?>

dev:
  .settings:
    error_reporting:  <?php echo (E_ALL | E_STRICT)."\n" ?>

In order to avoid performance issues in the production environment, the server logs only the critical PHP errors. However, in the development environment, all types of events are logged, so that the developer can have all the information necessary to trace errors.

The location of the PHP log files depends on your php.ini configuration. If you never bothered about defining this location, PHP probably uses the logging facilities provided by your web server (such as the Apache error logs). In this case, you will find the PHP logs under the web server log directory.

16.1.2. Symfony Logs

In addition to the standard PHP logs, symfony can log a lot of custom events. You can find all the symfony logs under the myproject/log/ directory. There is one file per application and per environment. For instance, the development environment log file of the frontend application is named frontend_dev.log, the production one is named frontend_prod.log, and so on.

If you have a symfony application running, take a look at its log files. The syntax is very simple. For every event, one line is added to the log file of the application. Each line includes the exact time of the event, the nature of the event, the object being processed, and any additional relevant details. Listing 16-2 shows an example of symfony log file content.

Listing 16-2 - Sample Symfony Log File Content, in log/frontend_dev.php

Nov 15 16:30:25 symfony [info ] {sfAction} call "barActions->executemessages()"
Nov 15 16:30:25 symfony [debug] SELECT bd_message.ID, bd_message.SENDER_ID, bd_...
Nov 15 16:30:25 symfony [info ] {sfPropelLogger} executeQuery: SELECT bd_message.ID...
Nov 15 16:30:25 symfony [info ] {sfView} set slot "leftbar" (bar/index)
Nov 15 16:30:25 symfony [info ] {sfView} set slot "messageblock" (bar/mes...
Nov 15 16:30:25 symfony [info ] {sfView} execute view for template "messa...
Nov 15 16:30:25 symfony [info ] {sfView} render "/home/production/myproject/...
Nov 15 16:30:25 symfony [info ] {sfView} render to client

You can find many details in these files, including the actual SQL queries sent to the database, the templates called, the chain of calls between objects, and so on.

New in symfony 1.1: The format of the file logs is configurable by overriding the format and/or the time_format settings in factories.yml as shown in Listing 16-3.

Listing 16-3 - Changing the Log Format

all:
  logger:
    param:
      sf_file_debug:
        param:
          format:      %time% %type% [%priority%] %message%%EOL%
          time_format: %b %d %H:%M:%S

16.1.2.1. Symfony Log Level Configuration ###

There are eight levels of symfony log messages: emerg, alert, crit, err, warning, notice, info, and debug, which are the same as the PEAR::Log package (http://pear.php.net/package/Log/) levels. You can configure the maximum level to be logged in each environment in the factories.yml configuration file of each application, as demonstrated in Listing 16-4.

Listing 16-4 - Default Logging Configuration, in frontend/config/factories.yml

prod:
  logger:
    param:
      level: err

By default, in all environments except the production environment, all the messages are logged (up to the least important level, the debug level). In the production environment, logging is disabled by default; if you change logging_enabled to on in settings.yml, only the most important messages (from crit to emerg) appear in the logs.

You can change the logging level in the factories.yml file for each environment to limit the type of logged messages.

16.1.2.2. Adding a Log Message ###

You can manually add a message in the symfony log file from your code by using one of the techniques described in Listing 16-5.

Listing 16-5 - Adding a Custom Log Message

// From an action
$this->logMessage($message, $level);

// From a template
<?php use_helper('Debug') ?>
<?php log_message($message, $level) ?>

$level can have the same values as in the log messages.

Alternatively, to write a message in the log from anywhere in your application, use the sfLogger methods directly, as shown in Listing 16-6. The available methods bear the same names as the log levels.

Listing 16-6 - Adding a Custom Log Message from Anywhere

if (sfConfig::get('sf_logging_enabled'))
{
  sfContext::getInstance()->getLogger()->info($message);
}

class myLogger extends sfLogger
{
  protected function doLog($message, $priority)
  {
    error_log(sprintf('%s (%s)', $message, sfLogger::getPriorityName($priority)));
  }
}

require_once('Log.php');
require_once('Log/error_log.php');

// Define a thin wrapper to implement the interface
// for the logger we want to use with symfony
class Log_my_error_log extends Log_error_log implements sfLoggerInterface
{
}

16.1.2.3. Purging and Rotating Log Files ###

Don't forget to periodically purge the log/ directory of your applications, because these files have the strange habit of growing by several megabytes in a few days, depending, of course, on your traffic. Symfony provides a special log:clear task for this purpose, which you can launch regularly by hand or put in a cron table. For example, the following command erases the symfony log files:

> php symfony log:clear

For both better performance and security, you probably want to store symfony logs in several small files instead of one single large file. The ideal storage strategy for log files is to back up and empty the main log file regularly, but to keep only a limited number of backups. You can enable such a log rotation with a period of 7 days and a history (number of backups) of 10, as shown in Listing 16-7. You would work with one active log file plus ten backup files containing seven days' worth of history each. Whenever the next period of seven days ends, the current active log file goes into backup, and the oldest backup is erased.

Listing 16-7 - Launching Log Rotation

> php symfony log:rotate frontend prod --period=7 --history=10

The backup log files are stored in the logs/history/ directory and suffixed with the date they were saved.