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 myapp/config/settings.yml

prod:
 .settings:
    error_reporting:  257

dev:
  .settings:
    error_reporting:  4095

The numbers are a short way of writing error levels (refer to the PHP documentation on error reporting for more details). Basically, 4095 is a shortcut for E_ALL | E_STRICT, and 257 stands for E_ERROR | E_USER_ERROR (the default value for every new environment).

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 myapp application is named myapp_dev.log, the production one is named myapp_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/myapp_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 ] {sfCreole} 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.

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 (pear.php.net/package/Log) levels. You can configure the maximum level to be logged in each environment in the logging.yml configuration file of each application, as demonstrated in Listing 16-3.

Listing 16-3 - Default Logging Configuration, in myapp/config/logging.yml

prod:
  enabled: off
  level:   err
  rotate:  on
  purge:   off

dev:

test:

#all:
#  enabled:  on
#  level:    debug
#  rotate:   off
#  period:   7
#  history:  10
#  purge:    on

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 enabled to on, only the most important messages (from crit to emerg) appear in the logs.

You can change the logging level in the logging.yml file for each environment to limit the type of logged messages. The rotate, period, history, and purge settings are described in the upcoming "Purging and Rotating Log Files" section.

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-4.

Listing 16-4 - 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-5. The available methods bear the same names as the log levels.

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

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

require_once('Log.php');
$log = Log::singleton('error_log', PEAR_LOG_TYPE_SYSTEM, 'symfony');
sfLogger::getInstance()->registerLogger($log);

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-purge 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 in applications and environments where the logging.yml file specifies purge: on (which is the default value):

> symfony log-purge

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 and specify the parameters in logging.yml. For instance, with a period of 7 days and a history (number of backups) of 10, as shown in Listing 16-6, 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-6 - Configuring Log Rotation, in myapp/config/logging.yml

prod:
  rotate:  on
  period:  7       ## Log files are rotated every 7 days by default
  history: 10      ## A maximum history of 10 log files is kept

To execute the log rotation, periodically execute the log-rotate task. This task only purges files for which rotate is on. You can specify a single application and environment when calling the task:

> symfony log-rotate myapp prod

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