ModSecurity duplicate anomaly logs reported instead of single

Question

This is my second time configuring ModSecurity with the OWASP ruleset. Previously I've used version 2.2.5 of the ruleset and now on a different server 2.2.9.

I'm trying to configure anomaly detection and so I've disabled error.log logging for non-anomalys.

Everything seems to be working however when the anomaly threshold is exceeded, I receive many log entries for the single anomaly. Previously this was just one log entry, and multiple seems excessive.

I'm triggering a simple XSS attack and the error.log shows the following:

[Fri Jul 01 09:25:09.234394 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Pattern match "(?i)(<script[^>]*>[\\\\s\\\\S]*?<\\\\/script[^>]*>|<script[^>]*>[\\\\s\\\\S]*?<\\\\/script[[\\\\s\\\\S]]*[\\\\s\\\\S]|<script[^>]*>[\\\\s\\\\S]*?<\\\\/script[\\\\s]*[\\\\s]|<script[^>]*>[\\\\s\\\\S]*?<\\\\/script|<script[^>]*>[\\\\s\\\\S]*?)" at ARGS:p. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_41_xss_attacks.conf"] [line "14"] [id "973336"] [rev "1"] [msg "XSS Filter - Category 1: Script Tag Vector"] [data "Matched Data: <script>alert('simple-xss-test')</script> found within ARGS:p: <script>alert('simple-xss-test')</script>"] [severity "CRITICAL"] [ver "OWASP_CRS/2.2.9"] [maturity "1"] [accuracy "8"] [tag "OWASP_CRS/WEB_ATTACK/XSS"] [tag "WASCTC/WASC-8"] [tag "WASCTC/WASC-22"] [tag "OWASP_TOP_10/A2"] [tag "OWASP_AppSensor/IE1"] [tag "PCI/6.5.1"] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]
[Fri Jul 01 09:25:09.235629 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Pattern match "(.*)" at TX:950109-OWASP_CRS/PROTOCOL_VIOLATION/EVASION-ARGS:p. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_49_inbound_blocking.conf"] [line "26"] [id "981176"] [msg "Inbound Anomaly Score Exceeded (Total Score: 39, SQLi=14, XSS=12): Last Matched Message: XSS Attack Detected"] [data "Last Matched Data: %3Cscript%3Ealert(%27simple-xss-test%27)%3C/script%3E"] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]
[Fri Jul 01 09:25:09.235701 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Pattern match "(.*)" at TX:960024-OWASP_CRS/WEB_ATTACK/COMMAND_INJECTION-ARGS:p. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_49_inbound_blocking.conf"] [line "26"] [id "981176"] [msg "Inbound Anomaly Score Exceeded (Total Score: 39, SQLi=14, XSS=12): Last Matched Message: XSS Attack Detected"] [data "Last Matched Data: ')</"] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]
[Fri Jul 01 09:25:09.235767 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Pattern match "(.*)" at TX:950901-OWASP_CRS/WEB_ATTACK/SQL_INJECTION-ARGS:p. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_49_inbound_blocking.conf"] [line "26"] [id "981176"] [msg "Inbound Anomaly Score Exceeded (Total Score: 39, SQLi=14, XSS=12): Last Matched Message: XSS Attack Detected"] [data "Last Matched Data: script>alert"] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]
[Fri Jul 01 09:25:09.235834 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Pattern match "(.*)" at TX:981173-OWASP_CRS/WEB_ATTACK/RESTRICTED_SQLI_CHARS-ARGS:p. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_49_inbound_blocking.conf"] [line "26"] [id "981176"] [msg "Inbound Anomaly Score Exceeded (Total Score: 39, SQLi=14, XSS=12): Last Matched Message: XSS Attack Detected"] [data "Last Matched Data: <script>alert('"] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]
[Fri Jul 01 09:25:09.235900 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Pattern match "(.*)" at TX:981243-Detects classic SQL injection probings 2/2-OWASP_CRS/WEB_ATTACK/SQLI-ARGS:p. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_49_inbound_blocking.conf"] [line "26"] [id "981176"] [msg "Inbound Anomaly Score Exceeded (Total Score: 39, SQLi=14, XSS=12): Last Matched Message: XSS Attack Detected"] [data "Last Matched Data: >alert('s"] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]
[Fri Jul 01 09:25:09.236009 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Pattern match "(.*)" at TX:973336-OWASP_CRS/WEB_ATTACK/XSS-ARGS:p. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_49_inbound_blocking.conf"] [line "26"] [id "981176"] [msg "Inbound Anomaly Score Exceeded (Total Score: 39, SQLi=14, XSS=12): Last Matched Message: XSS Attack Detected"] [data "Last Matched Data: <script>alert('simple-xss-test')</script>"] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]
[Fri Jul 01 09:25:09.236075 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Pattern match "(.*)" at TX:973307-OWASP_CRS/WEB_ATTACK/XSS-ARGS:p. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_49_inbound_blocking.conf"] [line "26"] [id "981176"] [msg "Inbound Anomaly Score Exceeded (Total Score: 39, SQLi=14, XSS=12): Last Matched Message: XSS Attack Detected"] [data "Last Matched Data: alert("] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]
[Fri Jul 01 09:25:09.236367 2016] [:error] [pid 17771:tid 139978059269888] [client 81.102.141.69] ModSecurity: Warning. Operator GE matched 15 at TX:inbound_anomaly_score. [file "/etc/apache2/modsecurity-crs/activated_rules/modsecurity_crs_60_correlation.conf"] [line "37"] [id "981204"] [msg "Inbound Anomaly Score Exceeded (Total Inbound Score: 39, SQLi=14, XSS=12): XSS Attack Detected"] [hostname "domain.co.uk"] [uri "/robots.txt"] [unique_id "V3Yo5dRurOYAAEVrxjEAAADJ"]

What seems to be happening is that rule #981176 (the one I understand does the blocking) is logging every single match against the attack, instead of just producing one log entry for the anomaly. As you can see, each line includes the same unique_id

I've compared the old 2.2.5 ruleset against the 2.29 and I cannot see any difference which may cause this.

Ideally I would like a receive one single log entry when an anomaly exceeds the threshold, so that I may investigate in the modsec_audit.log. It was my understand that it should behave this way.

Any ideas how to reduce this to one single log entry as I used to have?

Thanks

Answer 1

This should be set by changing the SecDefaultAction defined in the modsecurity_crs_10_setup.conf file. The default is below (except changed from deny to pass for Anomaly scoring) and will log everything to both error and audit log:

SecDefaultAction "phase:1,pass,log"
SecDefaultAction "phase:2,pass,log"

To just log this in the Audit log use the following:

SecDefaultAction "phase:1,pass,nolog,auditlog"
SecDefaultAction "phase:2,pass,nolog,auditlog"

Is that what is set?

You might be a bit confused as to how this will stop logging the main rules, but not the summary rule (where the anomaly score is checked). The key is that the normal rules (e.g. 960024) don't define the logging and just block based on the defaults, so do depend on these defaults:

"phase:2,capture,t:none,t:urlDecodeUni,block,id:'960024'...etc.

While the rules that check the anomaly scores (e.g. 981176) do explicitly "log" and "deny" so don't need the the defaults to tell it to do this:

"chain,phase:2,id:'981176',t:none,deny,log

This is why changing the default means the core rules don't log in error log but the summary anomaly rules do.

So this should solve the first alert you are incorrectly receiving for rule 973336 as it should not have logged.

What I don't understand however, is why you are receiving several alerts for rule 981176 - one for each rule alerted. That seems wrong to me as it should just log once for the last alert.

However prior to 2.9.1 ModSecurity was using it's own error logging rather than using the standard Apache logging. so it may be worth trying this again after upgrading ModSecurity to 2.9.1. See this bug for more details: https://github.com/SpiderLabs/ModSecurity/pull/840

Alternatively if that doesn't work then try e-mailing [email protected]. and asking there as they may have better understanding of how anomaly scoring logging should work (I don't use it myself to be honest). See https://lists.owasp.org/mailman/listinfo/owasp-modsecurity-core-rule-set for more details of this mailing list.