ModSecurity icon indicating copy to clipboard operation
ModSecurity copied to clipboard

Inconsistent Error Log Format of ModSecurity depending on Apache's ErrorLogFormat directive

Open dune73 opened this issue 1 month ago • 2 comments

There is a funny behavior in the 2.9.x release line that I discovered yesterday.

ModSec 2.9.x has a habit of writing a prefix into the error log: [client <IP Address>] ModSecurity: ...

Starting 2.9.8 and following a merge of a bugfix by Marc Stern (https://github.com/owasp-modsecurity/ModSecurity/pull/3192), this prefix in square brackets disappears when you configure ErrorLogFormat in Apache. If you do not configure said directive, the [client ...] prefix remains, but the IP is accompanied by a colon and the client port number.

Up to 2.9.7, the Apache error log format would not change the behavior of ModSecurity. It would simply allow you to define the Apache prefix (e.g. format of the timestamp, severity etc.).

But now suddenly ModSecurity reacts to this as well. I am not sure this can be considered a bug. But it's certainly undocumented behavior.

Example ModSec 2.9.7 with ErrorLogFormat (-> ErrorLogFormat "[%{cu}t] [%-m:%-l] %-a %-L %M"):

[2025-12-02 11:46:39.609045] [security2:error] 127.0.0.1:48024 aS7Djwp_d4rQSzSzUpsP1wAAAAE [client 127.0.0.1] ModSecurity: Warning. Matched phrase "etc/passwd" at ARGS:test. [file "/home/dune73/crs/rules/REQUEST-930-APPLICATION-ATTACK-LFI.conf"] [line "118"] [id "930120"] [msg "OS File Access Attempt"] [data "Matched Data: etc/passwd found within ARGS:test: /etc/passwd"] [severity "CRITICAL"] [ver "OWASP_CRS/4.21.0-dev"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-lfi"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "OWASP_CRS/ATTACK-LFI"] [tag "capec/1000/255/153/126"] [hostname "localhost"] [uri "/index.html"] [unique_id "aS7Djwp_d4rQSzSzUpsP1wAAAAE"]

Example ModSec 2.9.8 with ErrorLogFormat:

[2025-12-02 11:47:02.523759] [security2:error] 127.0.0.1:43714 aS7DpilIiJN1A-ostwkEZQAAAAA ModSecurity: Warning. Matched phrase "etc/passwd" at ARGS:test. [file "/home/dune73/crs/rules/REQUEST-930-APPLICATION-ATTACK-LFI.conf"] [line "118"] [id "930120"] [msg "OS File Access Attempt"] [data "Matched Data: etc/passwd found within ARGS:test: /etc/passwd"] [severity "CRITICAL"] [ver "OWASP_CRS/4.21.0-dev"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-lfi"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "OWASP_CRS/ATTACK-LFI"] [tag "capec/1000/255/153/126"] [hostname "localhost"] [uri "/index.html"] [unique_id "aS7DpilIiJN1A-ostwkEZQAAAAA"]

Example ModSec 2.9.8 without ErrorLogFormat:

[Tue Dec 02 11:47:30.996655 2025] [security2:error] [pid 2150210:tid 2150239] [client 127.0.0.1:38370] ModSecurity: Warning. Matched phrase "etc/passwd" at ARGS:test. [file "/home/dune73/crs/rules/REQUEST-930-APPLICATION-ATTACK-LFI.conf"] [line "118"] [id "930120"] [msg "OS File Access Attempt"] [data "Matched Data: etc/passwd found within ARGS:test: /etc/passwd"] [severity "CRITICAL"] [ver "OWASP_CRS/4.21.0-dev"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-lfi"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "OWASP_CRS/ATTACK-LFI"] [tag "capec/1000/255/153/126"] [hostname "localhost"] [uri "/index.html"] [unique_id "aS7DwtEn2rWqwBtW5o1hlQAAAAA"]

dune73 avatar Dec 02 '25 10:12 dune73

Maybe I don't fully understand the problem, so I tried to reproduce the behavior.

Here is the error log what I get without any kind of custom ErrorLogFormat directive:

[Tue Dec 02 21:02:01.527260 2025] [security2:error] [pid 342774:tid 342822] [client 172.35.40.12:48536] ModSecurity: Warning. Matched phrase ...
[Tue Dec 02 21:02:01.543070 2025] [security2:error] [pid 342774:tid 342822] [client 172.35.40.12:48536] ModSecurity: Access denied with code 403 (phase 2). Operator GE ...
[Tue Dec 02 21:02:01.543742 2025] [security2:error] [pid 342774:tid 342822] [client 172.35.40.12:48536] ModSecurity: Warning. ...

And I a bit changed your format and passed to the server:

    ErrorLogFormat "[%{cu}t] [%-m:%-l] [client %-a] %M"

(I put the [client ...] boundaries)

With this modification I get these lines:

[2025-12-02 21:03:00.330766] [security2:error] [client 172.35.40.12:45498] ModSecurity: Warning. Matched phrase ...
[2025-12-02 21:03:00.348033] [security2:error] [client 172.35.40.12:45498] ModSecurity: Access denied with code 403 (phase 2). Operator GE ...
[2025-12-02 21:03:00.348810] [security2:error] [client 172.35.40.12:45498] ModSecurity: Warning. ...

Is this what you want achieve?

airween avatar Dec 02 '25 20:12 airween

Well, up to 2.9.7 I got

[2025-12-02 11:46:39.609045] [security2:error] 127.0.0.1:48024 aS7Djwp_d4rQSzSzUpsP1wAAAAE [client 127.0.0.1] ModSecurity: Warning. ...

That is the client IP without the port number. And I do not see a way to have Apache immitate ModSec by setting a naked IP address.

The change is no big deal for IPv4, but with IPv6 it is difficult to accomodate to all the options and different formats with the same parser, thus:

  • IPv4 without port number included
  • IPv4 with port number included
  • IPv6 without port number included
  • IPv6 with port number included

Again, I am not sure this can be really considered a bug. It is a surprising behavior that reacts to Apache config changes in an unpredicted way and that leads to troubles downstream, but it is not a problem per se.

dune73 avatar Dec 03 '25 07:12 dune73

I remember this modification from @marcstern, and remember that there was a related issue which was fixed by @RedXanadu in 652b942. (The problem was that if someone uses the mod_security2 module as a standalone module, then the client IP disappeared.)

Is there anything we can do to make it easier to use?

I see your arguments here (parsing IPv6 addresses with port numbers is hard), but I agree too that duplicate the same information is not healthy.

And making this configurable... I'm not sure that's worth.

airween avatar Dec 13 '25 15:12 airween

Maybe the problem is Apache not giving an option to write the IP address without the port number in the error.log. I'd probably keep it as is for the time being. It's a pity the behavior was not documented, when this was introduced.

dune73 avatar Dec 13 '25 16:12 dune73

Unfortunately the documentation does not include any description about log format at all. Now I reviewed the reference and tried to figure out, what would be the best place, but I think we should add a completely new block (both cases for v2 and v3) where we describe the log syntax.

(Any help from anyone are welcome 😃)

airween avatar Dec 13 '25 16:12 airween

Yes, that's probably the most reasonable thing one can do right now.

dune73 avatar Dec 13 '25 16:12 dune73