Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Allow 0 length JSON requests #1822

Conversation

allanbomsft
Copy link

Allow 0 length JSON requests.
0 length XML and multipart already allowed.

@zimmerle zimmerle self-requested a review June 27, 2018 22:28
@zimmerle zimmerle self-assigned this Jun 27, 2018
@zimmerle zimmerle added the 2.x Related to ModSecurity version 2.x label Jun 27, 2018
@zimmerle
Copy link
Contributor

Hi @allanbomsft,

As discussed here: #1767 and here: #1392. That may not be a good idea as the content type state that a JSON is expected. At very least, I would expected an empty JSON, which will be:

{
}

What is your take on that?

@allanbomsft
Copy link
Author

The backstory: we had a customer escalation where their application was posting 0 length requests. Probably it was just zero-parameter RPC calls, and their HTTP client library was probably set up globally to use content type json.

It's kind of like passing null, and seems pretty harmless to me.

We allow 0 length for xml and form/multipart, so I think we should align to this.

@allanbomsft
Copy link
Author

allanbomsft commented Jun 29, 2018

Otherwise maybe we should align so xml also requires at least
<something></something>

and form/multipart similar idea.

@victorhora
Copy link
Contributor

#1618 (comment)

@victorhora victorhora added this to the v2.9.3 milestone Nov 10, 2018
@victorhora
Copy link
Contributor

victorhora commented Nov 16, 2018

Adding a bit more to this discussion, It seems like the request body parser for JSON and XML is behaving a bit differently when it comes to overall validation on v2.

For instance using an invalid JSON (or XML) request like so:

POST /token HTTP/1.1
Host: 127.0.0.1
User-Agent: curl/7.61.1
Accept: */*
Cache-Control: no-cache
Content-Type: application/json
origin: https://really.ai
referer: https://really.ai/
x-really-referer: https://really.ai/
Content-Length: 6

123450

Results in the following:

[Using Content-Type: application/json]:

[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Initialising transaction (txid W@xLHfhy6OgbU1ioBl7fXQAAAAA).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Transaction context created (dcfg 5630155a0230).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Starting phase REQUEST_HEADERS.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] This phase consists of 2 rule(s).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Recipe: Invoking rule 5630155bd498; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "23"] [id "200000"].
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][5] Rule 5630155bd498: SecRule "REQUEST_HEADERS:Content-Type" "@rx (?:application(?:/soap\\+|/)|text/)xml" "phase:1,auditlog,id:200000,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] T (0) lowercase: "application/json"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Transformation completed in 18 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Executing operator "rx" with param "(?:application(?:/soap\\+|/)|text/)xml" against REQUEST_HEADERS:Content-Type.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Target value: "application/json"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Operator completed in 14 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Rule returned 0.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Recipe: Invoking rule 5630155c2f40; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "30"] [id "200001"].
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][5] Rule 5630155c2f40: SecRule "REQUEST_HEADERS:Content-Type" "@rx application/json" "phase:1,auditlog,id:200001,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=JSON"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] T (0) lowercase: "application/json"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Transformation completed in 9 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Executing operator "rx" with param "application/json" against REQUEST_HEADERS:Content-Type.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Target value: "application/json"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Operator completed in 5 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Ctl: Set requestBodyProcessor to JSON.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Warning. Pattern match "application/json" at REQUEST_HEADERS:Content-Type. [file "/usr/local/nginx/conf/modsecurity.conf"] [line "30"] [id "200001"]
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Rule returned 1.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Match -> mode NEXT_RULE.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Second phase starting (dcfg 5630155a0230).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Input filter: Reading request body.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] JSON parser initialization
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] yajl JSON parsing callback initialization
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Input filter: Bucket type HEAP contains 6 bytes.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Input filter: Bucket type EOS contains 0 bytes.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][3] Cannot add scalar value without an associated key
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Request body no files length: 6
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Input filter: Completed receiving request body (length 6).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Starting phase REQUEST_BODY.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] This phase consists of 4 rule(s).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Recipe: Invoking rule 5630155c0a20; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "54"] [id "200002"].
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][5] Rule 5630155c0a20: SecRule "REQBODY_ERROR" "!@eq 0" "phase:2,auditlog,id:200002,t:none,log,deny,status:400,msg:'Failed to parse request body.',logdata:%{reqbody_error_msg},severity:2"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Transformation completed in 1 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Executing operator "!eq" with param "0" against REQBODY_ERROR.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Target value: "0"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Operator completed in 3 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Rule returned 0.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Recipe: Invoking rule 5630155c44f8; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "75"] [id "200003"].
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][5] Rule 5630155c44f8: SecRule "MULTIPART_STRICT_ERROR" "!@eq 0" "phase:2,auditlog,id:200003,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}'"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Transformation completed in 1 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Executing operator "!eq" with param "0" against MULTIPART_STRICT_ERROR.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Target value: "0"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Operator completed in 1 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Rule returned 0.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Recipe: Invoking rule 5630155c9390; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "118"] [id "200004"].
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][5] Rule 5630155c9390: SecRule "MULTIPART_UNMATCHED_BOUNDARY" "!@eq 0" "phase:2,auditlog,id:200004,t:none,log,pass,msg:'Multipart parser detected a possible unmatched boundary.'"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Transformation completed in 0 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Executing operator "!eq" with param "0" against MULTIPART_UNMATCHED_BOUNDARY.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Target value: "0"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Operator completed in 1 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Rule returned 0.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Recipe: Invoking rule 5630155caa60; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "120"] [id "200006"].
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][5] Rule 5630155caa60: SecRule "MULTIPART_UNMATCHED_BOUNDARY" "@eq 1" "phase:2,auditlog,id:200006,t:none,log,deny,msg:'Multipart parser detected a unmatched boundary.'"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Transformation completed in 1 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Executing operator "eq" with param "1" against MULTIPART_UNMATCHED_BOUNDARY.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] Target value: "0"
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Operator completed in 0 usec.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Rule returned 0.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Hook insert_filter: Adding input forwarding filter (r 563015602a80).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Hook insert_filter: Adding output filter (r 563015602a80).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Input filter: Forwarding input: mode=0, block=0, nbytes=8192 (f 563015614f80, r 563015602a80).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Input filter: Forwarded 6 bytes.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Input filter: Sent EOS.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Input filter: Input forwarding complete.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015602a80][/token][4] Initialising logging.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015615028][/missing.html][4] Starting phase LOGGING.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015615028][/missing.html][9] This phase consists of 0 rule(s).
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015615028][/missing.html][4] Recording persistent data took 0 microseconds.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015615028][/missing.html][4] Audit log: Logging this transaction.
[14/Nov/2018:11:19:41 --0500] [127.0.0.1/sid#563015585c50][rid#563015615028][/missing.html][4] JSON: Cleaning up JSON results

[Using Content-Type: application/xml]:

[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Initialising transaction (txid W@xK72M30SdD5QMHUTnx5wAAAAY).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Transaction context created (dcfg 5630155a0230).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Starting phase REQUEST_HEADERS.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] This phase consists of 2 rule(s).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Recipe: Invoking rule 5630155bd498; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "23"] [id "200000"].
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][5] Rule 5630155bd498: SecRule "REQUEST_HEADERS:Content-Type" "@rx (?:application(?:/soap\\+|/)|text/)xml" "phase:1,auditlog,id:200000,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML"
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] T (0) lowercase: "application/xml"
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Transformation completed in 25 usec.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Executing operator "rx" with param "(?:application(?:/soap\\+|/)|text/)xml" against REQUEST_HEADERS:Content-Type.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Target value: "application/xml"
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Operator completed in 10 usec.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Ctl: Set requestBodyProcessor to XML.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Warning. Pattern match "(?:application(?:/soap\\+|/)|text/)xml" at REQUEST_HEADERS:Content-Type. [file "/usr/local/nginx/conf/modsecurity.conf"] [line "23"] [id "200000"]
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Rule returned 1.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Match -> mode NEXT_RULE.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Recipe: Invoking rule 5630155c2f40; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "30"] [id "200001"].
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][5] Rule 5630155c2f40: SecRule "REQUEST_HEADERS:Content-Type" "@rx application/json" "phase:1,auditlog,id:200001,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=JSON"
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] T (0) lowercase: "application/xml"
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Transformation completed in 7 usec.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Executing operator "rx" with param "application/json" against REQUEST_HEADERS:Content-Type.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Target value: "application/xml"
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Operator completed in 1 usec.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Rule returned 0.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Second phase starting (dcfg 5630155a0230).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Input filter: Reading request body.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Input filter: Bucket type HEAP contains 6 bytes.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] XML: Initialising parser.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Input filter: Bucket type EOS contains 0 bytes.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] XML: Parsing complete (well_formed 0).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][2] XML parser error: XML: Failed parsing document.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Input filter: Completed receiving request body (length 6).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][1] XML parser error: XML: Failed parsing document.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Hook insert_error_filter: Adding output filter (r 563015616ca0).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Output filter: Receiving output (f 56301560ef40, r 563015616ca0).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Starting phase RESPONSE_HEADERS.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] This phase consists of 0 rule(s).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Content Injection: Not enabled.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Output filter: Bucket type HEAP contains 26 bytes.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] Output filter: Bucket type EOS contains 0 bytes.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Output filter: Completed receiving response body (buffered full - 26 bytes).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Starting phase RESPONSE_BODY.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] This phase consists of 0 rule(s).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Output filter: Output forwarding complete.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Initialising logging.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Starting phase LOGGING.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][9] This phase consists of 0 rule(s).
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Recording persistent data took 0 microseconds.
[14/Nov/2018:11:18:55 --0500] [127.0.0.1/sid#563015585c50][rid#563015616ca0][/token][4] Audit log: Logging this transaction.

This brings up the following on the error log and returns a 500 error from Apache by default:

ModSecurity: XML parser error: XML: Failed parsing document.
body.xml:1: parser error : Document is empty
123450

Notice that even though the parser failed for both, the JSON parser ends up being more forgiving and still allow the REQUEST_BODY phase (2) to start and process the rules on this phase before moving over to the next phase (RESPONSE_HEADERS).

But for the 0 length requests, it's the opposite. For a request like so:

POST /token HTTP/1.1
Host: 127.0.0.1
User-Agent: curl/7.61.1
Accept: */*
Cache-Control: no-cache
Content-Type: application/json
origin: https://really.ai
referer: https://really.ai/
x-really-referer: https://really.ai/
Content-Length: 0

Results in the following:

[Using Content-Type: application/json]:

[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Initialising transaction (txid W@xIdC5@fA4XFLcXw7-g0AAAAAQ).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Transaction context created (dcfg 5630155a0230).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Starting phase REQUEST_HEADERS.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] This phase consists of 2 rule(s).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Recipe: Invoking rule 5630155bd498; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "23"] [id "200000"].
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][5] Rule 5630155bd498: SecRule "REQUEST_HEADERS:Content-Type" "@rx (?:application(?:/soap\\+|/)|text/)xml" "phase:1,auditlog,id:200000,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML"
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] T (0) lowercase: "application/json"
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Transformation completed in 9 usec.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Executing operator "rx" with param "(?:application(?:/soap\\+|/)|text/)xml" against REQUEST_HEADERS:Content-Type.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] Target value: "application/json"
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Operator completed in 10 usec.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Rule returned 0.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Recipe: Invoking rule 5630155c2f40; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "30"] [id "200001"].
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][5] Rule 5630155c2f40: SecRule "REQUEST_HEADERS:Content-Type" "@rx application/json" "phase:1,auditlog,id:200001,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=JSON"
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] T (0) lowercase: "application/json"
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Transformation completed in 6 usec.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Executing operator "rx" with param "application/json" against REQUEST_HEADERS:Content-Type.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] Target value: "application/json"
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Operator completed in 3 usec.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Ctl: Set requestBodyProcessor to JSON.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Warning. Pattern match "application/json" at REQUEST_HEADERS:Content-Type. [file "/usr/local/nginx/conf/modsecurity.conf"] [line "30"] [id "200001"]
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Rule returned 1.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] Match -> mode NEXT_RULE.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Second phase starting (dcfg 5630155a0230).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Input filter: Reading request body.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] JSON parser initialization
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] yajl JSON parsing callback initialization
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] Input filter: Bucket type EOS contains 0 bytes.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][2] JSON parser error: parse error: premature EOF

[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Input filter: Completed receiving request body (length 0).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][1] JSON parser error: parse error: premature EOF

[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Hook insert_error_filter: Adding output filter (r 563015604aa0).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] Output filter: Receiving output (f 563015602da0, r 563015604aa0).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Starting phase RESPONSE_HEADERS.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] This phase consists of 0 rule(s).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] Content Injection: Not enabled.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] Output filter: Bucket type HEAP contains 26 bytes.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] Output filter: Bucket type EOS contains 0 bytes.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Output filter: Completed receiving response body (buffered full - 26 bytes).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Starting phase RESPONSE_BODY.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] This phase consists of 0 rule(s).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Output filter: Output forwarding complete.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Initialising logging.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Starting phase LOGGING.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][9] This phase consists of 0 rule(s).
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Recording persistent data took 0 microseconds.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] Audit log: Logging this transaction.
[14/Nov/2018:11:08:20 --0500] [127.0.0.1/sid#563015585c50][rid#563015604aa0][/token][4] JSON: Cleaning up JSON results

This brings up a ModSecurity: JSON parser error: parse error: premature EOF\non the error log and returns a 500 error from Apache by default.

On the case of the JSON parsing, yajl_complete_parse() as is, will not return yajl_status_ok for yajl_status() when the JSON handle is empty.

https://github.com/SpiderLabs/ModSecurity/blob/d8c711257bfcca2845108190900eb6cd194c7d0b/apache2/msc_json.c#L296-L311

(As a reminder, this PR, adds a workaround to change the scenario above checking that the length is large enough for the JSON parser to run successfully and allowing for phase 2 to continue.)

Moving on...

[Using Content-Type: application/xml]:

[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Initialising transaction (txid W@xH09kj6Ugdr2svgPdYdwAAAAM).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Transaction context created (dcfg 5630155a0230).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Starting phase REQUEST_HEADERS.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] This phase consists of 2 rule(s).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Recipe: Invoking rule 5630155bd498; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "23"] [id "200000"].
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][5] Rule 5630155bd498: SecRule "REQUEST_HEADERS:Content-Type" "@rx (?:application(?:/soap\\+|/)|text/)xml" "phase:1,auditlog,id:200000,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] T (0) lowercase: "application/xml"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Transformation completed in 12 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Executing operator "rx" with param "(?:application(?:/soap\\+|/)|text/)xml" against REQUEST_HEADERS:Content-Type.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] Target value: "application/xml"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Operator completed in 18 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Ctl: Set requestBodyProcessor to XML.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Warning. Pattern match "(?:application(?:/soap\\+|/)|text/)xml" at REQUEST_HEADERS:Content-Type. [file "/usr/local/nginx/conf/modsecurity.conf"] [line "23"] [id "200000"]
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Rule returned 1.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] Match -> mode NEXT_RULE.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Recipe: Invoking rule 5630155c2f40; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "30"] [id "200001"].
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][5] Rule 5630155c2f40: SecRule "REQUEST_HEADERS:Content-Type" "@rx application/json" "phase:1,auditlog,id:200001,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=JSON"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] T (0) lowercase: "application/xml"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Transformation completed in 5 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Executing operator "rx" with param "application/json" against REQUEST_HEADERS:Content-Type.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] Target value: "application/xml"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Operator completed in 1 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Rule returned 0.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Second phase starting (dcfg 5630155a0230).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Input filter: Reading request body.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] Input filter: Bucket type EOS contains 0 bytes.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Request body no files length: 0
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Input filter: Completed receiving request body (length 0).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Starting phase REQUEST_BODY.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] This phase consists of 4 rule(s).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Recipe: Invoking rule 5630155c0a20; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "54"] [id "200002"].
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][5] Rule 5630155c0a20: SecRule "REQBODY_ERROR" "!@eq 0" "phase:2,auditlog,id:200002,t:none,log,deny,status:400,msg:'Failed to parse request body.',logdata:%{reqbody_error_msg},severity:2"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Transformation completed in 2 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Executing operator "!eq" with param "0" against REQBODY_ERROR.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] Target value: "0"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Operator completed in 4 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Rule returned 0.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Recipe: Invoking rule 5630155c44f8; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "75"] [id "200003"].
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][5] Rule 5630155c44f8: SecRule "MULTIPART_STRICT_ERROR" "!@eq 0" "phase:2,auditlog,id:200003,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}'"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Transformation completed in 2 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Executing operator "!eq" with param "0" against MULTIPART_STRICT_ERROR.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] Target value: "0"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Operator completed in 1 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Rule returned 0.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Recipe: Invoking rule 5630155c9390; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "118"] [id "200004"].
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][5] Rule 5630155c9390: SecRule "MULTIPART_UNMATCHED_BOUNDARY" "!@eq 0" "phase:2,auditlog,id:200004,t:none,log,pass,msg:'Multipart parser detected a possible unmatched boundary.'"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Transformation completed in 1 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Executing operator "!eq" with param "0" against MULTIPART_UNMATCHED_BOUNDARY.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] Target value: "0"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Operator completed in 1 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Rule returned 0.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Recipe: Invoking rule 5630155caa60; [file "/usr/local/nginx/conf/modsecurity.conf"] [line "120"] [id "200006"].
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][5] Rule 5630155caa60: SecRule "MULTIPART_UNMATCHED_BOUNDARY" "@eq 1" "phase:2,auditlog,id:200006,t:none,log,deny,msg:'Multipart parser detected a unmatched boundary.'"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Transformation completed in 0 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Executing operator "eq" with param "1" against MULTIPART_UNMATCHED_BOUNDARY.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] Target value: "0"
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Operator completed in 1 usec.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Rule returned 0.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][9] No match, not chained -> mode NEXT_RULE.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Hook insert_filter: Adding input forwarding filter (r 563015612c60).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Hook insert_filter: Adding output filter (r 563015612c60).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Input filter: Forwarding input: mode=0, block=0, nbytes=8192 (f 563015618de0, r 563015612c60).
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Input filter: Sent EOS.
[14/Nov/2018:11:05:39 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Input filter: Input forwarding complete.
[14/Nov/2018:11:05:44 --0500] [127.0.0.1/sid#563015585c50][rid#563015612c60][/token][4] Initialising logging.
[14/Nov/2018:11:05:44 --0500] [127.0.0.1/sid#563015585c50][rid#563015618e88][/missing.html][4] Starting phase LOGGING.
[14/Nov/2018:11:05:44 --0500] [127.0.0.1/sid#563015585c50][rid#563015618e88][/missing.html][9] This phase consists of 0 rule(s).
[14/Nov/2018:11:05:44 --0500] [127.0.0.1/sid#563015585c50][rid#563015618e88][/missing.html][4] Recording persistent data took 0 microseconds.
[14/Nov/2018:11:05:44 --0500] [127.0.0.1/sid#563015585c50][rid#563015618e88][/missing.html][4] Audit log: Logging this transaction.

The scenario above happens due to xml_complete() not satisfying the following condition:

https://github.com/SpiderLabs/ModSecurity/blob/d8c711257bfcca2845108190900eb6cd194c7d0b/apache2/msc_xml.c#L114

Due to the expected XML content being empty, parsing_ctx is not set as normally would and it returns 1 allowing the phase to continue.

@victorhora
Copy link
Contributor

All that being said, which behaviour is "correct" for both cases (invalid and empty data) and for both XML and JSON parsers?

Should we always allow for the phase to go through regardless and and simply fill REQBODY_ERROR with a non zero value and only and let the rules to do the job of forbidding an empty or invalid request (e.g. rule 200002) or we should stop processing when such conditions are encountered and return an error to Apache (500 by default)?

@victorhora victorhora self-assigned this Nov 16, 2018
@marcstern
Copy link

marcstern commented Nov 16, 2018 via email

@marcstern
Copy link

Work-around for all people having that problem (and the same with other parsers):
We're using the following generic rule (as the last phase:1 rule):
SecRule REQUEST_HEADERS:Content-Length "^0$" "phase:1,t:none,ctl:requestBodyAccess=off"

This totally solves the problem, is totally generic & perene and should, imo, be the default - unless somebody sees a possible attack using an empty body.

zimmerle pushed a commit that referenced this pull request Nov 29, 2018
@zimmerle
Copy link
Contributor

After long discussions here and out of band, I am convinced that @allanbomsft is the best approach. Among of other reasons:

  1. we are going to maintain the approach adapted by other request body interpreters, as cited by @allanbomsft.
  2. as well point by @victorhora, not good idea to broke the original flow of the phase execution.
  3. as @marcstern said: there should be no harm in an empty body. At least till we hear otherwise :)

This was merged into 2.x family and ported to v3. Here is the v3 commit for the reference: d2b14de

Test cases for v3 are here:
https://github.com/SpiderLabs/ModSecurity/blob/d2b14de26860916bcd80864b5e985cada9c638f5/test/test-cases/regression/request-body-parser-json.json#L83-L153

Thank you @allanbomsft, and everybody who participate in the discussion.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
2.x Related to ModSecurity version 2.x
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants