Mod_security not actually blocking requests despite rule trigger & returning 403

I've pulled my finger out and installed mod_security to protect our WHMCS installation (a PHP based billing system) from some of the more obvious SQL injection attacks to try and minimise our susceptibility to being hit in the window of opportunity between a vulnerability becoming known and us finding out about it (at which point we deploy IP ACL or new mod_security rules as appropriate, and patch when a fix is available)

Problem is, I've got some rules I've picked up from WHT which on paper look good, and when I test them, mod_security appears to be doing it's thing – the malicious client gets shunted off to a 403, but the POST data appears to still be reaching the PHP script because the database content is changing.

PHP is running with suPHP; it's not clear to me from google searches if this is a possible cause of problems – I can't imagine it's all that uncommon a configuration.

To my mind the likely cause is that despite mod_security being set to deny it will still generate the intermediary response body (as evidenced by the fact it can log it, under type E) – this of course involves submitting the data I want to stop being submitted in the first place! However, even if I set SecResponseBodyAccess to Off, it does not stop the data being submitted – and to be honest, I would not unreasonably expect a deny/drop rule triggered during the request stage to prevent any attempt to generate the response body.

Anyone able to shed some light on this? Is there a bug in this version of mod_security (seems unlikely I'd be the first to notice), are the rules I picked up defective (possible), or is there just a stupid mistake somewhere in my configuration (most likely)?

This is a Debian Squeeze system; possibly relevant packages:

ii  apache2                             2.2.16-6+squeeze11                Apache HTTP Server metapackage
ii  libapache2-mod-suphp                0.7.1-1                           Apache2 module to run php scripts with the owner permissions
ii  libapache2-modsecurity              2.6.6-6~bpo60+1                   Tighten web applications security for Apache

/etc/apache2/mods-enabled/modsecurity.load

LoadFile /usr/lib/libxml2.so.2
LoadModule security2_module /usr/lib/apache2/modules/mod_security2.so

/etc/apache2/mods-enabled/modsecurity.conf

<IfModule security2_module>
        # Default Debian dir for modsecurity's persistent data
        SecDataDir /var/cache/modsecurity

        # Include all the *.conf files in /etc/modsecurity.
        # Keeping your local configuration in that directory
        # will allow for an easy upgrade of THIS file and
        # make your life easier
        Include "/etc/modsecurity/*.conf"
</IfModule>

/etc/modsecurity/modsecurity.conf
(largely unchanged from the Debian default recommended config – other than to change SecRuleEngine DetectionOnly to On)

# -- Rule engine initialization ----------------------------------------------

# Enable ModSecurity, attaching it to every transaction. Use detection
# only to start with, because that minimises the chances of post-installation
# disruption.
#
SecRuleEngine On


# -- Request body handling ---------------------------------------------------

# Allow ModSecurity to access request bodies. If you don't, ModSecurity
# won't be able to see any POST parameters, which opens a large security
# hole for attackers to exploit.
#
SecRequestBodyAccess On


# Enable XML request body parser.
# Initiate XML Processor in case of xml content-type
#
SecRule REQUEST_HEADERS:Content-Type "text/xml" \
     "phase:1,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML"


# Maximum request body size we will accept for buffering. If you support
# file uploads then the value given on the first line has to be as large
# as the largest file you are willing to accept. The second value refers
# to the size of data, with files excluded. You want to keep that value as
# low as practical.
#
SecRequestBodyLimit 13107200
SecRequestBodyNoFilesLimit 131072

# Store up to 128 KB of request body data in memory. When the multipart
# parser reachers this limit, it will start using your hard disk for
# storage. That is slow, but unavoidable.
#
SecRequestBodyInMemoryLimit 131072

# What do do if the request body size is above our configured limit.
# Keep in mind that this setting will automatically be set to ProcessPartial
# when SecRuleEngine is set to DetectionOnly mode in order to minimize
# disruptions when initially deploying ModSecurity.
#
SecRequestBodyLimitAction Reject

# Verify that we've correctly processed the request body.
# As a rule of thumb, when failing to process a request body
# you should reject the request (when deployed in blocking mode)
# or log a high-severity alert (when deployed in detection-only mode).
#
SecRule REQBODY_ERROR "!@eq 0" \
"phase:2,t:none,log,deny,status:400,msg:'Failed to parse request body.',logdata:'%{reqbody_error_msg}',severity:2"

# By default be strict with what we accept in the multipart/form-data
# request body. If the rule below proves to be too strict for your
# environment consider changing it to detection-only. You are encouraged
# _not_ to remove it altogether.
#
SecRule MULTIPART_STRICT_ERROR "!@eq 0" \
"phase:2,t:none,log,deny,status:44,msg:'Multipart request body \
failed strict validation: \
PE %{REQBODY_PROCESSOR_ERROR}, \
BQ %{MULTIPART_BOUNDARY_QUOTED}, \
BW %{MULTIPART_BOUNDARY_WHITESPACE}, \
DB %{MULTIPART_DATA_BEFORE}, \
DA %{MULTIPART_DATA_AFTER}, \
HF %{MULTIPART_HEADER_FOLDING}, \
LF %{MULTIPART_LF_LINE}, \
SM %{MULTIPART_SEMICOLON_MISSING}, \
IQ %{MULTIPART_INVALID_QUOTING}, \
IQ %{MULTIPART_INVALID_PART}, \
IH %{MULTIPART_INVALID_HEADER_FOLDING}, \
IH %{MULTIPART_FILE_LIMIT_EXCEEDED}'"

# Did we see anything that might be a boundary?
#
SecRule MULTIPART_UNMATCHED_BOUNDARY "!@eq 0" \
"phase:2,t:none,log,deny,status:44,msg:'Multipart parser detected a possible unmatched boundary.'"

# PCRE Tuning
# We want to avoid a potential RegEx DoS condition
#
SecPcreMatchLimit 1000
SecPcreMatchLimitRecursion 1000

# Some internal errors will set flags in TX and we will need to look for these.
# All of these are prefixed with "MSC_".  The following flags currently exist:
#
# MSC_PCRE_LIMITS_EXCEEDED: PCRE match limits were exceeded.
#
SecRule TX:/^MSC_/ "!@streq 0" \
        "phase:2,t:none,deny,msg:'ModSecurity internal error flagged: %{MATCHED_VAR_NAME}'"


# -- Response body handling --------------------------------------------------

# Allow ModSecurity to access response bodies.
# You should have this directive enabled in order to identify errors
# and data leakage issues.
#
# Do keep in mind that enabling this directive does increases both
# memory consumption and response latency.
#
SecResponseBodyAccess On

# Which response MIME types do you want to inspect? You should adjust the
# configuration below to catch documents but avoid static files
# (e.g., images and archives).
#
SecResponseBodyMimeType text/plain text/html text/xml

# Buffer response bodies of up to 512 KB in length.
SecResponseBodyLimit 524288

# What happens when we encounter a response body larger than the configured
# limit? By default, we process what we have and let the rest through.
# That's somewhat less secure, but does not break any legitimate pages.
#
SecResponseBodyLimitAction ProcessPartial


# -- Filesystem configuration ------------------------------------------------

# The location where ModSecurity stores temporary files (for example, when
# it needs to handle a file upload that is larger than the configured limit).
#
# This default setting is chosen due to all systems have /tmp available however,
# this is less than ideal. It is recommended that you specify a location that's private.
#
SecTmpDir /tmp/

# The location where ModSecurity will keep its persistent data.  This default setting
# is chosen due to all systems have /tmp available however, it
# too should be updated to a place that other users can't access.
#
SecDataDir /tmp/


# -- File uploads handling configuration -------------------------------------

# The location where ModSecurity stores intercepted uploaded files. This
# location must be private to ModSecurity. You don't want other users on
# the server to access the files, do you?
#
#SecUploadDir /opt/modsecurity/var/upload/

# By default, only keep the files that were determined to be unusual
# in some way (by an external inspection script). For this to work you
# will also need at least one file inspection rule.
#
#SecUploadKeepFiles RelevantOnly

# Uploaded files are by default created with permissions that do not allow
# any other user to access them. You may need to relax that if you want to
# interface ModSecurity to an external program (e.g., an anti-virus).
#
#SecUploadFileMode 0600


# -- Debug log configuration -------------------------------------------------

# The default debug log configuration is to duplicate the error, warning
# and notice messages from the error log.
#
#SecDebugLog /opt/modsecurity/var/log/debug.log
#SecDebugLogLevel 3


# -- Audit log configuration -------------------------------------------------

# Log the transactions that are marked by a rule, as well as those that
# trigger a server error (determined by a 5xx or 4xx, excluding 404,
# level response status codes).
#
# To log, use RelevantOnly
SecAuditEngine RelevantOnly
SecAuditLogRelevantStatus "^(?:5|4(?!04))"

# Log everything we know about a transaction.
SecAuditLogParts ABIJDEFHZ

# Use a single file for logging. This is much easier to look at, but
# assumes that you will use the audit log only ocassionally.
#
SecAuditLogType Serial
SecAuditLog /var/log/apache2/modsec_audit.log

# Specify the path for concurrent audit logging.
#SecAuditLogStorageDir /opt/modsecurity/var/audit/


# -- Miscellaneous -----------------------------------------------------------

# Use the most commonly used application/x-www-form-urlencoded parameter
# separator. There's probably only one application somewhere that uses
# something else so don't expect to change this value.
#
SecArgumentSeparator &

# Settle on version 0 (zero) cookies, as that is what most applications
# use. Using an incorrect cookie version may open your installation to
# evasion attacks (against the rules that examine named cookies).
#
SecCookieFormat 0

Sample rules that are relevant to my test of submitting a post with AES_ENCRYPT in the payload, from /etc/modsecurity/whmcs_rules.conf:

SecRule REQUEST_URI|ARGS|REQUEST_BODY "aes_encrypt" "id:00101,phase:4,t:urlDecodeUni,t:htmlEntityDecode,t:replaceComments,t:compressWhiteSpace,t:lowercase,log,deny,msg:'WHMCS'"
SecRule REQUEST_URI|ARGS|REQUEST_BODY "aes_encrypt" "id:00102,phase:4,t:urlDecodeUni,t:htmlEntityDecode,t:hexDecode,t:replaceComments,t:compressWhiteSpace,t:lowercase,log,deny,msg:'WHMCS'"

/var/log/modsec_audit.log (snippet)

--bc497c3a-A--
[30/Oct/2013:12:33:19 +0000] UnD8jtXm0XMAABtcO10AAABA <client> 65312 <server> 443

--bc497c3a-B--
**logged, but trimmed for privacy**

--bc497c3a-C--
**logged, but trimmed for privacy**

--bc497c3a-F--
HTTP/1.1 403 Forbidden
X-Powered-By: PHP/5.3.3-7+squeeze17, PHP/5.3.3-7+squeeze17
Expires: Thu, 19 Nov 1981 08:52:00 GMT
Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Pragma: no-cache
Vary: Accept-Encoding
Content-Encoding: gzip
Keep-Alive: timeout=15, max=100
Connection: Keep-Alive
Transfer-Encoding: chunked
Content-Type: text/html; charset=UTF-8

--bc497c3a-E--
**response that is generated by the PHP script when the POST is submitted**

--bc497c3a-H--
Message: Access denied with code 403 (phase 4). Pattern match "aes_encrypt" at ARGS:firstname. [file "/etc/modsecurity/whmcs_rules.conf"] [line "41"] [id "00101"] [msg "WHMCS"]
Action: Intercepted (phase 4)
Stopwatch: 1383136398855159 530401 (- - -)
Stopwatch2: 1383136398855159 530401; combined=1155, p1=16, p2=14, p3=3, p4=1115, p5=6, sr=0, sw=1, l=0, gc=0
Response-Body-Transformed: Dechunked
Producer: ModSecurity for Apache/2.6.6 (http://www.modsecurity.org/).
Server: Apache/2.2.16 (Debian) mod_ssl/2.2.16 OpenSSL/0.9.8o

--bc497c3a-Z--