modsecurity-crs-docker
modsecurity-crs-docker copied to clipboard
coreruleset
Has the format of the modsecurity error.log message changed?
I just updated the first of my containers with the new version 4.
After some adjustments the only issue left is that my CrowdSec instance no longer detects the ips of the rejected clients. Crowdsec is parsing the nginx error.log and until the update of the modsecurity container it worked well.
Has the format of the message written to the error.log somehow changed?
Not that I'm aware of. Could you post examples of pre v4 / v4 logs so I can see the difference?
Hi @theseion
I've taken the same request on both my systems, one with the new CRS 4.0, one with the old 3.5.5.
New log entry:
2024/03/08 18:26:50 [error] 89#89: *546 [client 2a03:1b20:b:f011::a01d] ModSecurity: Access denied with code 403 (phase 2). Matched "Operator Ge' with parameter 5' against variable TX:BLOCKING_INBOUND_ANOMALY_SCORE' (Value: 5' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "176"] [id "949110"] [rev ""] [msg "Inbound Anomaly Score Exceeded (Total Score: 5)"] [data ""] [severity "0"] [ver "OWASP_CRS/4.0.0"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "anomaly-evaluation"] [hostname "10.0.2.100"] [uri "/"] [unique_id "170991881036.291448"] [ref ""], client: 2a03:1b20:b:f011::a01d, server: , request: "GET /?exec=/bin/bash HTTP/1.1", host: "fedi.0x42.ch"
Old log entry:
2024/03/08 18:27:55 [error] 100#100: *14928 [client 2a03:1b20:b:f011::a01d] ModSecurity: Access denied with code 403 (phase 2). Matched "Operator Ge' with parameter 5' against variable TX:ANOMALY_SCORE' (Value: 5' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "81"] [id "949110"] [rev ""] [msg "Inbound Anomaly Score Exceeded (Total Score: 5)"] [data ""] [severity "2"] [ver "OWASP_CRS/3.3.5"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-generic"] [hostname "10.0.2.100"] [uri "/"] [unique_id "170991887581.167881"] [ref ""], client: 2a03:1b20:b:f011::a01d, server: , request: "GET /?exec=bin/bash HTTP/1.1", host: "nc1.0x42.ch"
The difference is the severity which is now 0 in the new version. The Crowdsec scenario blocks on CRITICAL aka value 2.
So why is severity now 0?
This is the part H in the modsec audit log:
---6D9Yq7X2---H--
ModSecurity: Warning. Matched "Operator PmFromFile' with parameter unix-shell.data' against variable ARGS:exec' (Value: /bin/bash' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-932-APPLICATION-ATTACK-RCE.conf"] [line "556"] [id "932160"] [rev ""] [msg "Remote Command Execution: Unix Shell Code Found"] [data "Matched Data: bin/bash found within ARGS:exec: /bin/bash"] [severity "2"] [ver "OWASP_CRS/4.0.0"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "application-multi"] [tag "language-shell"] [tag "platform-unix"] [tag "attack-rce"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "capec/1000/152/248/88"] [tag "PCI/6.5.2"] [hostname "10.0.2.100"] [uri "/"] [unique_id "170991881036.291448"] [ref "o1,8v11,9t:cmdLine,t:normalizePath"]
ModSecurity: Access denied with code 403 (phase 2). Matched "Operator Ge' with parameter 5' against variable TX:BLOCKING_INBOUND_ANOMALY_SCORE' (Value: 5' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "176"] [id "949110"] [rev ""] [msg "Inbound Anomaly Score Exceeded (Total Score: 5)"] [data ""] [severity "0"] [ver "OWASP_CRS/4.0.0"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "anomaly-evaluation"] [hostname "10.0.2.100"] [uri "/"] [unique_id "170991881036.291448"] [ref ""]
This is the blocking rule in 3.3.5:
SecRule TX:ANOMALY_SCORE "@ge %{tx.inbound_anomaly_score_threshold}" \
"id:949110,\
phase:2,\
deny,\
t:none,\
log,\
msg:'Inbound Anomaly Score Exceeded (Total Score: %{TX.ANOMALY_SCORE})',\
tag:'application-multi',\
tag:'language-multi',\
tag:'platform-multi',\
tag:'attack-generic',\
ver:'OWASP_CRS/3.3.5',\
severity:'CRITICAL',\
setvar:'tx.inbound_anomaly_score=%{tx.anomaly_score}'"
And this in 4.0:
SecRule TX:BLOCKING_INBOUND_ANOMALY_SCORE "@ge %{tx.inbound_anomaly_score_threshold}" \
"id:949110,\
phase:2,\
deny,\
t:none,\
msg:'Inbound Anomaly Score Exceeded (Total Score: %{TX.BLOCKING_INBOUND_ANOMALY_SCORE})',\
tag:'anomaly-evaluation',\
tag:'OWASP_CRS',\
ver:'OWASP_CRS/4.0.1-dev'"
As we see: the severity is missing. This is causing the problem with Modsec no longer detecting the log entry as relevant for blocking.
This is the filter line in Crowdsec:
filter: evt.Meta.log_type == 'modsecurity' && (evt.Parsed.ruleseverity == 'CRITICAL' || evt.Parsed.ruleseverity == '2')
Maybe the issue should go to the rules repository?
Technically, rule 949110 only performs the blocking action, it's not itself a rule for an attack that needs to have a severity rating. That being said, I'm not entirely sure that dropping the severity was a conscious decision. In the related PR at least that point wasn't discussed. I'm sure, @dune73 could shed some more light on this.
Reading your Crowdsec rule, it looks to me like it should block on 932160 anyway, right? What's more, you could modify the rule to block whenever you see 949110, since that means the blocking action was executed.
Very interesting case. Very good you bring this up @ne20002. Sorry for the inconvenience. It is something somebody should have caught pre-release but if we fix in the next few days we can fix it for 4.1.0 due in the next few days.
So there are detection rules and administrative rules in CRS. 932160 is a detection rule, it identifies the request as an attacking request. Then there are the administrative rules that do all sorts of things. In that group we also have the blocking rules in 949 and 959.
The refactoring of the scoring variables also removed the severity item from the administrative rules. You will notice there is an initialization rule carrying the severity tag, but that's a special case that alarms on broken configurations.
Now the severity item is meant to be in sync with the anomaly score of a detection rule. Critical severity adds 5 points to the anomaly score.
With all this being said, I think or settings are more consistent with the intentions of the rule set with CRS4 than they were with CRS3.
But of course we want to me this work with CrowdSec. Exploring CrowdSec has been on my 2do list for too long. But I am still not familiar with the exact mechanism.
Here are a few questions:
- So what does CrowdSec do with the logs exactly?
- Why is it interested in the blocking rule?
- What functionality is broken now?
I am going to open an issue against CRS, but let's continue to discuss this in this thread for your convenience.
Hi Thank you all very much.
Crowdsec works with parsers and scenarios to identify and block bad actors. Kind a fail2ban does. The Crowsec parser for Modsecurity works on the Nginx error.log. After parsing info Crowdsec decides with the matching scenario.
Within parsing a number of values are extracted from the entry in the logfile. In the scenario then a decision is made based on those values. In the current version of Crowdsec, the Crowdsec scenario acts on entries starting with 'modsecuriy' and having the string CRITICAL or a severity of 2. I believe they just want to act on critical which for me makes sense.
With the new CRS 4.0 neither the string CRITICAL nor a severity 2 is present in the log entry written to Nginx error.log. In fact, severity is now always 0. This is, why Crowdsec no longer sees the log entries. Blocking by Modsecurity is still working, but using Crowdsec and blocking identified bad actors by their ip right away on the router (or where the Crowdsec bouncer is running) makes a lot of sense (as well as sharing information of detected bad actors with the Crowdsec community) to me.
If I understand then looking on the other rules as described above would need to parse the Modsecurity audit log instead of the Nginx error log. I believe this would put on some extra resource usage and is more difficult to implement.
I think, that a value describing criticality and severity in the log entry in Nginx error.log is not a bad idea. In fact, those values are still written, but are emtpy or 0.
I also see a possiblity to fix this on Crowdsec side by looking on different info in the log entry like 'Access denied' and 'Anomaly Score Exceeded'. Not sure what the best solution would be. But I'd go for writing the severity to the error.log (maybe based on the highest severity of underlying rules, not sure if this is possible).
Very, good. I see what is going on now.
I dare say CrowdSec is not doing this in a very smart way.
Making CrowdSec making good use of ModSec and CRS probably means talking to the developers of the integration. Can you get me in touch with the relevant people?
Your description says that it will act on ModSec + critical/severity 2. That means it acts on 932160 and you do not have to do anything. Given 90+% of the CRS detection rules are in the critical category, we only have a problem if 2 or more rules below the critical threshold team up to trigger 949110 leading to a blockade, but lacking the severity in all the rules triggered CrowdSec ignores it. I think this relatively rare in production and if it happens it is often a false positive (e.g. Loadbalancer doing a health check with IP address as Host header and without an accept header)
There is a question where you want the CrowdSec / Fail2Ban logic to happen. Do you want (1) CrowdSec / Fail2Ban try and make sense of the various CRS alerts, make up their mind and decide on a blocking decision. Or do you want to (2) just follow the blocking decision of CRS that has more insight into the rules and the alerts than CrowdSec / Fail2Ban.
What CrowdSec attempts to do is (1) from my point and view and I think it should do (2).
I have a fail2ban setup and it's as simple as block IPs that hit a 403 in the Apache access log 3 times.
If I was to do that with CRS, I would either look for alerts of the blocking rules (949110, 949111, 959100, 959101) or I would make sure the reporting level is at 1 or above (default is 4) and then look for rule 980170.
Actually looking for e.g 932160 is not that easy, as Crowdsec is parsing the Nginx error.log. The parser is looking for a line starting with 'modsecurity' and either critical or severity 2. which means, it acted on all entries written to the error.log because of a blocking decision in Modsecurity/CRS 3.5. Afaik, only blocking rules are logged to Nginx's error.log. The relevant change causing the issue is the lack of the severity 2 in the error.log which is now 0.
I'm not a Crowdsec developer but I'll file an issue at crowdsec project and on discourse.crowdsec.net.
I'm not running an online banking, I just run my very own small Friendica and Nextcloud server. Thus, I consider all triggering of CRS rules an illegal connection attempt and want to block them right away, if possible on my router by ip blocking to reduce resource usage on my small systems. ;)
Also, this problem does not only affects me but all users of Modsecurity/CRS with Crowdsec. I have no idea how much users have this setup. It might also affect users of other tools scanning the Nginx error.log in a similar way. But I'm not aware of any tools like this. Changing the parser may be the right way to go but would need all users of those two tools together to update them both.
I agree that as Crowdsec is relying on information in the log lines made by the CRS, it's Crowdsec's responsibility to change their parser. On the other hand I wonder if the logging information provided by the CRS shall include a few more information on the blocking decission so that other tools can work with that.
@theseion, @dune73
There is a question where you want the CrowdSec / Fail2Ban logic to happen. Do you want (1) CrowdSec / Fail2Ban try and make sense of the various CRS alerts, make up their mind and decide on a blocking decision. Or do you want to (2) just follow the blocking decision of CRS that has more insight into the rules and the alerts than CrowdSec / Fail2Ban.
Maybe we should widen the view on the issue. I see CRS as responsible for detecting attacks, etc and it is doing well. If there is no need for the severity in the log from CRS' point of view, that is ok. As Crowdsec is relying on the log entries from CRS, it should work on what is available.
On the other hand, Crowdsec is much more than just blocking. It collects information about attacks, it combines information from different sources and user / systems. It also provides a larger picture on an actual threat situation. For this it requires a bit more information than just 'CRS decided to block a request'. As this wider view will probably become more and more important, it would be good when CRS would provide a bit more insights.
Having said that, I still see no need in changing anything in CRS. If Crowdsec wants to go with (2) a simple parser acting on the error.log of Nginx/Apache would be sufficiant. If more information is of interesst, as of (1), an enhanced parser working on the CRS audit.log would be a second option. It would be up to the Crowdsec user to decide.
The only thing to do at the moment is to provide a workaround on Crowdsec side to make the parser / scenario work again with the CRS version 4 so that at least (2) is still working. An enhanced parser / scenario would be a seperate task to take.
For me I will try to manipulate my local scenario file and see if I get it working again for (2). ;)
@ne20002 If you don't mind log spam, you can set the error logging level in Nginx to info. It will display all the triggered rules and not just the anomoly scoring rule that blocked the request, most rules have an severity level of 2 which is enough to trigger the scenario. If you modify the ModSecurity scenario then it'll become tainted and you won't receive automatic updates for the ModSecurity collection. Or you could just copy the scenario, change it's name(to avoid conflicts) and make the modifications you need to avoid tainting the ModSecurity collection.
Yes, copying is the way I go. It should fix the current problem until an official fix is available.
@ne20002 Thank you for the followup.
I do not get this, though.
You quoted the following logline above:
ModSecurity: Warning. Matched "Operator PmFromFile' with parameter unix-shell.data' against variable ARGS:exec' (Value: /bin/bash' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-932-APPLICATION-ATTACK-RCE.conf"] [line "556"] [id "932160"] [rev ""] [msg "Remote Command Execution: Unix Shell Code Found"] [data "Matched Data: bin/bash found within ARGS:exec: /bin/bash"] [severity "2"] [ver "OWASP_CRS/4.0.0"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "application-multi"] [tag "language-shell"] [tag "platform-unix"] [tag "attack-rce"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "capec/1000/152/248/88"] [tag "PCI/6.5.2"] [hostname "10.0.2.100"] [uri "/"] [unique_id "170991881036.291448"] [ref "o1,8v11,9t:cmdLine,t:normalizePath"]
This matches the criteria you pointed out above: It starts with "ModSecurity" and it carries a severity of "2".
And I would be very surprised if NGINX would only log the blocking decision and not the detection rule. The idea is clearly to log both: The detection rules with their alerts and the blocking decision (if any).
You asked for CRS to log more information about a request. This is that the detection rules are doing. If you want a better summary of the blocking decision with more information, then I suggest you look into the CRS4 reporting level used in the RESPONSE-980 rule group.
But first, let's get this logging situation sorted out: If CrowdSec works the way you say it does, then a 933160 alert should be logged by Nginx and it should trigger CrowdSec.
@ne20002 Thank you for the followup.
I do not get this, though.
You quoted the following logline above:
ModSecurity: Warning. Matched "Operator PmFromFile' with parameter unix-shell.data' against variable ARGS:exec' (Value: /bin/bash' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-932-APPLICATION-ATTACK-RCE.conf"] [line "556"] [id "932160"] [rev ""] [msg "Remote Command Execution: Unix Shell Code Found"] [data "Matched Data: bin/bash found within ARGS:exec: /bin/bash"] [severity "2"] [ver "OWASP_CRS/4.0.0"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "application-multi"] [tag "language-shell"] [tag "platform-unix"] [tag "attack-rce"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "capec/1000/152/248/88"] [tag "PCI/6.5.2"] [hostname "10.0.2.100"] [uri "/"] [unique_id "170991881036.291448"] [ref "o1,8v11,9t:cmdLine,t:normalizePath"]This matches the criteria you pointed out above: It starts with "ModSecurity" and it carries a severity of "2".
And I would be very surprised if NGINX would only log the blocking decision and not the detection rule. The idea is clearly to log both: The detection rules with their alerts and the blocking decision (if any).
You asked for CRS to log more information about a request. This is that the detection rules are doing. If you want a better summary of the blocking decision with more information, then I suggest you look into the CRS4 reporting level used in the RESPONSE-980 rule group.
But first, let's get this logging situation sorted out: If CrowdSec works the way you say it does, then a 933160 alert should be logged by Nginx and it should trigger CrowdSec.
Just so I can attempt to help, Laurence from CrowdSec Support 👋🏻
The example line shown doesnt have the nginx error prefix example:
2024/02/08 00:56:35 [error] 2120350#2120350: *527836 [client 1.2.3.4]
I guess it was omitted by thought I make sure 👍🏻
and we expect currently after the "ref" section this information
, client: %{IPORHOST:remote_addr}, server: %{DATA:target_fqdn}, request: \"%{WORD:verb} %{DATA:request} HTTP/%{NUMBER:http_version}\"(, host: \"%{IPORHOST}(:%{INT})?\")?
If this information is now not needed or is logged on a conditional basis we can make this optional for the line to parse example
Actually I'm using Crowdsec and CRS/Nginx container. It logs detection rule and blocking rule to Modesc audit.log. But to error.log only the blocking rule is logged. This in version 3.3.5 and 4.0.0. The Crowdsec parser looks only on the error.log.
Hey @LaurenceJJones, thank you for joining the discussion. I'm sure we can sort this out to make things run smoothly for CrowdSec users.
Trying to recreate the logging situation locally now.
OK. So this is not what I expected to find. The logging on the official CRS Nginx container (nginx-alpine) is as described as above.
Request: curl localhost:8080 --data "exec:/bin/bash" -H "Host: localhost" -v
Access Log
127.0.0.1 - - [11/Mar/2024:15:29:29 +0000] "POST / HTTP/1.1" 403 146 "-" "curl/8.5.0" "-"
Error Log
2024/03/11 15:29:29 [error] 538#538: *24 [client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 2). Matched "Operator `Ge' with parameter `5' against variable `TX:BLOCKING_INBOUND_ANOMALY_SCORE' (Value: `5' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "176"] [id "949110"] [rev ""] [msg "Inbound Anomaly Score Exceeded (Total Score: 5)"] [data ""] [severity "0"] [ver "OWASP_CRS/4.0.0"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "anomaly-evaluation"] [hostname "127.0.0.1"] [uri "/"] [unique_id "171017096930.654276"] [ref ""], client: 127.0.0.1, server: localhost, request: "POST / HTTP/1.1", host: "localhost"
Notice how 933160 is not being logged in the error.log.
AuditLog
{"transaction":{"client_ip":"127.0.0.1","time_stamp":"Mon Mar 11 15:29:29 2024","server_id":"0464d6f362807f483b1335360064b441bc6da3a9","client_port":50446,"host_ip":"127.0.0.1","host_port":8080,"unique_id":"171017096930.654276","request":{"method":"POST","http_version":1.1,"uri":"/","headers":{"Host":"localhost","User-Agent":"curl/8.5.0","Accept":"*/*","Content-Length":"14","Content-Type":"application/x-www-form-urlencoded"}},"response":{"body":"<html>\r\n<head><title>403 Forbidden</title></head>\r\n<body>\r\n<center><h1>403 Forbidden</h1></center>\r\n<hr><center>nginx</center>\r\n</body>\r\n</html>\r\n","http_code":403,"headers":{"Server":"nginx","Date":"Mon, 11 Mar 2024 15:25:42 GMT","Content-Length":"146","Content-Type":"text/html","Connection":"keep-alive"}},"producer":{"modsecurity":"ModSecurity v3.0.12 (Linux)","connector":"ModSecurity-nginx v1.0.3","secrules_engine":"Enabled","components":["OWASP_CRS/4.0.0\""]},"messages":[{"message":"Remote Command Execution: Unix Shell Code Found","details":{"match":"Matched \"Operator `PmFromFile' with parameter `unix-shell.data' against variable `ARGS_NAMES:exec:/bin/bash' (Value: `exec:/bin/bash' )","reference":"o6,8v135,14t:cmdLine,t:normalizePath","ruleId":"932160","file":"/etc/modsecurity.d/owasp-crs/rules/REQUEST-932-APPLICATION-ATTACK-RCE.conf","lineNumber":"556","data":"Matched Data: bin/bash found within ARGS_NAMES:exec:/bin/bash: exec:/bin/bash","severity":"2","ver":"OWASP_CRS/4.0.0","rev":"","tags":["modsecurity","application-multi","language-shell","platform-unix","attack-rce","paranoia-level/1","OWASP_CRS","capec/1000/152/248/88","PCI/6.5.2"],"maturity":"0","accuracy":"0"}},{"message":"Inbound Anomaly Score Exceeded (Total Score: 5)","details":{"match":"Matched \"Operator `Ge' with parameter `5' against variable `TX:BLOCKING_INBOUND_ANOMALY_SCORE' (Value: `5' )","reference":"","ruleId":"949110","file":"/etc/modsecurity.d/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf","lineNumber":"176","data":"","severity":"0","ver":"OWASP_CRS/4.0.0","rev":"","tags":["modsecurity","anomaly-evaluation"],"maturity":"0","accuracy":"0"}}]}}
Pretty-Printed:
{
"transaction": {
"client_ip": "127.0.0.1",
"time_stamp": "Mon Mar 11 15:29:29 2024",
"server_id": "0464d6f362807f483b1335360064b441bc6da3a9",
"client_port": 50446,
"host_ip": "127.0.0.1",
"host_port": 8080,
"unique_id": "171017096930.654276",
"request": {
"method": "POST",
"http_version": 1.1,
"uri": "/",
"headers": {
"Host": "localhost",
"User-Agent": "curl/8.5.0",
"Accept": "*/*",
"Content-Length": "14",
"Content-Type": "application/x-www-form-urlencoded"
}
},
"response": {
"body": "<html>\r\n<head><title>403 Forbidden</title></head>\r\n<body>\r\n<center><h1>403 Forbidden</h1></center>\r\n<hr><center>nginx</center>\r\n</body>\r\n</html>\r\n",
"http_code": 403,
"headers": {
"Server": "nginx",
"Date": "Mon, 11 Mar 2024 15:25:42 GMT",
"Content-Length": "146",
"Content-Type": "text/html",
"Connection": "keep-alive"
}
},
"producer": {
"modsecurity": "ModSecurity v3.0.12 (Linux)",
"connector": "ModSecurity-nginx v1.0.3",
"secrules_engine": "Enabled",
"components": [
"OWASP_CRS/4.0.0\""
]
},
"messages": [
{
"message": "Remote Command Execution: Unix Shell Code Found",
"details": {
"match": "Matched \"Operator `PmFromFile' with parameter `unix-shell.data' against variable `ARGS_NAMES:exec:/bin/bash' (Value: `exec:/bin/bash' )",
"reference": "o6,8v135,14t:cmdLine,t:normalizePath",
"ruleId": "932160",
"file": "/etc/modsecurity.d/owasp-crs/rules/REQUEST-932-APPLICATION-ATTACK-RCE.conf",
"lineNumber": "556",
"data": "Matched Data: bin/bash found within ARGS_NAMES:exec:/bin/bash: exec:/bin/bash",
"severity": "2",
"ver": "OWASP_CRS/4.0.0",
"rev": "",
"tags": [
"modsecurity",
"application-multi",
"language-shell",
"platform-unix",
"attack-rce",
"paranoia-level/1",
"OWASP_CRS",
"capec/1000/152/248/88",
"PCI/6.5.2"
],
"maturity": "0",
"accuracy": "0"
}
},
{
"message": "Inbound Anomaly Score Exceeded (Total Score: 5)",
"details": {
"match": "Matched \"Operator `Ge' with parameter `5' against variable `TX:BLOCKING_INBOUND_ANOMALY_SCORE' (Value: `5' )",
"reference": "",
"ruleId": "949110",
"file": "/etc/modsecurity.d/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf",
"lineNumber": "176",
"data": "",
"severity": "0",
"ver": "OWASP_CRS/4.0.0",
"rev": "",
"tags": [
"modsecurity",
"anomaly-evaluation"
],
"maturity": "0",
"accuracy": "0"
}
}
]
}
}
@theseion, @fzipi, @franbuehler : Is this logging behavior desired? If yes, how did you pull this off? (seriously, I am not sure how you can do this with ModSec. Based on the rule configuration, I would say 932160 and 949110 would both be logged in the error.log. Or none of the two.)
Or is it a funny side-effect of the SecDefaultAction used here in combination with ModSecurity v3?
I'm a bit at a loss, since this brings CrowdSec in a troubling situation.
@LaurenceJJones : I think looking for the severity in a ModSec alert message is not the best approach. Custom rules written by a user or some other 3rd party are unlikely to carry a severity value most of the time.
A dead-beat indication that ModSecurity has taken action is to look for ModSecurity: Access denied in the error.log. See above. This is consistent across all ModSecurity versions and I have never seen it lie. Triggering CrowdSec on this pattern would be basing on the fact that the WAF was instructed to block a request for whatever reason and that's very close to desiring CrowdSec to block the same client for subsequent requests.
But before you jump into action, let's wait what the CRS docker people have to say.
Notice how 933160 is not being logged in the error.log.*
This is how it worked since I use the modesurity-crs container.
I believe implementing/restoring the logging of the triggered detection rule to the error.log would be best in any case.
Changing the Crowdsec parser to look on ModSecurity: Access denied would also be a good idea.
But I like the idea of Crowdsec being able, besides blocking subsequent requests, to collect more information on the reason for blocking, not only severity but e.g. rule number, from maybe many attacked instances to send it to central api and use this for community decisions.
@dune73 I can't recreate what you see using the compose setup for CRS (I would have been very surprised too, because many of our tests would fail against nginx otherwise).
Error log entries for curl localhost:8080 --data "exec:/bin/bash" -H "Host: localhost" -v:
2024/03/11 18:17:22 [info] 105#105: *1 ModSecurity: Warning. Matched "Operator `Rx' with parameter `^(?:(?:\*|[^!\"\(\),/:-\?\[-\]\{\}]+)/(?:\*|[^!\"\(\),/:-\?\[-\]\{\}]+)|\*)(?:[\s\v]*;[\s\v]*(?:charset[\s\v]*=[\s\v]*\"?(?:iso-8859-15?|utf-8|windows-1252)\b\"?|(?:[^\s\v-\"\(\),/:-\?\[-\]c\{\}]|c(?: (728 characters omitted)' against variable `REQUEST_HEADERS:Accept' (Value: `*/*' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-920-PROTOCOL-ENFORCEMENT.conf"] [line "1241"] [id "920600"] [rev ""] [msg "Illegal Accept header: charset parameter"] [data "*/*"] [severity "2"] [ver "OWASP_CRS/4.0.1-dev"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-protocol"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [hostname "172.18.0.3"] [uri "/"] [unique_id "171018104222.881454"] [ref "v63,3t:lowercase"], client: 192.168.65.1, server: localhost, request: "POST / HTTP/1.1", host: "localhost"
2024/03/11 18:17:22 [info] 105#105: *1 ModSecurity: Warning. Matched "Operator `ValidateByteRange' with parameter `38,44-46,48-58,61,65-90,95,97-122' against variable `REQUEST_BODY' (Value: `exec:/bin/bash' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-920-PROTOCOL-ENFORCEMENT.conf"] [line "1799"] [id "920273"] [rev ""] [msg "Invalid character in request (outside of very strict set)"] [data "REQUEST_BODY=exec:/bin/bash"] [severity "2"] [ver "OWASP_CRS/4.0.1-dev"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-protocol"] [tag "paranoia-level/4"] [tag "OWASP_CRS"] [tag "capec/1000/210/272"] [hostname "172.18.0.3"] [uri "/"] [unique_id "171018104222.881454"] [ref "o5,1o9,1v135,14t:urlDecodeUnio5,1o9,1v135,14t:urlDecodeUni"], client: 192.168.65.1, server: localhost, request: "POST / HTTP/1.1", host: "localhost"
2024/03/11 18:17:22 [info] 105#105: *1 ModSecurity: Warning. Matched "Operator `PmFromFile' with parameter `unix-shell.data' against variable `ARGS_NAMES:exec:/bin/bash' (Value: `exec:/bin/bash' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-932-APPLICATION-ATTACK-RCE.conf"] [line "556"] [id "932160"] [rev ""] [msg "Remote Command Execution: Unix Shell Code Found"] [data "Matched Data: bin/bash found within ARGS_NAMES:exec:/bin/bash: exec:/bin/bash"] [severity "2"] [ver "OWASP_CRS/4.0.1-dev"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "application-multi"] [tag "language-shell"] [tag "platform-unix"] [tag "attack-rce"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "capec/1000/152/248/88"] [tag "PCI/6.5.2"] [hostname "172.18.0.3"] [uri "/"] [unique_id "171018104222.881454"] [ref "o6,8v135,14t:cmdLine,t:normalizePath"], client: 192.168.65.1, server: localhost, request: "POST / HTTP/1.1", host: "localhost"
2024/03/11 18:17:22 [info] 105#105: *1 ModSecurity: Warning. Matched "Operator `Ge' with parameter `5' against variable `TX:BLOCKING_INBOUND_ANOMALY_SCORE' (Value: `20' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "222"] [id "949110"] [rev ""] [msg "Inbound Anomaly Score Exceeded (Total Score: 20)"] [data ""] [severity "0"] [ver "OWASP_CRS/4.0.1-dev"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "anomaly-evaluation"] [tag "OWASP_CRS"] [hostname "172.18.0.3"] [uri "/"] [unique_id "171018104222.881454"] [ref ""], client: 192.168.65.1, server: localhost, request: "POST / HTTP/1.1", host: "localhost"
I took a look at the compose file and set the values accordingly in my setup. I still have the issue. I'm not using compose but start the container from shell script with docker run.
In error.log only the blocking rule is logged, in audit.log both rules are logged.
In my error.log the entry starts with 2024/03/11 20:32:21 [error] whereas the entries in the log of @theseion starting with 2024/03/11 18:17:22 [info] . Is this a problem of log level?
Here what I did:
host $ docker buildx bake -f docker-bake.hcl --set "*.platform=linux/amd64" --load nginx-alpine
...
host $ docker run -ti --rm --name crs owasp/modsecurity-crs:nginx-alpine &
...
host $ docker exec -u 0 -it crs /bin/sh
...
EDIT FILES TO GET SEPARATE access.log, error.log and audit.log
...
crs $ kill -HUP 1
...
crs $ curl localhost:8080 --data "exec:/bin/bash" -H "Host: localhost" -v
With the logs all set to write to STDOUT / STDERR, it's difficult to keep them apart and to understand where the messages really originate from. Hence the separation.
All rule logs are written as info messages, except for the final blocking message, which is logged as error. However, for the blocking message to be logged, the engine has to be set to On, not DetectionOnly.
@theseion :
In @LaurenceJJones 's screenshot above, there is a nonblocking 932160 alert on loglevel error.
In your dump, though, there is 2024/03/11 18:17:22 [info] 105#105: for the blocking rule 949110. Or was that done via DetectionOnly?
This just does not add up for me.
That's my gut feeling as well. And I would be pleased if somebody with more docker FU than me (I'm like the least docker-experienced person you can think of) would play this through and dig at the bottom of this.
If I may sum up what we expect and see:
-
In CRS 3.3.5 the blocking rule has been logged to Nginx error.log with loglevel error and with severity = 2.
-
The Crowdsec parser was able to identify the log entry as it looks on the log line prefix and on severity = 2.
-
In my setup the detection rule has not been logged in the error.log.
-
With CRS 4 severity is now logged with 0 for blocking rules. As the detection rule is not logged to error.log, the Crowdsec parser now fails.
-
The expectation is, that the detection rule should also have been logged to error.log with log level error. If this would be the case, the Crowdsec parser would detect it. @theseion, is this expectation correct?
-
At least @dune73 can reproduce the behavior as described by me. We both start the modsecurity-crs:nginx container with docker run command (podman run in my case). Whereas @theseion started it with docker compose, the automatic tests also use docker compose.
7: I suspect that the behavior is caused by either the different way of starting the container or by the setting of the engine set to On versus DetectionOnly (suppressing the logging of the detection rule if set to On).
I have changed my Nginx error_log setting to level info. Now I get the detection rule logged in the error.log:
2024/03/12 11:00:08 [info] 91#91: *59 ModSecurity: Warning. Matched "Operator `PmFromFile' with parameter `unix-shell.data' against variable `ARGS:exec' (Value: `/bin/bash' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-932-APPLICATION-ATTACK-RCE.conf"] [line "556"] [id "932160"] [rev ""] [msg "Remote Command Execution: Unix Shell Code Found"] [data "Matched Data: bin/bash found within ARGS:exec: /bin/bash"] [severity "2"] [ver "OWASP_CRS/4.0.0"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "application-multi"] [tag "language-shell"] [tag "platform-unix"] [tag "attack-rce"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "capec/1000/152/248/88"] [tag "PCI/6.5.2"] [hostname "10.0.2.100"] [uri "/"] [unique_id "171023760855.494742"] [ref "o1,8v11,9t:cmdLine,t:normalizePath"], client: 2a03:1b20:b:f011::a01d, server: , request: "GET /?exec=/bin/bash HTTP/1.1", host: "fedi.xxxx.ch"
2024/03/12 11:00:08 [error] 91#91: *59 [client 2a03:1b20:b:f011::a01d] ModSecurity: Access denied with code 403 (phase 2). Matched "Operator `Ge' with parameter `5' against variable `TX:BLOCKING_INBOUND_ANOMALY_SCORE' (Value: `5' ) [file "/etc/modsecurity.d/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "176"] [id "949110"] [rev ""] [msg "Inbound Anomaly Score Exceeded (Total Score: 5)"] [data ""] [severity "0"] [ver "OWASP_CRS/4.0.0"] [maturity "0"] [accuracy "0"] [tag "modsecurity"] [tag "anomaly-evaluation"] [hostname "10.0.2.100"] [uri "/"] [unique_id "171023760855.494742"] [ref ""], client: 2a03:1b20:b:f011::a01d, server: , request: "GET /?exec=/bin/bash HTTP/1.1", host: "fedi.xxxx.ch"
But I also get a lot of log spam. :(
If this is the expected behaviour (@dune73 and I expected otherwise) than this needs to be documented, especially for the Crowdsec parser (@LaurenceJJones).
If this is the expected behaviour maybe a setting defining the log level for the detection rule in the error.log would be an option?
OK, we getting near the bottom now.
This very close to the desired behavior now. I am not using ModSec3 myself and on ModSec2 / Apache everything is on level error. No difference between "ModSecurity: Warning" (= pass) and "ModSecurity: Access denied" (= deny) there. But here we apparently have it.
Still not sure why @LaurenceJJones got an "error" on his screenshot in combination with "ModSecurity: warning".
But this piece of the puzzle left aside, it looks like the docker container is running at level warn by default, but the engine logs decisive information at level info.
Also ModSecurity logging the word "Warning" on loglevel "Info" is obviously wrong.
@airween : What is your take?
The signal to noise ratio now looks worse for you @ne20002, but that's because you are probably not used to seeing these alerts. But seeing them is part of the operation and helps with the decision if it's a real alert or a false positive.
Now I would advise CrowdSec against blocking on this 930160 alert message that qualifies the defined criteris (ModSecurity + severity 2). I think it's better to trigger on "ModSecurity: Access denied". Optionally, if you want to limit to CRS, then "ModSecurity: Access denied" + "tag: OWASP_CRS".
But the docker container has to be fixed or better still, ModSecurity3 should start to log at a reasonable loglevel.
The log spam is more other info messages printed by Nginx, not Modsecurity related. From Modsecurity I only see the detection rule with level info.
I agree that if the detection rule would be logged with level warn (as it is a warning), everything would be fine and it would suit the default log level of the container.
I have a bit different position regarding Crowdsec as I believe Crowdsec should be able to do its own decission. Modsecurity with CRS is excellent in detecting and blocking single requests. Crowdsec on the other hand is a level ontop and e.g has options to block an ip after a predefined number of attempts or based on extra information it gets from Modsecurity like severity, ruleId and also and more important to share this with the community and may benefit from a bit more information for this decission.
The log spam is more other info messages printed by Nginx, not Modsecurity related. From Modsecurity I only see the detection rule with level info.
On Apache, you can set different loglevels for different modules. Do you know if Nginx allows for the same granularity?
As for CrowdSec: All agreed. This is up to CrowdSec. It's just that we need to provide CrowdSec with the necessary information. And CrowdSec using a tangential piece like "severity" is a bad choice though. I think CrowdSec needs to use patterns that allow it to understand what ModSec / CRS is doing exactly and then it can take that decision on a sound base.
I haven't spent much time yet looking into the issue but I have no clue how @LaurenceJJones managed to log that rule at error level. I went back and looked at older images (back to 3.3.2) and they all log at info level. Seems we're missing something.