Description
Describe the bug
I have created a custom rule to detect the word confidential
in the REQUEST_BODY
. If the word is detected, the action to undertake is deny
. However when I make this POST
request the request is logged as a GET
in the audit logs.
Here is the custom rule:
SecRule REQUEST_BODY "@rx (?i)(\b|\W*)confidential" "id:1, phase:2, deny, log, t:none, msg:'UNAUTHORIZED DATA ACCESS'"
Logs and dumps
Audit Logs
{
"transaction": {
"client_ip": "10.103.253.240",
"time_stamp": "Thu Nov 14 05:08:27 2024",
"server_id": "327c12d21520fbed95c8764ad076e59b7ea5d783",
"client_port": 51501,
"host_ip": "192.168.32.3",
"host_port": 8080,
"unique_id": "8f198db9483934603d69ce8654326042",
"request": {
"method": "GET",
"http_version": 1.1,
"uri": "/check",
"headers": {
"Content-Type": "application/json",
"User-Agent": "PostmanRuntime/7.42.0",
"Postman-Token": "6936971e-b447-4419-8f95-262f0a590386",
"Accept": "*/*",
"Host": "weborion.licensing.portal",
"Accept-Encoding": "gzip, deflate, br",
"Connection": "keep-alive",
"Content-Length": "21"
}
},
"response": {
"http_code": 403,
"headers": {
"Server": "nginx/1.27.2",
"Date": "Thu, 14 Nov 2024 05:08:27 GMT",
"Content-Type": "text/html",
"Connection": "keep-alive",
"ETag": "\"66dfdff2-93d6\""
}
},
"producer": {
"modsecurity": "ModSecurity v3.0.13 (Linux)",
"connector": "ModSecurity-nginx v1.0.3",
"secrules_engine": "Enabled",
"components": [
"OWASP_CRS/4.8.0\""
]
},
"messages": [
{
"message": "GET or HEAD Request with Body Content",
"details": {
"match": "Matched \"Operator `Rx' with parameter `^0?$' against variable `REQUEST_HEADERS:Content-Length' (Value: `21' )",
"reference": "o0,3v0,3v255,2",
"ruleId": "920170",
"file": "/etc/modsecurity.d/owasp-crs/rules/REQUEST-920-PROTOCOL-ENFORCEMENT.conf",
"lineNumber": "171",
"data": "21",
"severity": "2",
"ver": "OWASP_CRS/4.8.0",
"rev": "",
"tags": [
"application-multi",
"language-multi",
"platform-multi",
"attack-protocol",
"paranoia-level/1",
"OWASP_CRS",
"capec/1000/210/272"
],
"maturity": "0",
"accuracy": "0"
}
},
{
"message": "UNAUTHORIZED DATA ACCESS",
"details": {
"match": "Matched \"Operator `Rx' with parameter `(?i)(\\b|\\W*)confidential' against variable `REQUEST_BODY' (Value: `{\"confidential\":true}' )",
"reference": "o0,14o0,2v258,21",
"ruleId": "1",
"file": "/var/opt/modsecurity.d/custom-ruleset/TestRukeset/TestRukeset-RULES.conf",
"lineNumber": "1",
"data": "",
"severity": "0",
"ver": "",
"rev": "",
"tags": [],
"maturity": "0",
"accuracy": "0"
}
},
{
"message": "Inbound Score: 5 Outbound Score: 0",
"details": {
"match": "",
"reference": "",
"ruleId": "980145",
"file": "/var/opt/modsecurity.d/owasp-crs/weborion.licensing.portal.crs_setup.conf",
"lineNumber": "40",
"data": "",
"severity": "0",
"ver": "",
"rev": "",
"tags": [],
"maturity": "0",
"accuracy": "0"
}
}
]
}
}
Debug Logs (Level 9)
Modsecurity-Debug-Logs-Level-9.txt
A more closer view:
[8f198db9483934603d69ce8654326042] [/check] [4] (Rule: 911100) Executing operator "Within" with param "GET HEAD POST OPTIONS" Was: "" against REQUEST_METHOD.
[8f198db9483934603d69ce8654326042] [/check] [9] Target value: "POST" (Variable: REQUEST_METHOD)
[8f198db9483934603d69ce8654326042] [/check] [4] Rule returned 0.
[8f198db9483934603d69ce8654326042] [/check] [9] Matched vars cleaned
[8f198db9483934603d69ce8654326042] [/check] [9] Matched vars cleaned.
[8f198db9483934603d69ce8654326042] [/check] [4] (Rule: 911100) Executing operator "Within" with param "GET HEAD POST OPTIONS" Was: "" against REQUEST_METHOD.
[8f198db9483934603d69ce8654326042] [/check] [9] Target value: "GET" (Variable: REQUEST_METHOD)
[8f198db9483934603d69ce8654326042] [/check] [4] Rule returned 0.
[8f198db9483934603d69ce8654326042] [/check] [9] Matched vars cleaned.
In the logs above you can see that for the same unique_id
8f198db9483934603d69ce8654326042, the REQUEST_METHOD
variable value changes from POST
to GET
Error Logs:
2024/11/14 05:08:27 [error] 93#93: *16 [client 10.103.253.240] ModSecurity: Access denied with code 403 (phase 2). Matched "Operator `Rx' with parameter `(?i)(\b|\W*)confidential' against variable `REQUEST_BODY' (Value: `{"confidential":true}' ) [file "/var/opt/modsecurity.d/custom-ruleset/TestRukeset/TestRukeset-RULES.conf"] [line "1"] [id "1"] [rev ""] [msg "UNAUTHORIZED DATA ACCESS"] [data ""] [severity "0"] [ver ""] [maturity "0"] [accuracy "0"] [hostname "192.168.32.3"] [uri "/check"] [unique_id "8f198db9483934603d69ce8654326042"] [ref "o0,14o0,2v259,21"], client: 10.103.253.240, server: weborion.licensing.portal, request: "POST /check HTTP/1.1", host: "weborion.licensing.portal"
2024/11/14 05:08:27 [error] 93#93: *16 [client 10.103.253.240] ModSecurity: Access denied with code 403 (phase 2). Matched "Operator `Rx' with parameter `(?i)(\b|\W*)confidential' against variable `REQUEST_BODY' (Value: `{"confidential":true}' ) [file "/var/opt/modsecurity.d/custom-ruleset/TestRukeset/TestRukeset-RULES.conf"] [line "1"] [id "1"] [rev ""] [msg "UNAUTHORIZED DATA ACCESS"] [data ""] [severity "0"] [ver ""] [maturity "0"] [accuracy "0"] [hostname "192.168.32.3"] [uri "/check"] [unique_id "8f198db9483934603d69ce8654326042"] [ref "o0,14o0,2v258,21"], client: 10.103.253.240, server: weborion.licensing.portal, request: "POST /check HTTP/1.1", host: "weborion.licensing.portal"
In the error log the same request gets logged twice, it gets logged as POST request.
To Reproduce
- Setup an
POST
endpoint in the server/webApp protected by the WAF. - Add the custom rule.
- Modsecurity Configuration:
SecRuleEngine On
SecRequestBodyAccess on
SecRule REQUEST_HEADERS:Content-Type "^(?:application(?:/soap\+|/)|text/)xml" \
"id:'200000',phase:1,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML"
SecRule REQUEST_HEADERS:Content-Type "^application/json" \
"id:'200001',phase:1,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=JSON"
SecRequestBodyLimit 10485760
SecRequestBodyNoFilesLimit 1048576
SecRequestBodyLimitAction ProcessPartial
SecRequestBodyJsonDepthLimit 512
SecArgumentsLimit 1000
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"
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"
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}'"
SecPcreMatchLimit 100000
SecPcreMatchLimitRecursion 100000
SecRule TX:/^MSC_/ "!@streq 0" \
"id:'200005',phase:2,t:none,deny,msg:'ModSecurity internal error flagged: %{MATCHED_VAR_NAME}'"
SecResponseBodyAccess on
SecResponseBodyMimeType text/plain text/html text/xml application/JSON
SecResponseBodyLimit 537600
SecResponseBodyLimitAction Reject
SecTmpDir /tmp/
SecDataDir /tmp/
SecAuditEngine On
SecAuditLogType Serial
SecAuditLogRelevantStatus "^(?:5|4(?!04))"
SecAuditLog /var/log/modsec_logs/modsec_audit_weborion.licensing.portal.log
SecAuditLogFormat JSON
SecAuditLogParts ABFHZ
SecArgumentSeparator &
SecCookieFormat 0
SecUnicodeMapFile unicode.mapping 20127
SecStatusEngine Off
SecGeoLookupDb /var/GeoLite2-Country/GeoLite2-Country.mmdb
SecDebugLog /var/log/modsec_logs/modsec_debug.log
SecDebugLogLevel 9
- Make a curl request to the endpoint
Curl Command
curl --location 'http://<domain>/check' \ --header 'Content-Type: application/json' \ --data '{"confidential":true}'
Expected behavior
The audit logs should log the request as POST
and not GET
.
Server (please complete the following information):
- ModSecurity version (and connector): 3.0.13
- Modsecurity-Nginx Connector: v1.0.3
- CRS Version: 4.8.0
- WebServer: Nginx Version: 1.27.2
- OS (and distro): Ubuntu 22.04
Rule Set (please complete the following information):
- Running any public or commercial rule set? OWASP CRS
- What is the version number? 4.8.0
Additional context
I can see that the transaction starts again when the custom rule is triggered.
[8f198db9483934603d69ce8654326042] [/check] [4] (Rule: 1) Executing operator "Rx" with param "(?i)(\b|\W*)confidential" against REQUEST_BODY.
[8f198db9483934603d69ce8654326042] [/check] [9] Target value: "{"confidential":true}" (Variable: REQUEST_BODY)
[8f198db9483934603d69ce8654326042] [/check] [9] Matched vars updated.
[8f198db9483934603d69ce8654326042] [/check] [4] Rule returned 1.
[8f198db9483934603d69ce8654326042] [/check] [9] Saving msg: UNAUTHORIZED DATA ACCESS
[8f198db9483934603d69ce8654326042] [/check] [9] Running action: log
[8f198db9483934603d69ce8654326042] [/check] [9] Saving transaction to logs
[8f198db9483934603d69ce8654326042] [/check] [4] Running (disruptive) action: deny.
[8f198db9483934603d69ce8654326042] [/check] [8] Running action deny
[8f198db9483934603d69ce8654326042] [/check] [8] Skipping this phase as this request was already intercepted.
[8f198db9483934603d69ce8654326042] [] [4] Initializing transaction
[8f198db9483934603d69ce8654326042] [] [4] Transaction context created.
[8f198db9483934603d69ce8654326042] [] [4] Starting phase CONNECTION. (SecRules 0)
[8f198db9483934603d69ce8654326042] [] [9] This phase consists of 29 rule(s).
[8f198db9483934603d69ce8654326042] [] [4] Starting phase URI. (SecRules 0 + 1/2)
I am not sure if this is the expected behaviour from the backed. After this process it seems that the request goes through all the 4 phases again, however this time the REQUEST_METHOD
becomes GET