Team LiB
Previous Section Next Section

8.1. Apache Logging Facilities

Apache can produce many types of logs. The two essential types are the access log, where all requests are noted, and the error log, which is designed to log various informational and debug messages, plus every exceptional event that occurs. Additional information can be found in module-specific logs, as is the case with mod_ssl, mod_rewrite and mod_security. The access log is created and written to by the module mod_log_config, which is not a part of the core, but this module is so important that everyone treats it as if it is.

8.1.1. Request Logging

You only need to be familiar with three configuration directives to manage request logging:

  • LogFormat

  • transferLog

  • CustomLog

In fact, you will need to use only two. The CustomLog directive is so flexible and easy to use that you will rarely need to use transferLog in your configuration. (It will become clear why later.)

Other directives are available, but they are deprecated and should not be used because CustomLog can achieve all the necessary functionality. Some have been removed from Apache 2:


Deprecated, but still available


Deprecated and removed from Apache 2


Deprecated and removed from Apache 2


Deprecated and removed from Apache 2 LogFormat

Before covering the process of logging to files, consider the format of our log files. One of the benefits of Apache is its flexibility when it comes to log formatting. All this is owed to the LogFormat directive, whose default is the following, referred to as the Common Log Format (CLF):

LogFormat "%h %l %u %t \"%r\" %>s %b" common

The first parameter is a format string indicating the information to be included in a log file and the format in which it should be written; the second parameter gives the format string a name. You can decipher the log format using the symbol table. The table is available from the Apache reference documentation ( It is reproduced in Table 8-1.

Table 8-1. Standard logging format strings

Format string



The percent sign


Remote IP address


Local IP address


Bytes sent (excluding headers)


Bytes sent (excluding headers); a dash (-) is used instead of a zero


The contents of the cookie Name


Time taken to serve the request, in microseconds (Apache 2 only)


The contents of the environment variable Name




Remote host


Request protocol


The contents of the request header Name


Remote log name (from identd)


Request method


Contents of the note Name


Contents of the response header Name


Canonical port of the server


Process ID


Depending on Format, Process ID (pid) or thread ID (tid)


Query string


Request line


Response status


Time, in common log format


Time, in custom format


Time taken to serve the request, in seconds


Remote user


The URL, excluding the query string


Canonical server name


Server name according to UseCanonicalName directive


Connection status at the end of the request ("X" for aborted, "+" for persistent, and "-" for closed)

You have a lot of fields to play with. Format strings support optional parameters, as represented by the " . . . " in each format string representation in the table. Optional parameters can be used for the following actions:

  • Conditionally include the format item in the log line. If the parameter consists of a list of (comma-separated) HTTP status codes, the item will be included only if the response status code was one of the specified ones. Otherwise, a "-" will be placed in the output. For example, to log bytes sent only for requests with responses 200 or 404, use %200,404B. An exclamation mark preceding the status codes is used for negation. That is, the item will be included only if the response status code is not one of the ones specified after the exclamation mark. For example, to omit logging the request line when the request was rejected due to the request line being too long, use %!414r. (This comes in handy to prevent the logs from growing too quickly.)

  • Access values of fields from internally redirected requests, when the parameter is < for the original request or > for the last request in the chain. By default, the %s format string refers to the status of the original request, and you can use %>s to record the status of the last request in the chain.

Apache modules can collaborate on logging if they create a named note (a text string) and attach it to the request. If the %{note}n format string is used, the contents of the note will be written to the log. A change in the Apache architecture in the second generation allows for modules to collaborate and provide custom format strings. These format strings are available if the module that provides them is included in the configuration. (See Table 8-2.)

Table 8-2. Format string directives available only in Apache 2

Format string





Total bytes received, on a network level



Total bytes sent, on a network level



The contents of the variable Variable



Deprecated cryptography format function, included for backward compatibility with mod_ssl 1.3.x

With the inclusion of mod_logio, you can measure the number of bytes transferred for every request. This feature allows hosting providers to put accurate billing mechanisms in place. (With Apache 1, you can only record the size of the response body, leaving request headers, request body, and response headers unmeasured.)

Now that you are familiar with format strings, look at commonly used log formats (see Table 8-3). (You will need to define these formats in httpd.conf if they are not already there.)

Table 8-3. Commonly used log formats


LogFormat string

common (the default)

%h %l %u %t "%r" %>s %b


%h %l %u %t "%r" %>s %b "%{Referer}i" "%{User-Agent}i"


%v %h %l %u %t "%r" %>s %b


%v %h %l %u %t "%r" %>s %b "%{Referer}i" "%{User-Agent}i"

Though you can create your own log format, you will most likely use one of the formats above since that is what web server log analyzers support. Nevertheless, the ability to create logs with a custom format is convenient for advanced uses, as we shall see later in this chapter. TransferLog

transferLog is the basic request logging directive, which creates an access log with the given filename:

TransferLog /var/www/logs/access_log

The filename can be given with an absolute path, as above; if a relative filename is supplied, Apache will create the full path by pre-pending the server home directory (e.g. /usr/local/apache).

By default, the transferLog directive uses the Common Log Format (CLF), which logs every request on a single line with information formatted (as shown in Section Here is an example of what such a line looks like: - - [29/Jun/2004:14:36:04 +0100] "POST /upload.php 
HTTP/1.1" 200 3229

However, if a LogFormat directive has been used earlier in the configuration file, the transferLog directive will use the format it defined and not the CLF. This is unexpected and can lead to errors since changing the order in which formats are defined can lead to a different format being used for the log files. I prefer not to use transferLog, and instead use the CustomLog directive (which forces me to explicitly define the log format). CustomLog

The real power comes from using the CustomLog directive. The equivalent to the transferLog usage described above looks like this:

CustomLog /var/www/logs/access_log custom

The explicit naming of the log format helps us avoid mistakes. I like this directive because of its conditional logging features. Have a look at the following configuration fragment:

# determine which requests are static - you may need to
# adjust the regular expression to exclude other files, such
# as PDF documents, or archives
SetEnvIfNoCase REQUEST_URI "\.(gif|png|jpg)$" static_request
# only log dynamic requests
CustomLog /var/www/logs/application_log combined env=!static_request

The conditional logging opens the door to many interesting logging opportunities, which really helps in real life. Most commonly, you will use mod_setenvif or mod_rewrite (which can also set environment variables) to determine what gets logged.

I mentioned that, by default, Apache uses the CLF, which does not record many request parameters. At the very least you should change the configuration to use the combined format, which includes the UserAgent and the Referer fields.

Looking at the log format string table shown in the LogFormat section, you can see over twenty different format strings, so even the use of a combined format results in loss of information. Create your own log format based on your information requirements. A nice example can be found at:

"Profiling LAMP Applications with Apache's Blackbox Logs" by Chris Josephes (

In the article, Chris makes a case for a log format that allows for web serving troubleshooting and performance management. At the end, he names the resulting log format Blackbox.

8.1.2. Error Logging

The Apache error log contains error messages and information about events unrelated to request serving. In short, the error log contains everything the access log doesn't:

  • Startup and shutdown messages

  • Various informational messages

  • Errors that occurred during request serving (i.e., status codes 400-503)

  • Critical events

  • Standard error output (stderr)

The format of the error log is fixed. Each line essentially contains only three fields: the time, the error level, and the message. In some rare cases, you can get raw data in the error log (no time or error level). Apache 2 adds the Referer information to 404 responses noted in the error log.

Error logs are created using the ErrorLog configuration directive. Standard file naming conventions apply here; a relative filename will be assumed to be located in the server main folder.

ErrorLog /var/www/logs/error_log

The directive can be configured globally or separately for each virtual host. The LogLevel directive configures log granularity and ensures more information is not in the log than necessary. Its single parameter is one of the levels in Table 8-4. Events that are on the specified level or higher will be written to the log file.

Table 8-4. Error log levels




Emergencies (system unstable)


Alerts to act on immediately


Critical conditions


Error messages


Warning messages


Normal but significant conditions


Informational messages


Debugging information

The default setting is warn. However, Apache always logs the messages of level notice when logging to text files. Some interesting messages are emitted on the informational level (e.g., that a client timed out on a connection, a potential sign of a DoS attack). Consider running the error log on the information level:

LogLevel info

Take some time to observe the error log to get a feeling as to what constitutes normal Apache behavior. Some messages seem dangerous but may not be.

On server startup, you will get a message similar to this one:

[Mon Jul 05 12:26:27 2004] [notice] Apache/2.0.50 (Unix) DAV/2
PHP/4.3.4 configured -- resuming normal operations

You will see a message to log the shutdown of the server:

[Mon Jul 05 12:27:22 2004] [notice] caught SIGTERM, shutting down

Most other relevant events will find their way to the error log as well.

The Apache error log is good at telling you that something bad has happened, but it may not contain enough information to describe it. For example, since it does not contain information about the host where the error occurred, it is difficult to share one error log between virtual hosts.

There is a way to get more informational error messages using the mechanism of custom logging. Here is an example:

LogFormat "%h %l %u %t \"%r\" %>s %b \"%{error-notes}n\"" commone
CustomLog logs/super_error_log commone

Most of the time, the error message that caused a request to fail is contained in the error-notes note. By adding the contents of that variable to the log line output to the access log, we can get any request detail we want and the error message at the same time. This trick does not remove a need for the error log but makes forensic log analysis much easier.

8.1.3. Special Logging Modules

Apache processes should never crash, but when they do, a message such as the following will appear in the error log:

[Mon Jul  5 08:33:08 2004] [notice] child pid 1618 exit signal
Segmentation fault (11)

A segmentation fault appears because of an error in Apache code or because a hacker is taking advantage of the web server through a buffer overflow attack. Either way, this is bad and you have to find out why it is happening. Having frequent unexplained segmentation faults is a reason for concern.

Your first impulse after discovering a segmentation fault will probably be to find the request that caused it. Due to the inadequate format of the error log, this may be difficult. Segmentation fault messages appear only in the main error log and not in the virtual hosts. Finding the corresponding request log entry may prove difficult when hosting a server with more than a couple of virtual hosts since the information about which virtual host was being processed at the time is unavailable.

To make the matter worse, the request usually is not logged to the access log. The logging phase is one of the last phases of request processing to take place, so nothing is logged when the server crashes during one of the earlier phases.

The purpose of mod_forensics (available since Versions 1.3.31 and 2.0.50) is to reveal the requests that make the server crash. It does that by having a special log file where requests are logged twice: once at the beginning and once at the end. A special utility script is used to process the log file. If a request appears only once in the log file, we know the server crashed before it could log the request for the second time.

To enable mod_forensics you also need to enable mod_unique_id. After you add the module to your configuration, decide where to put the new log file:

ForensicLog /var/www/logs/forensic_log

After restarting the server, the beginning of each request will be marked with a log of the request data (with headers but excluding the request body). Here is an example:

+QOmjHtmgtpkAADFIBBw|GET /cgi-bin/
Keep-Alive:300|User-Agent:Mozilla/5.0 %28Windows%3b U%3b Windows NT 5.1%3b
en-US%3b rv:1.7%29 Gecko/20040616

For each request that was properly handled, the unique identifier will be written to the log, too:


As you can see, a lot of data is being logged, so implement frequent log rotation for the forensic log. I don't think it is a good idea to leave mod_forensics enabled on a production server because excessive logging decreases performance.

The chances of catching the offending request with mod_forensics are good though in some rare instances this module will fail:

  • If the segmentation fault occurs before mod_forensics gets to log the request into the log

  • If the segmentation fault occurs after mod_forensics writes the second log entry to the log, in which case the complete pair will be in the log in spite of a segmentation fault

Once you figure out the request, you should determine which of the active modules causes it. Your goal here is to determine whether to contact the module author (for a third-party module) or the Apache developers at (for standard modules).

If you have to continue on your own, consider the following tips:

8.1.4. Audit Log

One major disadvantage of Apache's (and most other web servers') logging facilities is that there is no way to observe and log request and response bodies. While most web application attacks take place through GET requests, that is only because they are performed (or programmed) by less capable attackers. The dangerous types will take the extra two minutes to craft a POST request, knowing the chances of the attack being logged are very small.

However, audit logging becomes a possibility with the help of mod_security ( This module (described further in Chapter 12) adds audit logging configuration directives that can be placed almost anywhere in the configuration. It works with the main server, virtual servers, or in a directory context. To specify the audit log file and start audit logging, add the following to your configuration:

SecAuditEngine On
SecAuditLog /var/www/logs/audit_log

After the installation and configuration, you will be able to log the contents of those POST payloads for the first time. Below is an example of an individual audit log entry, where mod_security denied the request because a pattern "333" was detected in the request body. ("333" is not a real attack but something I often use for testing to make sure my configuration works.)

=  =  =  =  =  =  =  =  =  =  =  =  =  =  =  =  =  =  =  =  =  =  = 
Request: - - [29/Jun/2004:12:04:05 +0100] "POST /cgi-bin/
HTTP/1.0" 500 539
Handler: cgi-script
POST /cgi-bin/ HTTP/1.0
Connection: Close
Content-Length: 5
Content-Type: application/x-www-form-urlencoded
User-Agent: mod_security regression test utility
mod_security-message: Access denied with code 500. Pattern match 
"333" at POST_PAYLOAD.
mod_security-action: 500
HTTP/1.0 500 Internal Server Error
Connection: close
Content-Type: text/html; charset=iso-8859-1

The entry begins with a few request identifiers followed by the request headers and the request body, followed by the response headers. The module will automatically detect and make use of the unique ID generated by mod_unique_id. This variable can help track a request over several log files. Currently, the module does not support response body logging, though the filter architecture of Apache 2 allows for it.

Now that we can log request bodies, we will start logging data that is otherwise invisible. Passwords and credit-card numbers are often "hidden" by being transmitted only as part of POST requests but will now appear in plain text in the audit log. This forces us to classify the audit log as an asset and protect it accordingly. Later, you will find recommendations for the treatment of application logs; such treatment can be equally applied to the audit log.

The audit engine of mod_security supports several logging levels (configured with the SecAuditEngine directive):


No logging takes place.


Perform full audit logging. Not recommended since it results in large amounts of data (of small value) in the log file. Besides, static resources do not support POST requests and they cannot be hacked, so it is not useful to log static resource requests.


Only the relevant requests are logged. A request may be marked relevant if it is intercepted by one of the rules in the mod_security configuration or if the response status is out of the ordinary. (By default, response codes 4XX and 5XX will cause the request to be logged into the audit log.)


Logs only dynamic requests and the requests intercepted by mod_security. Static files such as images or documents are ignored. Additional steps are sometimes needed to enable mod_security to distinguish dynamic requests from static ones. (This procedure is described in Chapter 12.)

8.1.5. Performance Measurement

An experimental feature in the Apache 2 version of mod_security adds performance measurement support. Measuring script performance can be difficult because the response is typically generated and transmitted back to the client concurrently. The only measure normally available is the total time it took to process a request. But that number does not mean much. For example, for a client accessing the server over a slow link (e.g., a modem connection), the processing time will be long but that does not indicate a fault.

You can measure performance of individual processes but only if you separate them first. This can be done if the response is not sent to the client as it is being generated. Instead, the response is kept in a memory buffer until generation is complete: This is called buffering. mod_security already introduces buffering into the request processing but for different reasons (security). With buffering in place, performance measurement becomes trivial. mod_security records elapsed time at three points for each request:


Initialization has completed. If the request contains a body, the body will have been read by now (provided POST scanning is enabled in mod_security configuration).


The mod_security rule engine has completed analyzing the request. Now you can see how much overhead mod_security introduces. The request is about to be processed by an Apache handler.


The response has been generated and is about to be sent to the client.

These measurements are useful when used in a custom log together with information provided by the mod_logio module, because to make sense of the numbers you need to know the number of bytes sent to, (format string %I) and from, (format string %O) the server:

CustomLog logs/timer_log "%t \"%r\" %>s - %I %O -\
%{mod_security-time1}n %{mod_security-time2}n \
%{mod_security-time3}n %D

Each entry in the log will look something like this:

[19/Nov/2004:22:30:08 +0000] "POST /upload.php HTTP/1.1" 200
- 21155 84123 - 673761 687806 5995926 7142031

All times are given in microseconds, relative to the beginning of request processing. The following conclusions can be made out of the line given in the previous example (with the figures rounded to the nearest millisecond so they are easier to read):

  • Apache spent 674 milliseconds reading the request (with the body included).

  • mod_security spent 14 milliseconds analyzing the request (time2-time1).

  • The response was generated in 5,308 milliseconds (time3-time2).

  • It took the client 1,146 milliseconds to receive the response (%D-time3).

  • The client sent the request data at approximately 31 KBps (%I/time1).

  • The client received the response data at approximately 72 KBps (%O/(%D-time3)).

8.1.6. File Upload Interception

A special case of audit logging occurs when files are uploaded to the server. Since mod_security supports the multipart/form-data encoding, you can choose to keep the uploaded files:

SecUploadKeepFiles On
SecUploadDir /var/www/logs/files

The SecUploadKeepFiles directive can have one of three possible values:


Files are not kept.


All files are kept.


Only files that are part of a rejected request are kept.

8.1.7. Application Logs

Include the application logs on the list of logs you monitor. At the very least, you should integrate the logs of the application engine with the rest of the logs. For example, configuring PHP to send errors to the Apache error log (described in Chapter 3) removes one thing from the TODO list. For each application, you should do the following:

  1. Determine (from the documentation, or by talking to the programmers) what logs the application produces.

  2. Classify logs according to the material they contain. How sensitive are the application logs? They are often verbose and may contain passwords and credit card numbers.

  3. Implement log rotation.

Consider the following five recommendations to increase the security of your application logs:

  • The application logs will have to be written to by the web server processes and, thus, have to be owned by the web server user. Do not jeopardize the security of the main Apache logs because of that! Create a separate folder in which to keep the application logs and allow the web server process to write there.

  • Being owned by the web server user, application logs are in danger since an attacker will most likely come through the web server. To minimize the danger, implement a custom rotation script to periodically rotate the logs. The idea is to move the logs to a separate directory, change the ownership (to root), and change the permissions (so the web server user cannot get to them any more).

  • If the sensitive data in the log files is not needed (or is needed for a limited time only), consider removing it from the logs at the same time as the rotation.

  • If you can, move the logs from the server altogether. A complete discussion on centralized logging strategies can be found below.

  • If you cannot get the logs out of the server, consider encrypting them on a regular basis with a public encryption key (while not storing the private key on the same server).

8.1.8. Logging as Much as Possible

The default logging format is adequate to generate traffic statistics but inadequate for forensic analysis. We need to use the custom logging facility and design a log format that provides us with the information we need. By starting with the combined log format and adding more fields, we increase the information logged while retaining backward-compatibility with traffic analysis software.

We add six fields to the log format:

POST request body

From the application or mod_security

Unique request identifier

Created by mod_unique_id

Request processing time

From Apache

Session identifier

From the application

Application warning

From the application

Error message

From Apache

The new log format will be shown soon after discussing how the information needed for the additional fields may be obtained. For example, integration with applications is required to achieve adequate logging levels. This comes in two forms: usage of HTTP status codes and integration with PHP. Using HTTP status codes

First, the application must make use of HTTP status codes other than 200 (which is used by default) where appropriate. These codes are very useful but not many applications utilize them. There are five code categories (see Table 8-5).

Table 8-5. HTTP status codes overview

Overall range

Defined range













Client error



Server error

The 4XX category is particularly interesting and is the one we use the most (see Table 8-6).

Table 8-6. HTTP client error status codes

Status code



Bad Request




Payment Required




Not Found


Method Not Allowed


Not Acceptable


Proxy Authentication Required


Request Timeout






Length Required


Precondition Failed


Request Entity Too Large


Request URI Too Long


Unsupported Media Type


Request Range Not Satisfiable


Expectation Failed

With the status codes in mind, Table 8-7 presents the codes an application should return, given various events.

Table 8-7. HTTP status code usage in response to application events


Status code

Prevented hack attempt


Failed login attempt


User is denied access to a resource or an action is forbidden


Page not found (suitable for CMS applications)


Unexpected processing error (e.g., SQL query failed)


At first, I thought using the 401 status would be impossible since it would make the browser ask users to enter their credentials. Having done some tests, I determined that returning the status code alone (without the WWW-Authenticate header) is insufficient to trigger the authentication process. The 401 status can be used after all, and it appears in the access log. Integration with PHP

When installed as a module, PHP integrates with Apache and allows direct communication between modules to take place. Other application engines may provide similar support. We will take advantage of the POST request body being available to the PHP code. We can, therefore, take the body and return it to Apache, along with other parameters known to the application (the username and the session identifier). This is possible because Apache has a feature called notes, which was specifically designed for inter-module communication.

The following code fragment sends some of the information from the PHP module to Apache, where the information is available for other modules to use. It creates four Apache notes: x_username, x_sessionid, x_request, and x_log.

function inform_apache($username, $sessionid) {
    // reconstruct the first line of the request
    $request = $_SERVER["REQUEST_METHOD"];
    $request .= " " . $_SERVER["REQUEST_URI"];
    // add any available POST parameters
    if (count($_POST) != 0) {
        // some POST requests contain parameters in the URI 
        if (strpos($request, "?") =  = false) $request .= "?";
        else $request .= "&";
        $count = 0;
        foreach($_POST as $name => $value) {
            if ($count != 0) $request .= "&";
            $request .= urlencode($name) . "=" . urlencode($value);
    $request .= $_SERVER["SERVER_PROTOCOL"];
    // send the parameters to Apache through notes
    apache_note("x_username", $username);
    apache_note("x_sessionid", $sessionid);
    apache_note("x_request", $request);
    // set an environment variable to trigger
    // conditional logging
    apache_setenv("x_log", "true");

Sending a message from the application to the logging module can be useful. This can be done through a warning note:

function warn_apache($warning) {
    apache_note("x_warning", $warning);
} Recommended log format

Finally, we arrive at our new log format:

LogFormat "%h %l %{x_username}n %t \"%{x_request}n\" %>s %b \"%{Referer}i\" \
\"%{User-Agent}i\" %{UNIQUE_ID}n %T %D %{x_sessionid}n %{x_warning}n \
%{error-notes}n" apptrack

Note the following:

  • The application username takes the place of the HTTP-based username previously obtained via %u.

  • The original request line (obtained via %r) is replaced with our request line (via %{x_request}n), which will include the POST data, too.

  • We use %T 0 for Apache 1 and %T %D for Apache 2. Since Apache 1 does not provide the request processing time in seconds, we will use a zero instead of the actual value to avoid having two log formats. The log processing software must be able to handle the case where this information is unavailable.

We use the new log format together with a conditional logging directive to avoid having bogus lines in the log file:

# log only requests that have the extra PHP-supplied information
CustomLog /var/www/logs/special_log apptrack env=x_log Alternative integration method

If you cannot take advantage of the Apache notes mechanism and the PHP integration (you may not be running PHP as a module, for example), the alternative is to use mod_security to recover the POST request body (it will create the x_request note when configured to do so) and to use response headers to transport the information out of the application. In the application code, send out the session identifier and the username, using headers x_sessionid and x_username. These headers can be logged with %{x_sessionid}o and %{x_username}o, respectively.

header("x_sessionid: $sessionid");
header("x_username: $username");

You will not be able to send a warning from the application using response headers though. Outgoing headers will be visible to the client, too, and using them for a warning may result in revealing critical information to an attacker.

    Team LiB
    Previous Section Next Section