Why is apache writing two access log outputs per request?

Question

We are currently running a apache2/mod-php site on docker, deployed to google kubernetes. In order to leverage the severity level filtering of google cloud logging I've created a LogFormat in our apache.conf that writes the logs output as structured JSON. Now I'm seeing two access log outputs in our logs. 1 is the correctly formatted CustomLog and the other seems to be a default access log of some sort.

Here's the apache conf:

  1 LogLevel info
  2 
  3 LogFormat "{\"message\": \"%{X-Forwarded-For}i %l %u %t '%r' %>s %b '%{Referer}i' '%{User-Agent}i'\", \"severity\": \"INFO\"}" common
  4 CustomLog /dev/stderr common
  5 
  6 
  7 ErrorLogFormat "{\"message\": \"[%t] [%l] [pid %P] %F: %E: [client %a] %M\", \"severity\": \"ERROR\"}"
  8 ErrorLog /dev/stderr
  9 
 10 <VirtualHost *:80>
 11   ServerName myhost.com
 12   ServerAlias myhost.com
 13   DocumentRoot /var/www/html/public/
 14 
 15   <Directory />
 16     AllowOverride All
 17     Order allow,deny
 18     Allow from all
 19 
 20     RewriteEngine on
 21     RewriteCond %{REQUEST_FILENAME} !-d
 22     RewriteCond %{REQUEST_FILENAME} !-f
 23     RewriteRule ^(.*)$ index.php?%{QUERY_STRING} [L]
 24   </Directory>
 25 
 26   <Directory ~ "\.svn">
 27     Order allow,deny
 28     Deny from all
 29   </Directory>
 30 
 31   <Directory ~ "\.git">
 32     Order allow,deny
 33     Deny from all
 34   </Directory>
 35 
 36   RemoteIPHeader X-Forwarded-For
 37   RemoteIPTrustedProxy 10.0.0.0/24
 38 
 39 </VirtualHost>

My error logs and info logs are showing up correctly in google cloud storage. However I keep seeing other access log entries.

Samples:

This log should not show up

::1 - - [13/May/2016:23:32:06 +0000] "GET /server-status?auto HTTP/1.1" 404 2970 "-" "Sysdig Agent/1.0"

This log should show up

{"message": "- - - [13/May/2016:23:32:06 +0000] 'GET /server-status?auto HTTP/1.1' 404 2720 '-' 'Sysdig Agent/1.0'", "severity": "INFO"}

I've tried a number of different configurations and none of them seem to fix the problem. Any idea where this unwanted access log output is coming from?

Do you have any other `CustomLog` directive in any other config file? As noted in [Access Log documentation](http://httpd.apache.org/docs/2.4/logs.html#accesslog), "Multiple access logs can be created simply by specifying multiple CustomLog directives in the configuration file." — Colt, May 14 '16 at 02:00

score 1 · Accepted Answer · answered May 16 '16 at 17:03

So it looks like this version of php-apache for docker: FROM php:5.5-apache sends a custom log output to the process out. This makes sense as you would want docker log to actually output something when run.

To remedy this issue we will comment out the following lines:

45 LogFormat "%v:%p %h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" vhost_combined
46 LogFormat "%h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" combined
47 LogFormat "%h %l %u %t \"%r\" %>s %O" common
48 LogFormat "%{Referer}i -> %U" referer
49 LogFormat "%{User-agent}i" agent
50 
#51 CustomLog /proc/self/fd/1 combined

Why is apache writing two access log outputs per request?

1 Answers1