ModSeurity v3 not execute phase2

[eddychen111]

rules not execute phase2，is some config error?

SecRule REQUEST_BODY with phase2 not execute，with no debug log output

nginx: nginx/1.21.4
modsecurity: v3/master

Config
modsecurity.conf

# -- 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 DetectionOnly
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 "^(?:application(?:/soap\+|/)|text/)xml" \
#     "id:'200000',phase:1,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML"

# Enable JSON request body parser.
# Initiate JSON Processor in case of JSON content-type; change accordingly
# if your application does not use 'application/json'
#
#SecRule REQUEST_HEADERS:Content-Type "^application/json" \
#     "id:'200001',phase:1,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=JSON"

# Sample rule to enable JSON request body parser for more subtypes.
# Uncomment or adapt this rule if you want to engage the JSON
# Processor for "+json" subtypes
#
#SecRule REQUEST_HEADERS:Content-Type "^application/[a-z0-9.-]+[+]json" \
#     "id:'200006',phase:1,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=JSON"

# 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

# What to 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

# Maximum parsing depth allowed for JSON objects. You want to keep this
# value as low as practical.
#
SecRequestBodyJsonDepthLimit 512

# Maximum number of args allowed per request. You want to keep this
# value as low as practical. The value should match that in rule 200007.
SecArgumentsLimit 1000

# If SecArgumentsLimit has been set, you probably want to reject any
# request body that has only been partly parsed. The value used in this
# rule should match what was used with SecArgumentsLimit
SecRule &ARGS "@ge 1000" \
"id:'200007', phase:2,t:none,log,deny,status:400,msg:'Failed to fully parse request body due to large argument count',severity:2"

# 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" \
"id:'200002', 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" \
"id:'200003',phase:2,t:none,log,deny,status:400, \
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_MISSING_SEMICOLON}, \
IQ %{MULTIPART_INVALID_QUOTING}, \
IP %{MULTIPART_INVALID_PART}, \
IH %{MULTIPART_INVALID_HEADER_FOLDING}, \
FL %{MULTIPART_FILE_LIMIT_EXCEEDED}'"

# Did we see anything that might be a boundary?
#
# Here is a short description about the ModSecurity Multipart parser: the
# parser returns with value 0, if all "boundary-like" line matches with
# the boundary string which given in MIME header. In any other cases it returns
# with different value, eg. 1 or 2.
#
# The RFC 1341 descript the multipart content-type and its syntax must contains
# only three mandatory lines (above the content):
# * Content-Type: multipart/mixed; boundary=BOUNDARY_STRING
# * --BOUNDARY_STRING
# * --BOUNDARY_STRING--
#
# First line indicates, that this is a multipart content, second shows that
# here starts a part of the multipart content, third shows the end of content.
#
# If there are any other lines, which starts with "--", then it should be
# another boundary id - or not.
#
# After 3.0.3, there are two kinds of types of boundary errors: strict and permissive.
#
# If multipart content contains the three necessary lines with correct order, but
# there are one or more lines with "--", then parser returns with value 2 (non-zero).
#
# If some of the necessary lines (usually the start or end) misses, or the order
# is wrong, then parser returns with value 1 (also a non-zero).
#
# You can choose, which one is what you need. The example below contains the
# 'strict' mode, which means if there are any lines with start of "--", then
# ModSecurity blocked the content. But the next, commented example contains
# the 'permissive' mode, then you check only if the necessary lines exists in
# correct order. Whit this, you can enable to upload PEM files (eg "----BEGIN.."),
# or other text files, which contains eg. HTTP headers.
#
# The difference is only the operator - in strict mode (first) the content blocked
# in case of any non-zero value. In permissive mode (second, commented) the
# content blocked only if the value is explicit 1. If it 0 or 2, the content will
# allowed.
#

#
# See #1747 and #1924 for further information on the possible values for
# MULTIPART_UNMATCHED_BOUNDARY.
#
SecRule MULTIPART_UNMATCHED_BOUNDARY "@eq 1" \
    "id:'200004',phase:2,t:none,log,deny,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" \
        "id:'200005',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 /var/log/debug.log
SecDebugLogLevel 9


# -- 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).
#
SecAuditEngine RelevantOnly
SecAuditLogRelevantStatus "^(?:5|4(?!04))"

# Log everything we know about a transaction.
SecAuditLogParts ABIJDEFHZ
#SecAuditLogParts ABCDEFGHIJKZ

# 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/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

# Specify your Unicode Code Point.
# This mapping is used by the t:urlDecodeUni transformation function
# to properly map encoded data to your language. Properly setting
# these directives helps to reduce false positives and negatives.
#
# SecUnicodeMapFile unicode.mapping 20127

# Improve the quality of ModSecurity by sharing information about your
# current ModSecurity version and dependencies versions.
# The following information will be shared: ModSecurity version,
# Web Server version, APR version, PCRE version, Lua version, Libxml2
# version, Anonymous unique id for host.
SecStatusEngine On

main.conf

SecDefaultAction "phase:1,log,auditlog,deny,status:403"
SecDefaultAction "phase:2,log,auditlog,deny,status:403"
SecRule REQUEST_BODY "@eq param\=test" "id:22000100,phase:2,deny"

Logs and dumps

[169002196257.436038] [] [4] Initializing transaction
[169002196257.436038] [] [4] Transaction context created.
[169002196257.436038] [] [4] Starting phase CONNECTION. (SecRules 0)
[169002196257.436038] [] [9] This phase consists of 0 rule(s).
[169002196257.436038] [] [4] Starting phase URI. (SecRules 0 + 1/2)
[169002196257.436038] [/] [4] Starting phase REQUEST_HEADERS. (SecRules 1)
[169002196257.436038] [/] [9] This phase consists of 0 rule(s).
[169002196257.436038] [/] [4] Starting phase RESPONSE_HEADERS. (SecRules 3)
[169002196257.436038] [/] [9] This phase consists of 0 rule(s).
[169002196257.436038] [/] [9] Appending response body: 27 bytes. Limit set to: 524288.000000
[169002196257.436038] [/] [4] Starting phase RESPONSE_BODY. (SecRules 4)
[169002196257.436038] [/] [9] This phase consists of 0 rule(s).
[169002196257.436038] [/] [4] Starting phase LOGGING. (SecRules 5)
[169002196257.436038] [/] [9] This phase consists of 0 rule(s).
[169002196257.436038] [/] [8] Checking if this request is suitable to be saved as an audit log.
[169002196257.436038] [/] [8] Checking if this request is relevant to be part of the audit logs.
[169002196257.436038] [/] [9] Return code 200' is not interesting to audit logs, relevant code(s): ^(?:5|4(?!04))'.

[martinhsv]

Hello @eddychen111 ,

The most likely explanation is a problem with an nginx configuration file. You might want to check if the transaction is subject to a redirect.

Incidentally, your rule 22000100 is incorrect. The @eq operator is intended for numeric values ( https://github.com/SpiderLabs/ModSecurity/wiki/Reference-Manual-%28v3.x%29#eq ) . If you want to perform an exact string comparison, you may be looking for @streq instead.

[eddychen111]

Thanks @martinhsv

here two question：

1. can you give some idea for nginx config which may have an impact for modsecurity phase 2
2. why Initializing running twice when change to phase 4

The nginx configuration as follows:
nginx.conf

load_module "modules/ngx_http_modsecurity_module.so";
#error_log  logs/error.log;
#error_log  logs/error.log  notice;
#error_log  logs/error.log  info;

#pid        logs/nginx.pid;


events {
    worker_connections  1024;
}


http {
    include       mime.types;
    default_type  application/octet-stream;

    #log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
    #                  '$status $body_bytes_sent "$http_referer" '
    #                  '"$http_user_agent" "$http_x_forwarded_for"';

    #access_log  logs/access.log  main;

    sendfile        on;
    #tcp_nopush     on;

    #keepalive_timeout  0;
    keepalive_timeout  65;

    #gzip  on;

    server {
        listen       80;
        server_name  localhost;


        modsecurity on;
        modsecurity_rules_file /etc/nginx/modsec/main.conf;
        #charset koi8-r;

        #access_log  logs/host.access.log  main;

#        location / {
#            root   html;
#            index  index.html index.htm;
#        }

        location / {
            default_type text/plain;
            return 200 "Thank you for requesting ${request_uri}\n";
        }

        #error_page  404              /404.html;

        # redirect server error pages to the static page /50x.html
        #
        error_page   500 502 503 504  /50x.html;
        location = /50x.html {
            root   html;
        }
    }
}

Additional:
I change this rule to phase 4，it works and output log in debug，also transaction phase 2

SecRule REQUEST_BODY "@eq param\=test" "id:22000100,phase:4,deny"

debug output

[169027626044.846231] [] [4] Initializing transaction
[169027626044.846231] [] [4] Transaction context created.
[169027626044.846231] [] [4] Starting phase CONNECTION. (SecRules 0)
[169027626044.846231] [] [9] This phase consists of 0 rule(s).
[169027626044.846231] [] [4] Starting phase URI. (SecRules 0 + 1/2)
[169027626044.846231] [/?a=a] [4] Adding request argument (GET): name "a", value "a"
[169027626044.846231] [/?a=a] [4] Starting phase REQUEST_HEADERS.  (SecRules 1)
[169027626044.846231] [/?a=a] [9] This phase consists of 2 rule(s).
[169027626044.846231] [/?a=a] [4] (Rule: 200000) Executing operator "Rx" with param "^(?:application(?:/soap\+|/)|text/)xml" against REQUEST_HEADERS:Content-Type.
[169027626044.846231] [/?a=a] [9]  T (0) t:lowercase: "application/x-www-form-urlencoded"
[169027626044.846231] [/?a=a] [9] Target value: "application/x-www-form-urlencoded" (Variable: REQUEST_HEADERS:Content-type)
[169027626044.846231] [/?a=a] [4] Rule returned 0.
[169027626044.846231] [/?a=a] [9] Matched vars cleaned.
[169027626044.846231] [/?a=a] [4] (Rule: 200001) Executing operator "Rx" with param "^application/json" against REQUEST_HEADERS:Content-Type.
[169027626044.846231] [/?a=a] [9]  T (0) t:lowercase: "application/x-www-form-urlencoded"
[169027626044.846231] [/?a=a] [9] Target value: "application/x-www-form-urlencoded" (Variable: REQUEST_HEADERS:Content-type)
[169027626044.846231] [/?a=a] [4] Rule returned 0.
[169027626044.846231] [/?a=a] [9] Matched vars cleaned.
[169027626044.846231] [/?a=a] [4] Starting phase RESPONSE_HEADERS. (SecRules 3)
[169027626044.846231] [/?a=a] [9] This phase consists of 0 rule(s).
[169027626044.846231] [/?a=a] [9] Appending response body: 31 bytes. Limit set to: 524288.000000
[169027626044.846231] [/?a=a] [4] Starting phase RESPONSE_BODY. (SecRules 4)
[169027626044.846231] [/?a=a] [9] This phase consists of 1 rule(s).
[169027626044.846231] [/?a=a] [4] (Rule: 22000100) Executing operator "Eq" with param "param\=test" against REQUEST_BODY.
[169027626044.846231] [/?a=a] [9] Target value: "" (Variable: REQUEST_BODY)
[169027626044.846231] [/?a=a] [9] Matched vars updated.
[169027626044.846231] [/?a=a] [4] Rule returned 1.
[169027626044.846231] [/?a=a] [4] Running (disruptive)     action: deny.
[169027626044.846231] [/?a=a] [8] Running action deny
[169027626044.846231] [/?a=a] [8] Skipping this phase as this request was already intercepted.
[16902762609.916818] [] [4] Initializing transaction
[16902762609.916818] [] [4] Transaction context created.
[16902762609.916818] [] [4] Starting phase CONNECTION. (SecRules 0)
[16902762609.916818] [] [9] This phase consists of 0 rule(s).
[16902762609.916818] [] [4] Starting phase URI. (SecRules 0 + 1/2)
[16902762609.916818] [/?a=a] [4] Adding request argument (GET): name "a", value "a"
[16902762609.916818] [/?a=a] [4] Starting phase REQUEST_HEADERS.  (SecRules 1)
[16902762609.916818] [/?a=a] [9] This phase consists of 2 rule(s).
[16902762609.916818] [/?a=a] [4] (Rule: 200000) Executing operator "Rx" with param "^(?:application(?:/soap\+|/)|text/)xml" against REQUEST_HEADERS:Content-Type.
[16902762609.916818] [/?a=a] [9]  T (0) t:lowercase: "application/x-www-form-urlencoded"
[16902762609.916818] [/?a=a] [9] Target value: "application/x-www-form-urlencoded" (Variable: REQUEST_HEADERS:Content-type)
[16902762609.916818] [/?a=a] [4] Rule returned 0.
[16902762609.916818] [/?a=a] [9] Matched vars cleaned.
[16902762609.916818] [/?a=a] [4] (Rule: 200001) Executing operator "Rx" with param "^application/json" against REQUEST_HEADERS:Content-Type.
[16902762609.916818] [/?a=a] [9]  T (0) t:lowercase: "application/x-www-form-urlencoded"
[16902762609.916818] [/?a=a] [9] Target value: "application/x-www-form-urlencoded" (Variable: REQUEST_HEADERS:Content-type)
[16902762609.916818] [/?a=a] [4] Rule returned 0.
[16902762609.916818] [/?a=a] [9] Matched vars cleaned.
[16902762609.916818] [/?a=a] [9] Appending request body: 0 bytes. Limit set to: 13107200.000000
[16902762609.916818] [/?a=a] [4] Starting phase REQUEST_BODY. (SecRules 2)
[16902762609.916818] [/?a=a] [9] This phase consists of 5 rule(s).
[16902762609.916818] [/?a=a] [4] (Rule: 200007) Executing operator "Ge" with param "1000" against ARGS.
[16902762609.916818] [/?a=a] [9] Target value: "1" (Variable: ARGS)
[16902762609.916818] [/?a=a] [4] Rule returned 0.
[16902762609.916818] [/?a=a] [9] Matched vars cleaned.
[16902762609.916818] [/?a=a] [4] (Rule: 200002) Executing operator "Eq" with param "0" against REQBODY_ERROR.
[16902762609.916818] [/?a=a] [9] Target value: "" (Variable: REQBODY_ERROR)
[16902762609.916818] [/?a=a] [4] Rule returned 0.
[16902762609.916818] [/?a=a] [9] Matched vars cleaned.
[16902762609.916818] [/?a=a] [4] (Rule: 200003) Executing operator "Eq" with param "0" against MULTIPART_STRICT_ERROR.
[16902762609.916818] [/?a=a] [9] Target value: "" (Variable: MULTIPART_STRICT_ERROR)
[16902762609.916818] [/?a=a] [4] Rule returned 0.
[16902762609.916818] [/?a=a] [9] Matched vars cleaned.
[16902762609.916818] [/?a=a] [4] (Rule: 200004) Executing operator "Eq" with param "1" against MULTIPART_UNMATCHED_BOUNDARY.
[16902762609.916818] [/?a=a] [9] Target value: "" (Variable: MULTIPART_UNMATCHED_BOUNDARY)
[16902762609.916818] [/?a=a] [4] Rule returned 0.
[16902762609.916818] [/?a=a] [9] Matched vars cleaned.
[16902762609.916818] [/?a=a] [4] (Rule: 200005) Executing operator "StrEq" with param "0" against TX:regex(^MSC_).
[16902762609.916818] [/?a=a] [4] Rule returned 0.
[16902762609.916818] [/?a=a] [9] Matched vars cleaned.
[16902762609.916818] [/?a=a] [4] Starting phase LOGGING. (SecRules 5)
[16902762609.916818] [/?a=a] [9] This phase consists of 0 rule(s).
[16902762609.916818] [/?a=a] [8] Checking if this request is suitable to be saved as an audit log.
[16902762609.916818] [/?a=a] [8] Checking if this request is relevant to be part of the audit logs.
[16902762609.916818] [/?a=a] [9] Return code `200' is not interesting to audit logs, relevant code(s): `^(?:5|4(?!04))'.

[martinhsv]

@eddychen111 ,

I have never used the return nginx configuration item, but isn't that what it's supposed to do? Respond immediately to an HTTP Request for that particular location? If that's what it's doing why would it proceed to do anything with the request body (which is a later stage)? It seems likely that's why you never see the request body stage executing in ModSecurity -- because ModSecurity never receives one from nginx.

[eddychen111]

@eddychen111 ,

I have never used the return nginx configuration item, but isn't that what it's supposed to do? Respond immediately to an HTTP Request for that particular location? If that's what it's doing why would it proceed to do anything with the request body (which is a later stage)? It seems likely that's why you never see the request body stage executing in ModSecurity -- because ModSecurity never receives one from nginx.

@martinhsv
Thank you again for your great help. I'm so grateful for your help with this. Thank you very much for your response. problem seems to have solved.

[ffdevv]

I was desperately trying to get coreruleset (v. 3.3.7) working on nginx until I finally found this.
It is well known and it is easy to find that not having access to the body will make modsecurity skip phase:2. Paired with the fact that someone could put togheter the same logic to check both url and body and that coreruleset by default make decision wheter to block or not a request in such a way, not having access to the body will lead to complete bypass of CRS.
I've checked the SecRequestBodyAccess On config option plenty of times, and finally found the answer. It wasn't me accidentally misconfiguring and denying access to the body, it is that not every nginx location grants the same context to its directives.

I don't know if I did get lost or if this piece of information was just badly indexed in search engines, but I think it would be really helpful to have the docs (maybe in the comment before SecRequestBodyAccess or maybe in the CRS docs, I don't know) mentioning something like:

# 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. Beware that you could still not be able to 
# access request body if the rules are evaluated in a webserver context 
# that doesn't grant access to it.

For anyone else that could get there trying to test CRS without being able to block basic url patterns like ?foo=/etc/passwd&bar=/bin/sh just change the directive inside your location block to implement something that requires the body to be passed (e.g. proxy_pass and not return).