Many online applications use a web server as the primary point of contact for their clients. At least 43% of those systems are running the Apache HTTP Server. If you’re responsible for one of those systems, you need to work with the Apache error log.
Apache provides comprehensive logging via several different files, but the error log is the most important. You can even say Apache misnamed the file because it contains more than just errors. Apache records a large amount of diagnostic information in the error log. You have control over where it stores the messages and what information goes into them.
Let’s dive in and see how you can use the Apache error log to watch your web server and improve its reliability and resiliency.
You configure the error log with a set of directives that, like all Apache configuration values, you place in plain text files. I’ll be referring to the latest release of the web server in this post, which is 2.4 as of this writing.’
You can find details for how to set up configuration files for Apache here. I’ll cover the settings for the Apache error log in this post.
The ErrorLog configuration setting controls the location of the Apache error log file. Here’s the default setting for the Apache2 docker image:
#
# ErrorLog: The location of the error log file.
# If you do not specify an ErrorLog directive within a <VirtualHost>
# container, error messages relating to that virtual host will be
# logged here. If you *do* define an error logfile for a <VirtualHost>
# container, that host's errors will be logged there and not here.
#
ErrorLog /proc/self/fd/2
This configuration directs the logs to standard error, which is a sensible setting for most Docker environments.
You can enter any valid filename and the Apache will use it.
ErrorLog "/var/log/apache2/error.log"
If the file already exists, Apache will append new messages to it. So if you want to rotate log files to keep them from getting too large, you need to set something up on your own.
You can also send log messages to a Syslog server. Instead of a filename, use the Syslog directive.
ErrorLog syslog
The Syslog option has several different choices about the logging facility and the application name. You can find the details here.
Finally, you can direct logs to a Linux command.
ErrorLog "|/usr/local/bin/httpd_errors"
Apache interprets the pipe character to mean it should pipe the messages to the specified command.
The Apache error log has a logging level that filters the messages sent to the log. You specify the level with the LogLevel setting.
#
# LogLevel: Control the number of messages logged to the error_log.
# Possible values include: debug, info, notice, warn, error, crit,
# alert, emerg.
#
LogLevel warn
The Apache documentation describes the levels this way:
| Level | Description |
|---|---|
| emerg | System is unusable |
| alert | Action must be taken immediately |
| crit | Critical conditions |
| error | Error conditions |
| warn | Warning conditions |
| notice | Normal, but significant conditions |
| info | Informational messages |
| debug | Debugging messages |
| trace1 – trace8 | Trace messages with gradually increasing levels of detail |
Let’s make a quick comparison of the warn and debug levels. I’ll request a valid page and then an invalid one with each level.
Apache logs nothing for a single page request in warn level.
But, here’s the same request in debug level:
[Fri Feb 01 22:03:08.318615 2019] [authz_core:debug] [pid 9:tid 140597881775872] mod_authz_core.c(820): [client 172.17.0.1:50752] AH01626: authorization result of Require all granted: granted
[Fri Feb 01 22:03:08.319124 2019] [authz_core:debug] [pid 9:tid 140597881775872] mod_authz_core.c(820): [client 172.17.0.1:50752] AH01626: authorization result of <RequireAny>: granted
[Fri Feb 01 22:03:08.319709 2019] [authz_core:debug] [pid 7:tid 140597881775872] mod_authz_core.c(820): [client 172.17.0.1:50750] AH01626: authorization result of Require all granted: granted
[Fri Feb 01 22:03:08.320285 2019] [authz_core:debug] [pid 7:tid 140597881775872] mod_authz_core.c(820): [client 172.17.0.1:50750] AH01626: authorization result of <RequireAny>: granted
[Fri Feb 01 22:03:08.320970 2019] [core:info] [pid 7:tid 140597881775872] [client 172.17.0.1:50750] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
[Fri Feb 01 22:03:08.960056 2019] [authz_core:debug] [pid 7:tid 140597873383168] mod_authz_core.c(820): [client 172.17.0.1:50750] AH01626: authorization result of Require all granted: granted
[Fri Feb 01 22:03:08.960641 2019] [authz_core:debug] [pid 7:tid 140597873383168] mod_authz_core.c(820): [client 172.17.0.1:50750] AH01626: authorization result of <RequireAny>: granted
[Fri Feb 01 22:03:08.961235 2019] [core:info] [pid 7:tid 140597873383168] [client 172.17.0.1:50750] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
[Fri Feb 01 22:03:09.025752 2019] [authz_core:debug] [pid 7:tid 140597864990464] mod_authz_core.c(820): [client 172.17.0.1:50750] AH01626: authorization result of Require all granted: granted
[Fri Feb 01 22:03:09.026205 2019] [authz_core:debug] [pid 7:tid 140597864990464] mod_authz_core.c(820): [client 172.17.0.1:50750] AH01626: authorization result of <RequireAny>: granted
[Fri Feb 01 22:03:09.026647 2019] [core:info] [pid 7:tid 140597864990464] [client 172.17.0.1:50750] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
[Fri Feb 01 22:03:13.885995 2019] [authz_core:debug] [pid 7:tid 140597856597760] mod_authz_core.c(820): [client 172.17.0.1:50750] AH01626: authorization result of Require all granted: granted
You can see that the authz_core module is very noisy. If you want to watch the logs for other modules while filtering out messages from it, you can set its log level explicitly.
LogLevel debug authz_core:info
This setting sets the server for debug, but explicitly filters the authz_core back to info.
Let’s try the page request again.
[Fri Feb 01 22:07:57.154391 2019] [core:info] [pid 10:tid 140284200093440] [client 172.17.0.1:50756] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
[Fri Feb 01 22:07:57.808291 2019] [core:info] [pid 8:tid 140284216878848] [client 172.17.0.1:50758] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
[Fri Feb 01 22:07:57.878149 2019] [core:info] [pid 8:tid 140284208486144] [client 172.17.0.1:50758] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
We can see that the real problem with my web server is no favicon and my browser is very upset about it.
You can change the format of log messages too. So far, I’ve been using the default format. You specify the message composition with the ErrorLogFormat setting.
Let’s try a different setting and look at the difference. I’ll use this example from the Apache docs.
ErrorLogFormat "[%t] [%l] [pid %P] %F: %E: [client %a] %M"
Here’s what a request looks like now:
[Fri Feb 01 22:17:49 2019][info] [pid 9] core.c(4739): [client 172.17.0.1:50764] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
Let’s go over how this format works. The setting is a format string with parameters corresponding to fields in a logging event.
Here are the fields we used above:
| Item | Explanation |
|---|---|
| [%t] | timestamp for the message |
| [%l] | level of the message |
| [pid %P] | process pid |
| %F | source code file and line |
| %E | error status code and string |
| %a | client IP address and string |
| %M | the log message |
The sample log message lacks a message for the %E setting, so it’s missing. The Apache error log doesn’t fill missing parameters. It omits them.
You can specify different formats for new connections and new requests. A connection is when a new client connects to the server. A request is a message asking for a resource, such as a page or an image. Apache uses connection and request formats when a new client connects or makes a web request. It logs a message indicating that a client has connected or registered a new request.
Let’s add a new LogFormat for a connection.
ErrorLogFormat connection "[%t] First time: [pid %P] %F: %E: [client %a]"
ErrorLogFormat "[%t] [%l] [pid %P] %F: %E: [client %a] %M"
The new entry prints a “First time:” message along with the fields we’ve defined for our standard log format. But we had to omit %M since there’s no error message corresponding to a new connection.
Now, we’ll make our single-page request again.
[Fri Feb 01 22:44:09 2019] First time: [pid 9] [client 172.17.0.1:50770]
[Fri Feb 01 22:44:09 2019] [info] [pid 9] core.c(4739): [client 172.17.0.1:50770] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
We see the initial connection message and then the failed request for a favicon.
You can specify more than one connection or request log entry if you want to print information in separate listings.
You can take logging messages for new connections and requests one step further. The Apache error log will generate a unique identifier for every new request or connection. You can use this value to collate log entries. Use the %L field for identifiers.
So let’s change our configuration to reflect a new entry for each connection and request. Then, we’ll add the IDs to the standard log message.
ErrorLogFormat connection "[%t] New connection: [connection: %{c}L] [client %a]"
ErrorLogFormat request "[%t] New request: [connection: %{c}L] [request: %L] [pid %P] %F: %E: [client %a]"
ErrorLogFormat "[%t] [%l] [C: %{c}L] [R: %L] [pid %P] %F: %E: [client %a] %M"
So in the connection entry, we generate a connection identifier with %{c}L. In the request entry, we print the connection ID and then generate a request ID with %L. Finally, we add the IDs to each standard log entry.
Here is a page request:
[Sat Feb 02 00:30:55 2019] New connection: [connection: j8BjX4Z5tjk] [client 172.17.0.1:50784]
[Sat Feb 02 00:30:55 2019] New request: [connection: j8BjX4Z5tjk] [request: p7pjX4Z5tjk] [pid 8] [client 172.17.0.1:50784]
[Sat Feb 02 00:30:55 2019] [info] [C: j8BjX4Z5tjk] [R: p7pjX4Z5tjk] [pid 8] core.c(4739): [client 172.17.0.1:50784] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico
[Sat Feb 02 00:30:55 2019] New request: [connection: j8BjX4Z5tjk] [request: ACtkX1Z5tjk] [pid 8] [client 172.17.0.1:50784]
[Sat Feb 02 00:30:55 2019] [info] [C: j8BjX4Z5tjk] [R: ACtkX1Z5tjk] [pid 8] core.c(4739): [client 172.17.0.1:50784] AH00128: File does not exist: /usr/local/apache2/htdocs/foo.gif
[Sat Feb 02 00:30:55 2019] New connection: [connection: gTxkX8Z6tjk] [client 172.17.0.1:50786]
[Sat Feb 02 00:30:55 2019] New request: [connection: gTxkX8Z6tjk] [request: 5TVkX8Z6tjk] [pid 8] [client 172.17.0.1:50786]
[Sat Feb 02 00:30:55 2019] [info] [C: gTxkX8Z6tjk] [R: 5TVkX8Z6tjk] [pid 8] core.c(4739): [client 172.17.0.1:50786] AH00128: File does not exist: /usr/local/apache2/htdocs/bar.gif
[Sat Feb 02 00:30:55 2019] New request: [connection: gTxkX8Z6tjk] [request: wvRoX3Z6tjk] [pid 8] [client 172.17.0.1:50786]
[Sat Feb 02 00:30:55 2019] [info] [C: gTxkX8Z6tjk] [R: wvRoX3Z6tjk] [pid 8] core.c(4739): [client 172.17.0.1:50786] AH00128: File does not exist: /usr/local/apache2/htdocs/foobar.gif
[Sat Feb 02 00:30:55 2019] New request: [connection: gTxkX8Z6tjk] [request: i/JtX9Z7tjk] [pid 8] [client 172.17.0.1:50786]
Now we can see each connection and request as they’re created. I added a few bad image tags to the request page to generate extra traffic.
Apache is a mature web server with powerful tools for monitoring. You can configure its robust logging in a way that suits your application and monitoring needs.
You can collect Apache error logs with Stackify’s Retrace. Configure the Stackify agent to watch your weblogs by following the instructions here.
Stackify's APM tools are used by thousands of .NET, Java, PHP, Node.js, Python, & Ruby developers all over the world.
Explore Retrace's product features to learn more.
If you would like to be a guest contributor to the Stackify blog please reach out to [email protected]
