mod_log_config capabilities

Hello!
We are always happy to offer you new features. Recently Helicon Ape has got mod_log_config - the module for logs tweaking.

Why is it useful? Look, sometimes all of us have troubles. Reason searching may be pretty difficult so some extra help would be great. To log important actions is a good idea. You can always explore and find what's happened. But of course you wanna choose a “verbosity” of logging. That's mod_log_config job. And here you will see the flexibility by yourself. Let's start! ;)

mod_log_config

The module was included in version 1.2.0.18. To enable mod_log_config you must uncomment this line in httpd.conf file:

LoadModule log_config_module modules/mod_log_config.so

3 directives are supported: CustomLog, TransferLog and LogFormat. Let's leave boring directive description for mod_log_config documentation but let us point out that unlike in Apache, in Ape you may write the module configuration everywhere you need (not in server configuration only).

mod_log_config stores files relative to server configuration (httpd.conf). Please note there are potential issues with insufficient permissions.

Simple log

CustomLog my.log "%t %U%q %s"

It's quite simple, isn't it? You will get messages like

[13/Apr/2009:04:49:21 +0300] /index.php?q=1 200

Getting more

Numerous format strings are at your disposal. You may catch HTTP-headers, information about each request and so on and so forth. The configuration below could be useful to store an information about each request:

CustomLog access.log "%t %a,%{User-Agent}i %U%q %s"

Here is the result:

[14/Apr/2009:05:09:32 +0300] 127.0.0.1,Opera/9.64 (Windows NT 6.0; U; en) Presto/2.1.1 /iisstart.htm 200
[14/Apr/2009:05:09:32 +0300] 127.0.0.1,Opera/9.64 (Windows NT 6.0; U; en) Presto/2.1.1 / 200
[14/Apr/2009:05:09:32 +0300] 127.0.0.1,Opera/9.64 (Windows NT 6.0; U; en) Presto/2.1.1 /welcome.png 304
[14/Apr/2009:05:09:32 +0300] 127.0.0.1,Opera/9.64 (Windows NT 6.0; U; en) Presto/2.1.1 /favicon.ico 404

Perhaps you think the game is not worth the candle because there are IIS logs available. Yep, that's right. More useful way is to have separate logs for some interesting requests.

Per status code differentiation

We all like HTTP status 200. It means 'OK' and that's why we're not interested in loging it. Most common situation is when we are looking for some psecific status code in the logs. With mod_log_config you may create separate logs for every needed status. Please look at this configuration:

CustomLog ok.log "%200t %200a,%200{User-Agent}i %200U%200q %200s"
CustomLog redirections.log "%301t %301a,%301{User-Agent}i %301U%301q %301s"
CustomLog not_found.log "%404t %404a,%404{User-Agent}i %404U%404q %404s"
CustomLog server_error.log "%500t %500a,%500{User-Agent}i %500U%500q %500s"

There are four log files for four statuses: 200 - OK, 301 - permanent redirect, 404 - file not found, 500 - internal server error. Log records will look like:

[22/Apr/2009:03:05:51 +0300] 127.0.0.1,Opera/9.64 (Windows NT 6.0; U; en) Presto/2.1.1 /iisstart.htm 200

Pretty good thing except one nuance: when status doesn't match each log will contain a non-informative record like this:

- -,- -- -

Why? Because we didn't link each CustomLog directive with a status code. Instead of that we linked format strings. The configuration below is 100% compatible with Apache and Ape emulates its behaviour. We decided it isn't usable and implemented some extra features.

Our hacking module - mod_setenvif is becoming a kind of programming language;) It has very nice features to evaluate various conditions. So we've upgraded the module and now you may use the following syntax:

SetEnvIf status_code = 200 STATUS_OK
SetEnvIf status_code = 301 STATUS_REDIRECTION
SetEnvIf status_code = 404 STATUS_NOTFOUND
SetEnvIf status_code = 500 STATUS_ERROR

CustomLog ok.log "%t %a,%{User-Agent}i %U%q %s" env=STATUS_OK
CustomLog redirections.log "%t %a,%{User-Agent}i %U%q %s" env=STATUS_REDIRECTION
CustomLog not_found.log "%t %a,%{User-Agent}i %U%q %s" env=STATUS_NOTFOUND
CustomLog server_error.log "%t %a,%{User-Agent}i %U%q %s" env=STATUS_ERROR

Of course it isn't compatible with Apache. But with this syntax each file will have only sensible records. Four mod_setenvif rules compare HTTP status retrieved from the server and set environment variables. Each mod_log_config rule is waiting for its own variable and if it exists then the rule fires.

Long requests

There is quite simple solution for long requests logging. The solution isn't Apache compatible. Here it is:

SetEnvIf request_duration > 1000 LONG_REQUEST
CustomLog long_requests.log "%t %a,%{User-Agent}i %U%q %s, duration=%D"

It gives an output like:

[22/Apr/2009:03:05:51 +0300] 127.0.0.1,Opera/9.64 (Windows NT 6.0; U; en) Presto/2.1.1 /iisstart.htm 200, duration=26366

mod_setenvif compares a duration with 1000 microseconds and sets LONG_REQUEST environment variable in case the duration really exceedes specified limit. Then mod_log_config processes CustomLog directive in case LONG_REQUEST variable exists. Easy, isn't it? Well, let's see one more finger-licking good thing;)

Binding with modules

mod_log_config supports very useful format - %{module_note}n. The other Ape's modules can store theirs own variables which are available through this format. It gives a cool opportunity to track modules operation. Currently only three modules use this feature: mod_gzip,  mod_auth_basic and  mod_auth_digest.

GZIP compression statistic

The feature described above allows us to get some statistic information about mod_gzip work results. Please try out the following:

CustomLog mod_gzip.log "%h %u %t \"%V %r\" %s %{mod_gzip_result}n \
 In:%{mod_gzip_input_size}n -< Out:%{mod_gzip_output_size}n = %{mod_gzip_compression_ratio}n pct."

mod_gzip.log records will look like:

127.0.0.1  [22/Apr/2009:03:37:10 +0300] "localhost GET /iisstart.htm HTTP/1.1" 200 compressed In:689 -< Out:442 = 35,84906 pct

Authentication catching

If you want to know which users have been authenticated and which haven't, you should use something like that:

SetEnvIf status_code = 401 STATUS_UNAUTHORIZED
SetEnvif status_code = 200 STATUS_OK
CustomLog authorized.log "%t %a,%{User-Agent}i,name=%u %U%q %s" env=STATUS_OK
CustomLog unauthorized.log "%t %a,%{User-Agent}i,[usr=%{auth_failed_username}n] %U%q %s" env=STATUS_UNAUTHORIZED

authorized.log:

[22/Apr/2009:04:11:41 +0300] 192.168.1.84,r2d3,name=user1 /ape/auth/basic/file/groupfile/index.html 200

unauthorized.log:

[22/Apr/2009:04:12:30 +0300] 192.168.1.84,r2d2,[usr=user1] /ape/mod_rewrite/proxy/auth-basic/index.htm 401

Looking forward

Much more modules will be configured to work with mod_log_config in the future. Also using customers responses we are going to improve and extend the module features. We hope you will like the functionality Helicon Ape has got.

Best wishes,
HeliconTech Team