Has the format of the modsecurity error.log message changed? #215
Comments
|
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: Old log entry: 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-- This is the blocking rule in 3.3.5: And this in 4.0: 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: Maybe the issue should go to the rules repository? |
|
Technically, rule Reading your Crowdsec rule, it looks to me like it should block on |
|
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:
I am going to open an issue against CRS, but let's continue to discuss this in this thread for your convenience. |
|
Hi Crowdsec works with parsers and scenarios to identify and block bad actors. Kind a fail2ban does. 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. 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. 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 |
|
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. 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. |
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. 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. 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. 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. |
|
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: 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: I guess it was omitted by thought I make sure 👍🏻 and we expect currently after the "ref" section this information 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. |
|
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 ( Request: Access LogError LogNotice how 933160 is not being logged in the error.log. AuditLog@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 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 But before you jump into action, let's wait what the CRS docker people have to say. |
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 |
|
@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 |
|
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 |
|
Here what I did: 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. |
|
It's different depending on how the container is started? |
|
All rule logs are written as |
|
In @LaurenceJJones 's screenshot above, there is a nonblocking 932160 alert on loglevel In your dump, though, there is 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:
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: 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 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 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. |
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. |
Note we have test files that i took the line from https://github.com/crowdsecurity/hub/blob/master/.tests/modsecurity-logs-nginx/modsecurity-logs-nginx.log so I didnt generate it live sorry maybe i should of made that clear |
|
So you mean this could have been doctored a bit? :) |
|
I believe we can let this to Crowdsec. They may need to update their test log files (3 years old). The only thing I don't get is that we have logging of detection rules with info level in Nginx and with error level with the Apache image (if I did get @dune73 right). Changing the logging of detection rules to level warn would be consistent with the wording, with the container default log level (without having log spam) and will work with Crowdsec parser. So is this the way to go? |
|
ModSecurity v2 (-> Apache) and ModSecurity v3 (-> Nginx) have many undocumented behavior differences. No surprise there. Let's wait for @airween, who knows the v3 code base very well. He's a bit busy at the moment, but I am sure we'll hear from him. |
If I understand correctly, this is the "original" problem, right? I don't know it is by design or an accident, but libmodsecurity3 puts each fields into the log, even the key does not set at all. See the source 29 msg.append(" [file \"" + std::string(*rm->m_ruleFile.get()) + "\"]");
30 msg.append(" [line \"" + std::to_string(rm->m_ruleLine) + "\"]");
31 msg.append(" [id \"" + std::to_string(rm->m_ruleId) + "\"]");
32 msg.append(" [rev \"" + utils::string::toHexIfNeeded(rm->m_rev, true) + "\"]");
33 msg.append(" [msg \"" + rm->m_message + "\"]");
34 msg.append(" [data \"" + utils::string::toHexIfNeeded(utils::string::limitTo(200, rm->m_data), true) + "\"]");
35 msg.append(" [severity \"" +
36 std::to_string(rm->m_severity) + "\"]");
37 msg.append(" [ver \"" + utils::string::toHexIfNeeded(rm->m_ver, true) + "\"]");
38 msg.append(" [maturity \"" + std::to_string(rm->m_maturity) + "\"]");
39 msg.append(" [accuracy \"" + std::to_string(rm->m_accuracy) + "\"]");The other fields ( |
|
No, the question is, whether v3 really always logs at |
Ah, thanks. Then I need to investigate this behavior, it's really strange.
And what if the mode is |
|
|
|
I made a quick inspection:
This is what I have to figure out, how. |
|
That makes sense and is consistent with the effect of changing the nginx log level. But the library must choose the desired log level for the message somewhere... |
|
Initially, I thought nginx might assign "error" if a module triggers a 403 and it assigns "info" if no such thing happens. But I think that must be unlikely, since the logging instruction and the return value instructing the webserver to block a request are separate. Or at least this is how I see the processing working without deeper knowledge of the code base. If @airween's finding is confirmed and it's indeed nginx assigning the loglevel, then I guess we need to set the loglevel to info on the container and piss off users with the noise. For the record: the CIS NGINX Benchmark v2.0.1 recommends loglevel |
Usually the developer decides on what level a log statement is logged. It must be somewhere in the code. |
|
I played a bit I can work with log level info on the modescurity-crs:nginx container. :) The log spam can be simply ignored/filtered with a combination of cat and grep. So this is not an issue. As the Crowdsec parser is now looking on the log line of the detection rule, is will also detect line logged with DETECTION_PARANOIA_LEVEL higher than BLOCKING_PARANOIA_LEVEL. But this is not a CRS problem. |
|
Yes, correct about the higher PL. Which brings me back to my statement: CrowdSec better look at the blocking message than rule detection alerts. The distinction between detection and blocking paranoia level was made in order to fight false positives without blocking on them. If CrowdSec ignores that context and blocks IPs, it falls into this trap and executes on a false positive. @airween : Are you sure ModSec3 can't be made to log on level warn? |
Let me check this - I can try to take a look soon. |
|
Thank you. I get the feeling this is really important or we need to change the settings of the container. We need to deliver a container that actually works in prod and delivers the right amount of logs in the right format. |
|
Here is how the libmodsecurity3 handles the transactions. Libmodsecurity3 has a The application that embeds the library needs to create one, and pass it to the function If the If the This is by design from the beginning, I don't see any change in the logic lately. Note, that severity of log entries set up by Nginx, not the library. Here is where the connector sets the library's callback function for any non-disruptive log entries (with severity If somebody is interesting, I can provide a sample C code to demonstrate it. |
|
Thanks @airween. I think we can only do one thing from our side and that is to change default log level for nginx to |
|
Thank you for this detailed analysis @airween. This is now pretty much a ModSecurity problem, but the conversation started here, so I'll continue here. Summing things up: Nginx knows these log levels:
Based on the behavior of ModSecurity, it determines that rule alerts that are not directly blocking a request should be info, ignoring the fact that the rule alerts are the root cause of a likely subsequent blocking of the same request and that the alert says "Warning". How do other modules ever log on level On Apache, we could cope with the situation by assigning different modules a different loglevel, Nginx is less flexible, so we pretty much force people to use either the cumbersome Audit Log, or to eat all the noise that comes with running at |
|
I believe to change the log level to warn would be a good idea. This is an error.log of the Nginx with log level set to info: where there are then lot of entries like the last two lines (mainly the last line). Besindes this I only have the Modsecurity statement for the detection rule with level info and the log statement of the blocking rule with level error. |
|
I generally agree. Yet, the Center for Internet security advocates running Nginx on level "info" in the CIS Nginx Benchmark, a widespread hardening guide. Personally, I am a bit torn on that question, but Nginx should definitely log ModSec warnings on level |
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?
The text was updated successfully, but these errors were encountered: