Apache HTTPD logging
In this post, I’d like to show some examples of how to extend Apache HTTPD logging so that there is additional information available for debugging requests that fail.
Introduction
There are two log files that Apache HTTPD writes to by default. These are the access_log and error_log. The access_log records all requests that are served by the Apache HTTPD server. The information that gets logged is controlled by the LogFormat and CustomLog directives.
The default Apache HTTPD log format for the error_log file is controlled by the ErrorLogFormat directive.
In case of the LogFormat directive, it is possible to define multiple instances of this directive and associate these with identifiers
The identifier is then used with CustomLog directive along with a log filename as shown below.
LogFormat "%h %l %u %t \"%r\" %>s %b" common
CustomLog logs/access_log commonLogFormat "%h %u %t \"%r\" \"{User-Agent}i"\ %>s" ua_fmt
CustomLog logs/ua_log ua_fmt
Unique identifiers for requests
It is very helpful to associate an unique identifier with every request, so that it is possible to trace the request across access_log and error_log.
Apache HTTPD is a multi-process, multi-thread system with multiple threads logging to the log files. As a consequence of this, the log messages pertaining to a single request are not sequential. The log messages of multiple requests are interleaved, making debugging hard. In such a scenario, it is helpful to associate an unique identifier with every request. This allows one to grep for the unique identifier and collect all messages pertaining to that identifier in a sequential order for analysis.
An unique identifier is generated by loading the mod_unique_id module.
The log formats for access_log and error_log must then be modified to add the unique identifier.
Config snippet for loading mod_unique_id.so
LoadModule unique_id_module modules/mod_unique_id.so
Config snippet for adding unique identifier to access log:
Add %{UNIQUE_ID}e to the LogFormat directiveLogFormat "%h %l %u %t \"%r\" %>s %b %{UNIQUE_ID}e" common
Config snippet for adding unique identifier to error log:
Add %L to the ErrorLogFormat directiveErrorLogFormat "[%{u}t] [%-m:%l] [pid %P:tid %T] %7F: %E: [client\ %a] %M% ,\ referer\ %{Referer}i %L"