ModSecurity for IIS 2.7.3 stops website login action

[atitan]

WinSrv 2008 R2 x64 IIS7.5 with PHP 5.4 via FastCGI

I found this issue existed after enabled Modsec in web.config.
At first, I thought it might be caused by crs rules. However, even I only include modsecurity.conf, it still act the same.

Here are debug log during login process. The webpage couldn't respond until connection timed out.

Initialising transaction (txid 12538021364746957633). Transaction context created (dcfg 969290). First phase starting (dcfg 969290). Starting phase REQUEST_HEADERS. Recipe: Invoking rule 299ec08; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "24"] [id "200000"]. Transformation completed in 0 usec. Executing operator "rx" with param "text/xml" against REQUEST_HEADERS:Content-Type. Operator completed in 0 usec. Rule returned 0. Second phase starting (dcfg 969290). Input filter: Reading request body. Input filter: Completed receiving request body (length 109). Starting phase REQUEST_BODY. Recipe: Invoking rule 299d168; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "55"] [id "200001"]. Transformation completed in 0 usec. Executing operator "!eq" with param "0" against REQBODY_ERROR. Operator completed in 0 usec. Rule returned 0. Recipe: Invoking rule 29a04a8; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "76"] [id "200002"]. Transformation completed in 0 usec. Executing operator "!eq" with param "0" against MULTIPART_STRICT_ERROR. Operator completed in 0 usec. Rule returned 0. Recipe: Invoking rule 29a44d0; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "81"] [id "200003"]. Transformation completed in 0 usec. Executing operator "!eq" with param "0" against MULTIPART_UNMATCHED_BOUNDARY. Operator completed in 0 usec. Rule returned 0. Recipe: Invoking rule 29a5408; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "95"] [id "200004"]. Rule returned 0. Hook insert_filter: Adding input forwarding filter (r 29a9440). Hook insert_filter: Adding output filter (r 29a9440).

[brenosilva]

Hello,

Are there any rules for phase response header/body ?
What happens if you change SecRuleEngine to DetectionOnly ?
Is there any message into error.log ?

Thanks

[atitan]

Hi,

SecRuleEngine is set to DetectionOnly by default.
I didn't find any error message in log.

The rules I used is bundled with MSI package(modsecurity.conf), and its effective rules are:

`SecRuleEngine DetectionOnly

SecRequestBodyAccess On

SecRule REQUEST_HEADERS:Content-Type "text/xml"
"id:'200000',phase:1,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML"

SecRequestBodyLimit 13107200
SecRequestBodyNoFilesLimit 131072

SecRequestBodyInMemoryLimit 131072

SecRequestBodyLimitAction Reject

SecRule REQBODY_ERROR "!@eq 0"
"id:'200001', 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:'200002',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_MISSING_SEMICOLON},
IQ %{MULTIPART_INVALID_QUOTING},
IP %{MULTIPART_INVALID_PART},
IH %{MULTIPART_INVALID_HEADER_FOLDING},
FL %{MULTIPART_FILE_LIMIT_EXCEEDED}'"

SecRule MULTIPART_UNMATCHED_BOUNDARY "!@eq 0"
"id:'200003',phase:2,t:none,log,deny,status:44,msg:'Multipart parser detected a possible unmatched boundary.'"

SecPcreMatchLimit 1000
SecPcreMatchLimitRecursion 1000

SecRule TX:/^MSC_/ "!@Streq 0"
"id:'200004',phase:2,t:none,deny,msg:'ModSecurity internal error flagged: %{MATCHED_VAR_NAME}'"

SecResponseBodyMimeType text/plain text/html text/xml

SecResponseBodyLimit 524288

SecResponseBodyLimitAction ProcessPartial

SecTmpDir c:\inetpub\temp\

SecDataDir c:\inetpub\temp\

SecDebugLog C:\Logs\ModSecurity\debug.log
SecDebugLogLevel 4

SecArgumentSeparator &

SecCookieFormat 0`

[brenosilva]

Right,

Can you turn debug level to 9 ? Maybe there is an important debug information we are missing.

Thanks

[atitan]

OK, now it looks like this.

[4] Initialising transaction (txid 11673330240586785225). [5] Adding request cookie: name "wp-settings-time-2", value "1358523685" [5] Adding request cookie: name "wp-settings-1", value "editor%3Dhtml%26m6%3Do%26m10%3Do%26m5%3Do%26m8%3Dc%26m7%3Do%26m9%3Dc%26hidetb%3D1" [5] Adding request cookie: name "wp-settings-time-1", value "1362152354" [5] Adding request cookie: name "__atssc", value "facebook%3B2%2Ctwitter%3B1" [5] Adding request cookie: name "__atuvc", value "40%7C11%2C48%7C12%2C11%7C13%2C43%7C14%2C12%7C15" [5] Adding request cookie: name "__utma", value "97011023.318241276.1354960109.1365500826.1365587281.611" [5] Adding request cookie: name "__utmc", value "97011023" [5] Adding request cookie: name "__utmz", value "97011023.1365002021.581.7.utmcsr=google|utmccn=(organic)|utmcmd=organic|utmctr=(not%20provided)" [5] Adding request cookie: name "wordpress_test_cookie", value "WP+Cookie+check" [4] Transaction context created (dcfg 2459290). [4] First phase starting (dcfg 2459290). [4] Starting phase REQUEST_HEADERS. [9] This phase consists of 1 rule(s). [4] Recipe: Invoking rule 2b2ec08; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "24"] [id "200000"]. [5] Rule 2b2ec08: SecRule "REQUEST_HEADERS:Content-Type" "@rx text/xml" "phase:1,auditlog,id:200000,t:none,t:lowercase,pass,nolog,ctl:requestBodyProcessor=XML" [9] T (0) lowercase: "application/x-www-form-urlencoded" [4] Transformation completed in 0 usec. [4] Executing operator "rx" with param "text/xml" against REQUEST_HEADERS:Content-Type. [9] Target value: "application/x-www-form-urlencoded" [4] Operator completed in 0 usec. [4] Rule returned 0. [9] No match, not chained -> mode NEXT_RULE. [4] Second phase starting (dcfg 2459290). [4] Input filter: Reading request body. [9] Input filter: Bucket type POOL contains 109 bytes. [9] Input filter: Bucket type POOL contains 0 bytes. [9] Input filter: Bucket type EOS contains 0 bytes. [5] Adding request argument (BODY): name "log", value "******" [5] Adding request argument (BODY): name "pwd", value "******" [5] Adding request argument (BODY): name "wp-submit", value "Log In" [5] Adding request argument (BODY): name "redirect_to", value "https://atifans.net/wp-admin/" [5] Adding request argument (BODY): name "testcookie", value "1" [4] Input filter: Completed receiving request body (length 109). [4] Starting phase REQUEST_BODY. [9] This phase consists of 4 rule(s). [4] Recipe: Invoking rule 2b2d168; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "55"] [id "200001"]. [5] Rule 2b2d168: SecRule "REQBODY_ERROR" "!@eq 0" "phase:2,auditlog,id:200001,t:none,log,deny,status:400,msg:'Failed to parse request body.',logdata:%{reqbody_error_msg},severity:2" [4] Transformation completed in 0 usec. [4] Executing operator "!eq" with param "0" against REQBODY_ERROR. [9] Target value: "0" [4] Operator completed in 0 usec. [4] Rule returned 0. [9] No match, not chained -> mode NEXT_RULE. [4] Recipe: Invoking rule 2b304a8; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "76"] [id "200002"]. [5] Rule 2b304a8: SecRule "MULTIPART_STRICT_ERROR" "!@eq 0" "phase:2,auditlog,id:200002,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_MISSING_SEMICOLON}, IQ %{MULTIPART_INVALID_QUOTING}, IP %{MULTIPART_INVALID_PART}, IH %{MULTIPART_INVALID_HEADER_FOLDING}, FL %{MULTIPART_FILE_LIMIT_EXCEEDED}'" [4] Transformation completed in 0 usec. [4] Executing operator "!eq" with param "0" against MULTIPART_STRICT_ERROR. [9] Target value: "0" [4] Operator completed in 0 usec. [4] Rule returned 0. [9] No match, not chained -> mode NEXT_RULE. [4] Recipe: Invoking rule 2b344d0; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "81"] [id "200003"]. [5] Rule 2b344d0: SecRule "MULTIPART_UNMATCHED_BOUNDARY" "!@eq 0" "phase:2,auditlog,id:200003,t:none,log,deny,status:44,msg:'Multipart parser detected a possible unmatched boundary.'" [4] Transformation completed in 0 usec. [4] Executing operator "!eq" with param "0" against MULTIPART_UNMATCHED_BOUNDARY. [9] Target value: "0" [4] Operator completed in 0 usec. [4] Rule returned 0. [9] No match, not chained -> mode NEXT_RULE. [4] Recipe: Invoking rule 2b35408; [file "c:\inetpub\wwwroot\owasp_crs\modsecurity.conf"] [line "95"] [id "200004"]. [5] Rule 2b35408: SecRule "TX:/^MSC_/" "!@streq 0" "phase:2,log,auditlog,id:200004,t:none,deny,msg:'ModSecurity internal error flagged: %{MATCHED_VAR_NAME}'" [4] Rule returned 0. [9] No match, not chained -> mode NEXT_RULE. [4] Hook insert_filter: Adding input forwarding filter (r 2b39440). [4] Hook insert_filter: Adding output filter (r 2b39440).

[atitan]

After few tests conducted, it seems POST-based pages are effected.
No post-data detected at PHP side if Modsec enabled.

[brenosilva]

Right,

What happens if you turn SecRequestBodyAccess Off ?

[atitan]

Now pages work after setting SecRequestBodyAccess Off.

[brenosilva]

This is a known issue. Looks like some modules other than ASP.NET have problem forward request body with ModSecurity.

Right now you cannot enable request body in this cases.

Thanks

Breno

[atitan]

Thanks for your help, Breno.

[beatinger]

There is actually another issue with ModSecurity with IIS, and that is, it does not allow objects to be created (error '80004005'). Took quite a while for us to figure this out. Using very latest version, and problem still exists.