Home > OS >  Strange Apache CustomLog behavior
Strange Apache CustomLog behavior

Time:10-08

I'm adding a Docker healthcheck function which I've successfully done in one container, but adding the same code to a different container is behaving strangely.

Essentially, I'm simply trying to not log certain requests, using an env var.

In dockerfile:

HEALTHCHECK CMD curl -ILfSs http://localhost:80 -A "HealthCheck" || exit 1

RUN ln -sf /dev/stdout /var/www/logs/access.log \
    && ln -sf /dev/stdout /var/www/logs/transfer.log \
    && ln -sf /dev/stdout /var/www/logs/ssl-transfer.log \
    && ln -sf /dev/stderr /var/www/logs/error.log \
    && ln -sf /dev/stderr /var/www/logs/ssl-error.log

In httpd.conf:

<IfModule log_config_module>
    LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined
    LogFormat "%h %l %u %t \"%r\" %>s %b" common

    <IfModule logio_module>
      LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %I %O" combinedio
    </IfModule>

    <IfModule setenvif_module>
       BrowserMatchNoCase ^healthcheck nolog
    </IfModule>

    CustomLog "logs/access.log" combinedio env=!nolog

</IfModule>

So now when the healthcheck ticks, the log which would normally show this:

127.0.0.1 - - [05/Oct/2022:03:22:13  0000] "HEAD / HTTP/1.1" 200 - "-" "HealthCheck" 74 1095

shows this (it shouldn't be showing anything at all since the env var gets set when the UserAgent matches 'healthcheck'):

127.0.0.1 - - [05/Oct/2022:05:17:46  0000] "HEAD / HTTP/1.1" 200 -

It acts almost as if it's doing a replace of everything that matches 'healthcheck' and after, with nothing at all (empty string), which I don't think it's even supposed to be capable of doing(?).

I've tested to make sure that the only healthcheck being called is this one in httpd.conf by commenting out the BrowserMatchNoCase ^healthcheck nolog line, and it indeed then just shows the usual, expected line containing the "HealthCheck" useragent.

CodePudding user response:

If the expected condition isn't matching AND the format is wrong, the simplest explanation is that you have a 2nd CustomLog directive in your configuration.

Additionally, I would remove all of the ifmodules. You don't want this stuff being skipped if the modules aren't loaded, you want it to fail.

CodePudding user response:

Mystery solved; there was a "hidden" TransferLog in the configs duking it out with my CustomLog, so my stuff was actually working as intended, but the TransferLog was also being called, so they were both outputting to the log at the same time for each HealthCheck call.

I say "hidden" because even though it was there in plain sight, it was the first time I've personally encountered the TransferLog directive; I've always just used CustomLog, and wasn't aware how TransferLog worked in combination with CustomLog when they're both present.

Removing TransferLog entirely and only using CustomLog (because it allows log formatting whereas TransferLog doesn't) did the trick.

  • Related