owasp-modsecurity / ModSecurity

ModSecurity is an open source, cross platform web application firewall (WAF) engine for Apache, IIS and Nginx. It has a robust event-based programming language which provides protection from a range of attacks against web applications and allows for HTTP traffic monitoring, logging and real-time analysis.
https://www.modsecurity.org
Apache License 2.0
8.3k stars 1.61k forks source link

SecRequestBodyAccess off skips the phase:2 rules #2465

Open airween opened 3 years ago

airween commented 3 years ago

Describe the bug

If the SecRequestBodyAccess is off, then the engine skips all rules which has phase:2 action.

To Reproduce

Here you can find a regression test case.

In the debug log you can see this line:

[nnnnnn] [/?q=evil] [4] Request body processing is disabled

Expected behavior

As you can see, the request contains an XML payload (CT doesn't count...), and only one (relevant) rule with id:1. The rule has two variable: REQUEST_URI and REQUEST_BODY. First one available in phase 1, but the second one only in phase 2, so the rule set to phase 2. The request was constructed that both variable matches, but the test returns with 200.

The expected behavior is 403, because the config disables only the processing of request body, not the whole phase 2.

If you replace the phase:2 by phase:1 in rule 1, then the request will blocked as it expected.

Server (please complete the following information):

Additional context

There are two another issues related to this wrong behavior: #1940 - CRS issue - this helped me to describe this behavior

2273 - ModSecurity - SecRequestBodyAccess Off doesn't fully disable request body processing

I checked the source, and found a very strange solution to handle the SecRequestBodyAccess - looks like the appendBody() allocates a buffer even thought the variable set it to off. In addition, the chosen body processor also woke up, and the payload will parsed. Checking the body access is comes only at this point, that's why the #2273 exists. I assume that users disable the body access to save CPU/memory (as reporter also wrote there), but in this isn't fulfilled.

The another strange behavior is if the SecRequestBodyAccess is off, then whole phase 2 will ignored (in line 895-911), because the evaluation called later, in L938.

Note: I didn't checked, but I suppose the ctl:requestBodyAccess=off would give same result.

airween commented 3 years ago

Sorry to say, but same behavior in case of SecResponseBodyAccess - if it's off, then whole phase:4 ignored.

Test case here. Problem is similar: the function returns by true if the body access is off, the evaluation won't called.

martinhsv commented 3 years ago

Hmm. I guess I can understand why it was coded that way (and some might even challenge whether it's a bug at all).

Given that phase:2 occurs at 'request body has been received', and one does not want to access the request body, it's not immediately obvious why one would write a rule to occur at phase:2. I.e. if your rule is checking request headers, why not make it a phase:1 rule? For example, this would seem to be the case with the cited rule 913100.

On the other hand, I can see at least some cases where this would be a problem -- particularly with generic rule sets.

For example, suppose a generic rule is intended to perform some detection against ARGS (both query args and post args), and so it is set up as a phase:2 rule. But a particular administrator is not interested in examining the request body and so sets SecResponseBodyAccess to off. In this case use of the rule will have been inadvertently turned off for query args as well.

dune73 commented 3 years ago

You hit the nail on the head with your reasoning why most rules are written in phase 2. A quick peek at the Trustwave rule set tells me that it's over 99% of the rules. The ratio is better with CRS, but this is a serious problem and I hope you can fix this soon.

airween commented 3 years ago

Thanks for quick response - I just followed the mod_security2 behavior.

While it works as I wrote that expected, I assume the v3 should follow that way - or make a separated documentation, how the new version works.

Anyway, using of phase action is just one thing - the another is the #2273: if the SecRequestBodyAccess is off, why does engine start to parse that?

marcstern commented 3 years ago

if your rule is checking request headers, why not make it a phase:1 rule? Several reasons:

  • with "configure --enable-request-early", phase 1 rules cannot be embedded in Location
  • some header rules may depend on request body (for instance the body size)
  • etc.
zimmerle commented 3 years ago

Not executing the rules seems to be a little too radical for my taste. On the other hand, I understand the value of not running it for performance reasons and other points cited below. Furthermore, it is easy to maintain the rules by having the execute-ever approach, given that it will allow cross-phases variables in a single Rule.

The cross-phase variables is controversial. Although it facilitates the development of the rules, oftentimes it leads to circumstances where:

Those points aren't issues on Apache, at least last time I checked, but they are issues on Nginx. Owing to it treats the request on this streaming fashion.

The too late to block is the factor that drives me to think towards a situation that ModSecurity should be warning the user that the rule may not be doing what the user hopes for, at least, not in the time that he expects. Together with the effort to support intermediate phases, this could give us a good ground for new features.

Version 2 has some counterpoints on when to execute the phase:1 via the --enable-request-early but I don't think it is related to that particular discussion.

airween commented 3 years ago

Another use case: when the variable is a collection name, eg. TX.

#
# -=[ Anomaly Mode: Overall Transaction Anomaly Score ]=-
#
SecRule TX:ANOMALY_SCORE "@ge %{tx.inbound_anomaly_score_threshold}" \
    "id:949110,\
    phase:2,\
    deny,\
    t:none,\
    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.0',\
    severity:'CRITICAL',\
    setvar:'tx.inbound_anomaly_score=%{tx.anomaly_score}'"

https://github.com/coreruleset/coreruleset/blob/af619744cbf25bca1d25c3bb27749951a4a4fb4f/rules/REQUEST-949-BLOCKING-EVALUATION.conf#L76-L91

I think this is justified, because the rule counts scores in the REQUEST phases, and it must to wait the end of these phases.

dune73 commented 3 years ago

@zimmerle: I think there is nothing wrong with giving the user a way to skip phases completely. It just should not be implicit and undocumented. If the option exists, it should be via a dedicated directive. I also like the idea of ModSecurity warning about rules not doing what people expect. The traditional phase:1 rule with ARGS_POST is silently ignored and that is very taxing on newbies. Personally, I would not mind a 500 in such a situation as the rule is simply broken, but that's a question of taste.

What is not clear to me following your response: How do you intend to handle this? With SecRequestBodyAccess off skipping phase:2, ModSec3 is effectively disabling almost the entire SLR and CRS rule sets.

zimmerle commented 3 years ago

justified, because the rule counts scores in the REQUEST phases, and it must to wait the end of these phases.

The last rule in a phase does not necessarily be the first rule of the subsequent phase. It could be the last in the current phase.

I. SecRule "..." "phase:1,..." 
II. SecRule "..." "phase:1,..." 
III. SecRule "..." "phase:1,actionB..." 

Order-wise this is equivalent -

I. SecRule "..." "phase:1,..." 
II. SecRule "..." "phase:1,..." 
III. SecRule "..." "phase:2,actionA..." 

Notice that in the former you are taking an action when the headers may be already delivered to the end application. In other words: actionB happens a phase before actionA.

zimmerle commented 3 years ago

Some facts were somewhat related to that issue -

The recommended configuration file, with the description of why we think it is quintessential to have Request Body Inspection On:

https://github.com/SpiderLabs/ModSecurity/blob/afefda53c69bb17e2ec16d24dd6fbc2c8fd7d063/modsecurity.conf-recommended#L12-L16

One that may be writing the rules is reading the logs that state - https://github.com/SpiderLabs/ModSecurity/blob/afefda53c69bb17e2ec16d24dd6fbc2c8fd7d063/src/transaction.cc#L897

The commit which makes the behavior different from v2: 379f37009598b39cf46645b68486d7fb70bacdd7

The issue that propelled the change in question #1531

Reverting 379f37009598b39cf46645b68486d7fb70bacdd7 will make the behavior works is a similar fashion of v2. Not yet recommended.

As a long term plan, we aim to remove those configurations. We could leave for the engine to fill the variables based on the utilization. If not used, there will be automatically disabled.

dune73 commented 3 years ago

I do not think you should remove configuration options. But that's for a long term discussion.

Near term: Will you revert 379f370 or how do you plan to fix this until the long term solution pans out?

dune73 commented 3 years ago

Any news on this front or a plan to share?

Infos from CRS: We merged a PR (-> 1941) that shifts all the CRS rules that can run in phase:1 into phase:1. This allows ModSecurity v3 users to mitigate this security vulnerability by running the development version of CRS (v3.4/dev) and edit the rule 949110 to run in phase 1. We are now preparing a minor release (likely 3.3.1) that will allow blocking in phase 1 as a configuration option.

martinhsv commented 3 years ago

Nothing substantial to report yet. This matter is currently under active discussion.

dune73 commented 3 years ago

Could we be part of the discussion, please? This issue affects our users, so we would like to chime in too. @zimmerle told us several times to report issues here on github so things could be discussed in public. If you discuss this behind closed doors now, this would be a contraction.

dune73 commented 3 years ago

Update from the OWASP ModSecurity Core Rule Set project:

https://github.com/coreruleset/coreruleset

With these two changes, we provide you with a workaround for this libModSecurity3 security issue that will let every attacker bypass your WAF when you have disabled request body access.

We plan to backport and release CRS 3.3.1 in the coming days. Please check https://coreruleset.org, the CRS mailinglist or back here for infos when this happened.

I have not heard any information about the Trustwave Spiderlabs ModSecurity rules (SLR). My estimation is that disabling request body access leads to a bypass of almost all the SLR rules. So a fix is due. In the meantime, try and enable request body access if you are affected from the vulnerability.

zimmerle commented 3 years ago

Sec[Request|Response]BodyAccess is no longer necessary. Back in the day, it was essential to save computational resources. With progress, ModSecurity managed to have the parser smart enough to figure with any variable that uses request|response body is in use; if so, turn on the processing automatically. :heart_eyes:

Considering how smart the parser is nowadays, it is natural to deprecate those outdated configuration flags. Moreover, mitigating the doubt on the semantic of the configuration. Namely: this issue, #1531, #1886, #2273, #2467, SpiderLabs/ModSecurity-nginx#124, 379f37009598b39cf46645b68486d7fb70bacdd7, #1643, 42a472adbda21e6ecc4711fd37d704cdb3d98fbb, SpiderLabs/ModSecurity-nginx#84, and SpiderLabs/ModSecurity-nginx#104.

One may argue in favor of having a configuration SecForce[Request|Response]BodyAccess Off. Particularly to address not-so-elegant rules that make unnecessary usage of variables that do not intend :upside_down_face:. Undoubtedly a fair point.

The phase will be processed as long as there is a rule to be addressed in that particular phase. Nonetheless, on the occasion of SecForce[Request|Response]BodyAccess development, we may want to raise this subject again.

The PoC with Sec[Request|Response]BodyAccess marked as deprecated is already implemented and under test here: ae128ad94d3e031178274f8262d3418f069e5370

As usual, this is open for appraisal. I will be delighted to discuss the technical matter.

airween commented 3 years ago

Back in the day, it was essential to save computational resources.

Do you think this isn't necessary in these days? Or why do you classify this as an argument?

ModSecurity managed to have the parser smart enough to figure with any variable that uses request|response body is in use; if so, turn on the processing automatically.

The point is here the automatically. I'm not sure this is a good idea (I mean to deprive users of the right to decide).

Considering how smart the parser is nowadays, it is natural to deprecate those outdated configuration flags.

Sorry, I don't share your opinion. It definitely isn't natural for most users (just see the mentioned issues in initial comment). These "flags" (like Sec[Request|Response]BodyAccess) allows to users to make more flexible the engine. I mean if these "flags" will disappear, and a user wants to check the performance of the built WAF (eg. turn off the body inspect), the only chance is to turn off the affected rules (which are on phase:2/phase4) - or am I wrong?

The PoC with Sec[Request|Response]BodyAccess marked as deprecated is already implemented and under test here: ae128ad

Okay, I see you've committed the modifications which marked as deprecated. The other part of this idea (automatically processing based on the used variables) is already done? Or is there any plan?

zimmerle commented 3 years ago

Back in the day, it was essential to save computational resources.

Do you think this isn't necessary in these days? Or why do you classify this as an argument?

I am afraid I did not paraphrase this. Maybe, however, disable SecRequestBodyAccess is not essential to many users.

ModSecurity managed to have the parser smart enough to figure with any variable that uses request|response body is in use; if so, turn on the processing automatically.

The point is here the automatically. I'm not sure this is a good idea (I mean to deprive users of the right to decide).

Perhaps I did not make myself clear. I am saying that the engine will enable such configuration as long as the user demands it.

Looking at the illustration below, because the user has used REQUEST_BODY, the engine recognizes that he/she wants to examine the request body; therefore, the engine enables the body processing.

Before the purposed change

SecRequestBodyAccess On
SecRule REQUEST_BODY "^(([a-z])+.)+[A-Z]([a-z])+$" "pass,msg:'OWASP CRS'"

After

SecRule REQUEST_BODY ".* ...." "pass ..."

Considering how smart the parser is nowadays, it is natural to deprecate those outdated configuration flags.

Sorry, I don't share your opinion. It definitely isn't natural for most users (just see the mentioned issues in initial comment). These "flags" (like Sec[Request|Response]BodyAccess) allows to users to make more flexible the engine. I mean if these "flags" will disappear, and a user wants to check the performance of the built WAF (eg. turn off the body inspect), the only chance is to turn off the affected rules (which are on phase:2/phase4) - or am I wrong?

I am sorry to say, but you are not right. There are other manners for not proceed with the inspection of the request body, for instance:

Straight from the modsecurity.conf-recommended file - https://github.com/SpiderLabs/ModSecurity/blob/f18595f42830f2f0ac27362a8b31120e3dfb850c/modsecurity.conf-recommended#L32-L46

Regardless, considering a smoother alternative, we have already suggested the existence of SecForce[Request|Response]BodyAccess Off.

For clearness, you may want to expatiate why the enable/disable of the request body weighs a performance test. What is the subject of such a test, performance of what?

The PoC with Sec[Request|Response]BodyAccess marked as deprecated is already implemented and under test here: ae128ad

Okay, I see you've committed the modifications which marked as deprecated. The other part of this idea (automatically processing based on the used variables) is already done? Or is there any plan?

I am not sure what is your understanding by done; The PoC is implemented and published in the link I have shared. I am sure there is space for embellishment and improvements in the code.

Scrutiny is always welcomed.

SandakovMM commented 3 years ago

Hello, @zimmerle I just want to check that I clearly understood how using of request body can be disabled after removing of Sec[Request/Responce]BodyAccess. Seems like there is a two way:


My humble opinion, if you interested (from user point of view, as I hope). Sometimes I want to disable all rules that process request body, but without big changes of pre-installed rules.

ModSecurity managed to have the parser smart enough to figure with any variable that uses request|response body is in use; if so, turn on the processing automatically.

Looking at the illustration below, because the user has used REQUEST_BODY, the engine recognizes that he/she wants to examine the request body; therefore, the engine enables the body processing.

I think this a great. But seems like mostly can be used by ruleset developers, because they decide use REQUEST_BODY or not. This is good to have ways to disable request/response body processing in my little custom part of modsecurity configuration. A usual user can install ruleset and add this small configuration file nearby.

You already provided them early. So this part mostly about why this question is shown up.

airween commented 3 years ago

Looking at the illustration below, because the user has used REQUEST_BODY, the engine recognizes that he/she wants to examine the request body; therefore, the engine enables the body processing. Before the purposed change ... After

I'm afraid we moved a little away from the original issue.

First, please help me to clarify your terminology. From your point of view, body processing == whole phase:2?

Then take a look to this rule:

SecRule REQUEST_URI|ARGS "\/assets\/file:\x2f\x2f" \
        "id:248260,msg:'...',phase:2,deny

This is a non-commercial rule from Comodo, especially for ModSecurity-nginx combo. There are tons of like this, also like in other commercial and/or non-commercial rule sets (I mean: mixed variables from phase:1/2, and rule triggered in phase:2).

Based on your example below, the new workflow will realize that the rule contains the ARGS, which derives from the REQUEST BODY, so the engine will process that without SecRequestBodyAccess on settings. It's a good idea, agree that.

But what can a user does if he/she wants to disable the processing of request body? Important: disable the processing of request body, not the whole phase:2!

Why users want to disable the processing of req body? Please read the mentioned issues:

I'm using ModSecurity with Nginx for proxying files as multipart/form-data. I don't want to process body content and save memory, so I set SecRequestBodyAccess to Off

In my configuration i use "SecRequestBodyAccess Off". This needed to make fastest checks and go further.

disable SecRequestBodyAccess is not essential to many users.

How do you know this? What about the users who wants to disable it?

Regardless, considering a smoother alternative, we have already suggested the existence of SecForce[Request|Response]BodyAccess Off.

Yes, I saw this, but could you help me to clarify, what's the difference between the new and old "flags"?

airween commented 3 years ago

Just one note - please take a look to this regression test:

No SecRequestBodyAccess directive regression test

As you can see, in the configuration section there isn't SecRequestBodyAccess - it's completely missing.

Now see the output (the expected result is 200, because the request body processing isn't enabled, and rule processed in phase:2).

[1609240212] [/] [9] Appending request body: 10 bytes. Limit set to: 0.000000
[1609240212] [/] [4] Starting phase REQUEST_BODY. (SecRules 2)
[1609240212] [/] [4] Adding request argument (POST): name "evil", value "evil
"
[1609240212] [/] [9] This phase consists of 1 rule(s).
[1609240212] [/] [4] (Rule: 1) Executing operator "Rx" with param "evil" against ARGS.
[1609240212] [/] [9] Target value: "evil\x0a" (Variable: ARGS:evil)
[1609240212] [/] [9] Matched vars updated.
[1609240212] [/] [4] Rule returned 1.
[1609240212] [/] [4] Running (disruptive)     action: deny.
[1609240212] [/] [8] Running action deny

Hmmm... this definitely looks like if the SecRequestBodyAccess directive is missing, the engine interprets it as On.

(You can change the variable by REQUEST_BODY, or any relevant var...)

I've checked this behavior on my Nginx instance, with same result.

(Could you check and confirm that libmodsecurity3 has a default value with on for SecRequestBodyAccess directive?)

I don't know what's the expected behavior, the mod_security2 follows the opposite way: if the variable is not set explicit as On, then the body processing isn't enabled (also checked on a live instance).

But if this is the libmodsecurity3 expected behavior, then I don't see the point why you want to remove the directive in the next versions, and why do you wants to add a new one with same behavior.

dune73 commented 3 years ago

@zimmerle I get the feeling the proposed change / solution for this regression is trying to do things in an intransparent way, kind of outsmarting the user. That usually leads to a disruption of existing use cases.

I prefer an engine to have an explicit way to configure it. Even more an engine that has ambiguous variables like ARGS that can be stuffed in phase 1 but also in phase 2.

Under the line I do not see much benefit in the proposed change, but new problems.

The directives SecRequestBodyAccess and SecResponseBodyAccess are useful the way they are. They are used in niche use cases obviously. But they also come in handy in more complex debugging situations. Removing them makes ModSecurity less useful. Replacing them with Force... options could be a workaround for problems that the proposed change introduces.

zimmerle commented 3 years ago

@SandakovMM

I just want to check that I clearly understood how using of request body can be disabled after removing of Sec[Request/Responce]BodyAccess. Seems like there is a two way:

  • Use SecForce[Request|Response]BodyAccess just like Sec[Request/Responce]BodyAccess was used before. But I need to be ready that this going to disable full phase 2, 4.
  • Use construction with SecRequestBodyLimit and SecRequestBodyLimitAction like:
SecRequestBodyLimit 0
SecRequestBodyLimitAction ProcessPartial

Does this normal way to use it? As far as I understand this construction just disable processing of any rule that checks request body. But other rules on phase 2 going to be works fine?

SecRequestBodyLimit allows ModSecurity to verify the request body size. If the size is above a threshold, SecRequestBodyLimitAction will be taken. I don't recommend SecRequestBodyLimit as a replacement for SecRequestBodyAccess.

The behavior of SecForce[Request|Response]BodyAccess is a discussion to be held be on the occasion of its development, as mentioned here: [1].

My humble opinion, if you interested (from user point of view, as I hope). Sometimes I want to disable all rules that process request body, but without big changes of pre-installed rules.

Your opinion really matters. I would like to understand why the proposed SecForce[Request|Response]BodyAccess does not address that behavior.

I think this a great. But seems like mostly can be used by ruleset developers, because they decide use REQUEST_BODY or not. This is good to have ways to disable request/response body processing in my little custom part of modsecurity configuration. A usual user can install ruleset and add this small configuration file nearby.

You already provided them early. So this part mostly about why this question is shown up.

REQUEST_BODY was a merely example of a variable that makes usage of the request body. Together with REQUEST_BODY, we have others variables that depends on the request body such as:

All those variable depends on the request body to have its value filled. If any of those variables are in use, then request body inspection comes naturally enabled. Otherwise, disable by SecForceRequestBodyAccess Off.

In practice, we are not removing functionality but adding the capability of not processing the request body if it is not in use by a rule; That wasn't possible before that proposal. That change is good for usability and performance.

zimmerle commented 3 years ago

@airween

Based on your example below, the new workflow will realize that the rule contains the ARGS, which derives from the REQUEST BODY, so the engine will process that without SecRequestBodyAccess on settings. It's a good idea, agree that.

In essence, this may be related to the use case of the user who loaded a set of rules and later decides to disable those rules due to having SecRequestBodyAccess to Off. I raise that use case scenario here: [1]. To address that niche use, I also have suggested the existence of SecForceRequestBodyAccess. Did you had considered using SecForceRequestBodyAccess in such a case?

Performance-wise I would recommend you have a separate file for the rules that depends on the request body; only load this file whenever you have the intention to use it, as oppose to load and disable.

airween commented 3 years ago

Did you had considered using SecForceRequestBodyAccess in such a case?

Actually (as I wrote in my next comment, the SecRequestBodyAccess is default On, if there isn't present in config file) I don't see the difference between the suggested SecForceRequestBodyAccess and the current one.

zimmerle commented 3 years ago

@dune73

The directives SecRequestBodyAccess and SecResponseBodyAccess are useful the way they are. They are used in niche use cases obviously. But they also come in handy in more complex debugging situations. Removing them makes ModSecurity less useful. Replacing them with Force... options could be a workaround for problems that the proposed change introduces.

I prefer to stick with the technical facts and concrete examples; this proposal suggests configuration labels/semantic a bit more consistent for the end-user. Let's exemplify using use case scenarios -

Before this proposal (The use case A)

Request Body Processed
SecRequestBodyAccess On
SecRule REQUEST_BODY ".*" "..."
Request Body Processed
SecRequestBodyAcess On
SecRule RESPONSE_HEADERS ".*" "..."
Request Body Processed (or not, up to the branch in question. see [3])
SecRule RESPONSE_HEADERS ".*" "..."
Request Body NOT Processed
SecRequestBodyAccess Off
SecRule REQUEST_BODY ".*" "..."

After this proposal (The use case B)

Request Body Processed
SecRule REQUEST_BODY ".*" "..."
Request Body NOT Processed
SecRule RESPONSE_HEADERS ".*" "..."
Request Body NOT Processed
SecForceRequestBodyAccess Off (or SecDisableRequestBody On)
SecRule REQUEST_BODY ".*" "..."

Perhaps the example would help to show the benefit clearly.

There were some concerns about possible limitations introduced by the deliberation of the use case B made at [2], specifically on explicit-ability, debugging limitations and possible new issues.

@dune73, Do you mind describing a bit why do you think those will be an issue? Even better if you could illustrate via examples.

zimmerle commented 3 years ago

Did you had considered using SecForceRequestBodyAccess in such a case?

Actually (as I wrote in my next comment, the SecRequestBodyAccess is default On, if there isn't present in config file) I don't see the difference between the suggested SecForceRequestBodyAccess and the current one.

I am afraid that this is not accurate. You may want to have a look at the illustration on [4], specifically on the Item 2 of the use case B.

airween commented 3 years ago

I am afraid that this is not accurate.

First I just want to clear the SecRequestBodyAccess. The behavior of this variable is totally different than SecResponseBodyAccess.

Have you checked my regression test?

Can you confirm that if SecRequestBodyAccess isn't in the config, the engine assumes it's On?

martinhsv commented 3 years ago

Just to clarify only the last question ...

In the case where SecRequestBodyAccess has not been specified at all in the configuration files, (and ctl:requestBodyAccess has not been used):

In v2.9.3 this is the same as if one had specified 'SecRequestBodyAccess Off'.

In v3 this is the same as if one had specified 'SecRequestBodyAccess On'

airween commented 3 years ago

In v3 this is the same as if one had specified 'SecRequestBodyAccess On'

That's what I wrote above.

And therefore IMHO there isn't any difference between the two scenarios (except the case with RESPONSE_HEADERS variable, which is clear).

zimmerle commented 3 years ago

From the user's perspective, the request body processing is always on; Once a variable that depends on the request body is used, the request body process will be available, therefore On. This proposal plays a difference when the request body is not used—in such a case, having the request body inspection always-on will not optimally use resources.

As pointed by @martinhsv, even our default configuration file lean on variables that are somewhat dependent on the request body -

https://github.com/SpiderLabs/ModSecurity/blob/f18595f42830f2f0ac27362a8b31120e3dfb850c/modsecurity.conf-recommended#L53-L54

The benefit of this proposal is more relevant in the response body. In my personal experience, response body inspection is less popular than the request body; thus, this proposal's advantage is more evident.

Users who are wont to turn On manually the request body may wonders if the engine is working correctly. In that sense, debugging will try to address the following questions -

  1. I am using a request body dependent variable, is my request body marked to be processed?
  2. I think I am not using anything that depends on the request body, is my request body processing disabled?

The answer to question 1. will always be yes. If a variable that depends on the request body were explicit on a rule (even as part of a setvar), the request body would be processed by ModSecurity.

An answer to question 2. is not so straightforward. Except for manually review the rules, there is no automatic way to understand if the request body is On.

To address question 2., I have an addendum to the proposal https://github.com/SpiderLabs/ModSecurity/issues/2465#issuecomment-750693231 -

Please, provide use cases for debate.

airween commented 3 years ago

I'm afraid we still don't understand each other.

You are constantly talking about the _requestbody processing, but the issue is not that. As I wrote the name of this issue: SecRequestBodyAccess off skips the phase:2 rules - the problem is this. The SecRequestBodyAccess off turns off the whole 2nd phase. Not just the access of the variables, but the whole phase.

I asked this here:

From your point of view, body processing == whole phase:2?

but I still haven't got any answer.

Please, provide use cases for debate.

There are so many cases in the comments, but once again:

SecRule REQUEST_URI|ARGS "\/assets\/file:\x2f\x2f" \
        "id:248260,msg:'...',phase:2,deny

In this rule the first variable available in phase:1 (REQUEST_URI) and phase:2 (ARGS), but the rule writer wants to check in same time, in 2nd phase.

SecRule TX:ANOMALY_SCORE "@ge %{tx.inbound_anomaly_score_threshold}" \
    "id:949110,\
    phase:2,\
    deny,\
    setvar:'tx.inbound_anomaly_score=%{tx.anomaly_score}'"

In this rule the variable doesn't depend directly on request but constantly counted, based on many variables.

libmodsecurity3 now skips the whole phase:2, which means it skips the processing of these rules above. That's the problem, not the visibility/availability of variables.

Or what do you think, what's the expected behavior in case of these rules? Engine should skip them, or not?

dune73 commented 3 years ago

I'm a bit busy at the moment not the least because I am working on CRS in order to mitigate this problem (see above).

But here is a use case.

I'm looking at a random rule from Trustwave's Spiderlab rules. I've picked 2028041. It's a rule in phase:2 that inspects a request to detect a cPanel XSS vulnerability. The rule refers to http://osvdb.org/show/osvdb/28041 for documentation, but this results in a 404. However, when you take the clues the rule provides you can find the following page explaining this problem: https://vulners.com/osvdb/OSVDB:28041 (Hint: Updating SLR to abandon osvdb.org in favor of an active documentation site would be useful for SLR users, I think.)

The doc explains this is essentially an XSS exploit via the query string parameter "dir" for a specific cPanel path. So the rule could run in phase 1, but Trustwave Spiderlabs has decided to configure this rule to run in phase 2. But the rule still uses the general argument ARGS instead of the query-string-specific ARGS_GET. So from looking at the rule, you do not really know if this has to be in phase 2, or if it could also be in phase 1.

Given the problem with libModSecurity3 discussed in this issue, disabling request body access leads to skipping phase 2 completely. So when you run the commercial Spiderlab rule set on libModSecurity3 and you disable the request body access for performance reasons, you also lose protection from XSS in query strings and that is not welcome and also very intransparent.

This means that libModSecurity3 is actively putting commercial Trustwave Spiderlabs customers in danger and I think this ought to be fixed. Either by updating SLR ASAP and shifting all rules that can run in phase 1 from phase 2 into phase 1. It's a lot of rules, I know, but unit testing should help with the task. OR you need to fix libModSecurity3 to support this SLR use case again.

For the record: SLR operates almost entirely in phase 2. If a setup runs on libModSecurity3 without request body access, SLR becomes useless.

martinhsv commented 3 years ago

To clarify:

The proposed path forward does not include continuing to skip a phase for which rules exist in the rule set. Going forward, if there are phase:2 rules, phase:2 will not be skipped.

dune73 commented 3 years ago

Thank you @martinhsv. That clarification is dearly welcome. Things and the path forward may look clear for you developers, but for us it's more of an Enigma.

Can you share a roadmap when you will be implementing / releasing the fix that will no longer skip a phase with existing rules?

airween commented 3 years ago

To clarify:

Thanks! Now there is only one thing left: clarify the fate of variable SecRequestBodyAccess (or SecForceRequestBodyAccess).

I still don't see the difference between the old and the new variable - see this table:

Value SecRequestBody SecForceReqiestBody
not set Allow access to req. variables Allow access to req. variables
On Allow access to req. variables Allow access to req. variables
Off Deny access to req. variables Deny access to req. variables

May be I forgot something (then please correct me), but looks like the behaviors of these variables are same (except that now the SecRequestBodyAcces skips the whole phase:2 - but I don't think it's a variable depend behavior).

So I don't see the reason to remove the SecRequestBodyAccess and create a new one with same effect.

martinhsv commented 3 years ago

Hi @airween ,

I'll try to reiterate and rephrase what @zimmerle has described above as it pertains to your latest inqury ...

On the surface it may look like SecRequestBodyAccess is being replaced with identical functionality, merely under a different name (e.g. 'SecForceRequestBodyAccess Off', or 'SecDisableRequestBody On'). However, there are a couple of differences:

1) There is a slight nuance to 'not set'

Under the current proposal, the internal switch to 'access request body' has an initial state of false. It then gets set to true if any of the rules in the rule set use any variables that may be populated by the request body.

So, when you say of the configuration item 'not set' == 'Allow access to req. variables', you are correct in that merely having a request variable present itself triggers the request body processing.

In practice, almost all rule sets will trigger this 'access_request_body == true' state -- even if the only request-body-populated-variables present are some of the basic ones included in modsecurity.conf-recommended (e.g. REQBODY_ERROR, ...)

Is there an advantage to this, as opposed to simply defining that the initial 'access request body' state is always true?

Perhaps very little advantage if the request body were the only consideration.

However, this same approach is being proposed for the response body, and here the advantages are more tangible.

First, it is expected to be a more common ModSecurity deployment to ignore the response body content than to ignore the request body. Second, it is a more foreseeable scenario that someone might indeed have no response-body-dependent variables in their rule set -- in which case they could benefit automatically without having to set a separate configuration item to 'ignore response body'.

If we accept that this approach offers some value at least for response bodies, then there is some advantage to taking a common approach for both cases (request bodies and response bodies).

2) A proposed replacement for SecRequestBodyAccess (and the Response equivalent) may only need to turn body access 'off'.

There may still be value in being able force this setting to be 'off'.

For one thing, with even a small-ish set of rules, it could be nuisance to comb through one's rules to identify that last, overlooked rule that is still, inadvertently using a variable populated by body content. Granted, one could achieve much the same effect with the BodyLimit configuration items, but it was felt that a simpler mechanism to simply turn off body processing might be seen as helpful to users.

However, given how (1) above describes how we deduce whether body access should be 'on', there may not be much of a case for forcing body access to be 'on'. If that assumption is correct, then not being able to force 'on' would be a notable difference compared to what the pre-existing config items support.


Should we retain the SecRequestBodyAccess and SecResponseBodyAccess names?

Given (1) and (2) above, the semantics of the control are slightly (but perhaps sufficiently) different to warrant configuration items with new names.

Note that if we do proceed with only allowing body processing to be forced 'off', then depending upon the name chosen, there may be no need for a parameter to be associated with the configuration item name (e.g. 'SecDisableRequestBody' would completely define what was intended).

It's really about trying to make the settings easier to understand for the long term. Retaining the old names might risk creating as much confusion as we seek to alleviate.

As always, feedback is welcome. If providing use cases that you think might not be well supported under this proposal, please provide as much of a specific description as possible.

defanator commented 3 years ago
  • We have introduced a new configuration option "Early Blocking" that allows you to block at the end of phase 1. See crs-setup.conf. (Again for the 3.4/dev branch)

Hi @dune73, gentlemen,

I took a chance to perform a quick testing of CRS v3.3.1-rc1 with the tx.blocking_early option, and noticed some weird behaviour with current libmodsecurity (v3/master as of today) and nginx connector (master as of today), check the 4 cases below:

a) SecRequestBodyAccess Off + tx.blocking_early=0:

vagrant@vagrant:/etc/nginx/modsec/owasp-crs/rules$ curl -H "User-Agent: Mozilla/5.00 (Nikto/2.1.5)" -vi 'http://localhost/modsec-full/ncl_items.shtml?SUBJECT=1'
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1
> Host: localhost
> Accept: */*
> User-Agent: Mozilla/5.00 (Nikto/2.1.5)
> 
< HTTP/1.1 200 OK
HTTP/1.1 200 OK
< Server: nginx/1.19.6
Server: nginx/1.19.6
< Date: Tue, 12 Jan 2021 15:18:53 GMT
Date: Tue, 12 Jan 2021 15:18:53 GMT
< Content-Type: text/plain
Content-Type: text/plain
< Content-Length: 64
Content-Length: 64
< Connection: keep-alive
Connection: keep-alive

< 
Thank you for requesting /modsec-full/ncl_items.shtml?SUBJECT=1
* Connection #0 to host localhost left intact

b) SecRequestBodyAccess Off + tx.blocking_early=1:
vagrant@vagrant:/etc/nginx/modsec/owasp-crs/rules$ curl -H "User-Agent: Mozilla/5.00 (Nikto/2.1.5)" -vi 'http://localhost/modsec-full/ncl_items.shtml?SUBJECT=1'
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1
> Host: localhost
> Accept: */*
> User-Agent: Mozilla/5.00 (Nikto/2.1.5)
> 
<html>
<head><title>403 Forbidden</title></head>
<body>
<center><h1>403 Forbidden</h1></center>
<hr><center>nginx/1.19.6</center>
</body>
</html>
* Connection #0 to host localhost left intact

c) SecRequestBodyAccess On + tx.blocking_early=0:
vagrant@vagrant:/etc/nginx/modsec/owasp-crs/rules$ curl -H "User-Agent: Mozilla/5.00 (Nikto/2.1.5)" -vi 'http://localhost/modsec-full/ncl_items.shtml?SUBJECT=1'
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1
> Host: localhost
> Accept: */*
> User-Agent: Mozilla/5.00 (Nikto/2.1.5)
> 
< HTTP/1.1 403 Forbidden
HTTP/1.1 403 Forbidden
< Server: nginx/1.19.6
Server: nginx/1.19.6
< Date: Tue, 12 Jan 2021 15:22:39 GMT
Date: Tue, 12 Jan 2021 15:22:39 GMT
< Content-Type: text/html
Content-Type: text/html
< Content-Length: 153
Content-Length: 153
< Connection: keep-alive
Connection: keep-alive

< 
<html>
<head><title>403 Forbidden</title></head>
<body>
<center><h1>403 Forbidden</h1></center>
<hr><center>nginx/1.19.6</center>
</body>
</html>
* Connection #0 to host localhost left intact

d) SecRequestBodyAccess On + tx.blocking_early=1:
vagrant@vagrant:/etc/nginx/modsec/owasp-crs/rules$ curl -H "User-Agent: Mozilla/5.00 (Nikto/2.1.5)" -vi 'http://localhost/modsec-full/ncl_items.shtml?SUBJECT=1'
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1
> Host: localhost
> Accept: */*
> User-Agent: Mozilla/5.00 (Nikto/2.1.5)
> 
<html>
<head><title>403 Forbidden</title></head>
<body>
<center><h1>403 Forbidden</h1></center>
<hr><center>nginx/1.19.6</center>
</body>
</html>
* Connection #0 to host localhost left intact

The weird thing is that HTTP response is completely broken when tx.blocking_early=1 (no matter how SecRequestBodyAccess is configured) - there's no HTTP response header at all.

(I may have missed something from the entire discussion here - sorry if I did - just wanted to bring the above to your attention. Cheers!)

dune73 commented 3 years ago

Hey @defanator, thank you for trying this out for us. The behavior is indeed quite unexpected - and very much not desired.

We could reproduce your problem, but only with an outdated modsec/nginx connector. You write you are running with the latest master. So given our own research, this should not happen in your setup.

So could you please confirm, the problem is persistent with latest master ModSec and latest master ModSec->Nginx connector?

How about the latest official releases of ModSec and ModSec->Nginx connector.

defanator commented 3 years ago

@dune73 the issue can be 100% reproduced with the following versions of libmodsecurity && nginx connector module:

test@vagrant:/home/test/ModSecurity$ git describe
v3.0.4-96-g310cbf89
test@vagrant:/home/test/ModSecurity-nginx$ git describe
v1.0.1-14-g3dbe4da

CRS v3.3.1-rc1:

root@vagrant:/etc/nginx/modsec/owasp-crs# git checkout v3.3.1-rc1
HEAD is now at f2d4136 update version strings for 3.3.1
root@vagrant:/etc/nginx/modsec/owasp-crs# git describe
2.2.7-1991-gf2d4136

diff for CRS:

root@vagrant:/etc/nginx/modsec/owasp-crs# git diff
diff --git a/crs-setup.conf.example b/crs-setup.conf.example
index 5094789..57bab2c 100644
--- a/crs-setup.conf.example
+++ b/crs-setup.conf.example
@@ -338,13 +338,13 @@ SecDefaultAction "phase:2,log,auditlog,pass"
 # does not get evaluated if the request is being blocked early. So when you
 # disabled blocking early again at some point in the future, then new alerts
 # from phase 2 might pop up.
-#SecAction \
-#  "id:900120,\
-#  phase:1,\
-#  nolog,\
-#  pass,\
-#  t:none,\
-#  setvar:tx.blocking_early=1"
+SecAction \
+  "id:900120,\
+  phase:1,\
+  nolog,\
+  pass,\
+  t:none,\
+  setvar:tx.blocking_early=1"

 # -- [[ Application Specific Rule Exclusions ]] ----------------------------------------

I haven't checked with libmodsecurity 3.0.4 and nginx connector 1.0.1 yet.

dune73 commented 3 years ago

Thank you very much @defanator. This helps a lot.

If you could check 3.0.4 and 1.0.1 too, that would be neat.

For the record: We are investigating this issue and a 2nd unexpected ModSec v3 misbehavior that CRS 3.3.1-RC1 triggers.

airween commented 3 years ago

hi @defanator,

@dune73 the issue can be 100% reproduced with the following versions of libmodsecurity && nginx connector module:

here are the versions what I'm using:

airween@debian-sid:/usr/local/src/DEBIAN/Modsecurity$ git describe
v3.0.4-96-g310cbf89
airween@debian-sid:/usr/local/src/DEBIAN/ModSecurity-nginx $ git describe
v1.0.1-12-g22e53ab

Note, that I cloned the repository about 8 days ago, but looks like there isn't any relevant modification in that two commits.

As you can see in the name of directory path, I'm using Debian, and made packages from sources. I use Debian's Nginx package, which is 1.18 is SID.

I installed these packages to an another machine where I test Coreruleset and ModSec, there is a configured CRS:

$ git branch | grep ^\*
* v3.3.1/rc1
$ git describe
2.2.7-1991-gf2d4136

this is the only difference I found against your config (only relevant lines):

$ diff crs-setup.conf.example /etc/modsecurity/crs/crs-setup.conf
311,318c311,318
< #SecAction \
< # "id:900110,\
< #  phase:1,\
< #  nolog,\
< #  pass,\
< #  t:none,\
< #  setvar:tx.inbound_anomaly_score_threshold=5,\
< #  setvar:tx.outbound_anomaly_score_threshold=4"
---
> SecAction \
>  "id:900110,\
>   phase:1,\
>   nolog,\
>   pass,\
>   t:none,\
>   setvar:tx.inbound_anomaly_score_threshold=5,\
>   setvar:tx.outbound_anomaly_score_threshold=4"

336,348c335,345
< # Please note that blocking early will hide potential alerts from you. This
< # means that a payload that would appear in an alert in phase 2 (or phase 4)
< # does not get evaluated if the request is being blocked early. So when you
< # disabled blocking early again at some point in the future, then new alerts
< # from phase 2 might pop up.
< #SecAction \
< #  "id:900120,\
< #  phase:1,\
< #  nolog,\
< #  pass,\
< #  t:none,\
< #  setvar:tx.blocking_early=1"
< 
---
> # Please note that blocking early will hide potential alerts from you. This means
> # that payload that would appear in an alert in phase 2 (or phase 4) do not get 
> # evaluated if the request is being blocked early. So when you disabled
> # blocking early again, then new alerts from phase 2 might pop up.
> SecAction \
>   "id:900120,\
>   phase:1,\
>   nolog,\
>   pass,\
>   t:none,\
>   setvar:tx.blocking_early=1"

Looks like tx.inbound_anomaly_score_threshold and tx.outbound_anomaly_score_threshold settings are missing from your setup. Could you check the CRS again with SecAction 900110? You can decrease the tx.inbound_anomaly_score_threshold to 2, but it worked for me with 5.

Update

I've checked without tx.inbound_anomaly_score_threshold and tx.outbound_anomaly_score_threshold, as you're using, but it still works, and I can't still reproduce the issue.

$ curl -H "User-Agent: nikto" -vvv 'http://localhost:8080/'
*   Trying ::1:8080...
* Connected to localhost (::1) port 8080 (#0)
> GET / HTTP/1.1
> Host: localhost:8080
> Accept: */*
> User-Agent: nikto
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 403 Forbidden
< Server: nginx/1.18.0
< Date: Wed, 20 Jan 2021 08:01:09 GMT
< Content-Type: text/html; charset=utf8
< Content-Length: 153
< Connection: keep-alive
< 
<html>
<head><title>403 Forbidden</title></head>
<body>
<center><h1>403 Forbidden</h1></center>
<hr><center>nginx/1.18.0</center>
</body>
</html>
* Connection #0 to host localhost left intact

In the error log I got:

2021/01/20 08:01:04 [notice] 624456#624456: ModSecurity-nginx v1.0.1 (rules loaded inline/local/remote: 0/944/0)
2021/01/20 08:01:05 [notice] 624457#624457: ModSecurity-nginx v1.0.1 (rules loaded inline/local/remote: 0/944/0)
2021/01/20 08:01:09 [info] 624459#624459: *1 ModSecurity: Warning. Matched "Operator `PmFromFile' with parameter `scanners-user-agents.data' against variable `REQUEST_HEADERS:User-Agent' (Value: `nikto' ) [file "/usr/share/modsecurity-crs/rules/REQUEST-913-SCANNER-DETECTION.conf"] [line "33"] [id "913100"] [rev ""] [msg "Found User-Agent associated with security scanner"] [data "Matched Data: nikto found within REQUEST_HEADERS:User-Agent: nikto"] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-reputation-scanner"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "capec/1000/118/224/541/310"] [tag "PCI/6.5.10"] [hostname "::1"] [uri "/"] [unique_id "1611129669"] [ref "o0,5v60,5t:lowercase"], client: ::1, server: _, request: "GET / HTTP/1.1", host: "localhost:8080"
2021/01/20 08:01:09 [error] 624459#624459: *1 [client ::1] ModSecurity: Access denied with code 403 (phase 1). Matched "Operator `Ge' with parameter `5' against variable `TX:ANOMALY_SCORE' (Value: `5' ) [file "/usr/share/modsecurity-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "154"] [id "949111"] [rev ""] [msg "Inbound Anomaly Score Exceeded in phase 1 (Total Score: 5)"] [data ""] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-generic"] [hostname "::1"] [uri "/"] [unique_id "1611129669"] [ref ""], client: ::1, server: _, request: "GET / HTTP/1.1", host: "localhost:8080"
2021/01/20 08:01:09 [error] 624459#624459: *1 [client ::1] ModSecurity: Access denied with code 403 (phase 3). Matched "Operator `Ge' with parameter `4' against variable `TX:OUTBOUND_ANOMALY_SCORE' (Value: `5' ) [file "/usr/share/modsecurity-crs/rules/RESPONSE-959-BLOCKING-EVALUATION.conf"] [line "138"] [id "959101"] [rev ""] [msg "Outbound Anomaly Score Exceeded in phase 3 (Total Score: 5)"] [data ""] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-generic"] [hostname "::1"] [uri "/"] [unique_id "1611129669"] [ref ""], client: ::1, server: _, request: "GET / HTTP/1.1", host: "localhost:8080"
2021/01/20 08:01:09 [info] 624459#624459: *1 client ::1 closed keepalive connection

It's really interesting that there are two lines with message Access denied with code 403 - first in phase:1, second in phase:3.

I assume this can cause this behavior - but I don't know the exact reason: looks like the engine blocks the request in phase:1 (action deny in rule), but it continues the processing of transaction, and later also blocks the request in phase:3 (also by a deny action).

Can you share your error.log?

defanator commented 3 years ago

@airween here's the error log:

2021/01/20 12:16:40 [info] 5873#5873: *1 ModSecurity: Warning. Matched "Operator `PmFromFile' with parameter `scanners-user-agents.data' against variable `REQUEST_HEADERS:User-Agent' (Value: `Mozilla/5.00 (Nikto/2.1.5)' ) [file "/etc/nginx/modsec/owasp-crs/rules/REQUEST-913-SCANNER-DETECTION.conf"] [line "33"] [id "913100"] [rev ""] [msg "Found User-Agent associated with security scanner"] [data "Matched Data: nikto found within REQUEST_HEADERS:User-Agent: mozilla/5.00 (nikto/2.1.5)"] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-reputation-scanner"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "capec/1000/118/224/541/310"] [tag "PCI/6.5.10"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "1611145000"] [ref "o14,5v92,26t:lowercase"], client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"
2021/01/20 12:16:40 [error] 5873#5873: *1 [client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 1). Matched "Operator `Ge' with parameter `5' against variable `TX:ANOMALY_SCORE' (Value: `5' ) [file "/etc/nginx/modsec/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "154"] [id "949111"] [rev ""] [msg "Inbound Anomaly Score Exceeded in phase 1 (Total Score: 5)"] [data ""] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-generic"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "1611145000"] [ref ""], client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"
2021/01/20 12:16:40 [error] 5873#5873: *1 [client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 3). Matched "Operator `Ge' with parameter `4' against variable `TX:OUTBOUND_ANOMALY_SCORE' (Value: `5' ) [file "/etc/nginx/modsec/owasp-crs/rules/RESPONSE-959-BLOCKING-EVALUATION.conf"] [line "138"] [id "959101"] [rev ""] [msg "Outbound Anomaly Score Exceeded in phase 3 (Total Score: 5)"] [data ""] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-generic"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "1611145000"] [ref ""], client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"

I was about to collect debug log as well, but nginx fails to start with debug version of the connector module with my current configuration, producing segfault. Will share additional details a bit later.

BTW, I'm using reproducible environment from https://github.com/defanator/modsecurity-performance/ for tests. You can adjust CRS version in https://github.com/defanator/modsecurity-performance/blob/master/pillars/versions.sls to v3.3.1-rc1 before launching vagrant vm, apply the mentioned patch for crs-setup.conf, and reproduce it with the following request:

test@vagrant:/etc/nginx/modsec/owasp-crs$ curl -H "User-Agent: Mozilla/5.00 (Nikto/2.1.5)" -vi 'http://localhost/modsec-full/ncl_items.shtml?SUBJECT=1'
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1
> Host: localhost
> Accept: */*
> User-Agent: Mozilla/5.00 (Nikto/2.1.5)
> 
<html>
<head><title>403 Forbidden</title></head>
<body>
<center><h1>403 Forbidden</h1></center>
<hr><center>nginx/1.19.6</center>
</body>
</html>
* Connection #0 to host localhost left intact
defanator commented 3 years ago

Backtrace from coredump obtained after running nginx-debug -t:

root@vagrant:/var/log/nginx# gdb /usr/sbin/nginx-debug /tmp/nginx-debug.9821.core
GNU gdb (Ubuntu 8.1.1-0ubuntu1) 8.1.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/sbin/nginx-debug...Reading symbols from /usr/lib/debug/.build-id/d3/26e2fe9866603a35837fb2a687444fd5f05250.debug...done.
done.
[New LWP 9821]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
bt Core was generated by `nginx-debug -t'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string (__str=..., this=0x7ffc9c60eb30) at /usr/include/c++/7/bits/basic_string.h:440
440       { _M_construct(__str._M_data(), __str._M_data() + __str.length()); }
(gdb) bt full
#0  std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string (__str=<error reading variable: Cannot access memory at address 0x8>, 
    this=0x7ffc9c60eb30) at /usr/include/c++/7/bits/basic_string.h:440
No locals.
#1  std::operator+<char, std::char_traits<char>, std::allocator<char> > (__rhs=0x7fa998d2fabd ":", __lhs=<error reading variable: Cannot access memory at address 0x8>, 
    this=<optimized out>) at /usr/include/c++/7/bits/basic_string.h:5928
        __str = <optimized out>
        __str = <optimized out>
#2  modsecurity::Rule::getReference[abi:cxx11]() (this=<optimized out>) at ../headers/modsecurity/rule.h:93
No locals.
#3  0x00007fa998c8475e in modsecurity::Rules::dump (this=<optimized out>) at ../headers/modsecurity/rules.h:45
        j = 0
#4  modsecurity::RulesSetPhases::dump (this=<optimized out>) at rules_set_phases.cc:74
        i = 1
#5  0x00007fa998c8063c in modsecurity::RulesSet::dump (this=<optimized out>) at rules_set.cc:260
No locals.
#6  0x00007fa998c80645 in modsecurity::msc_rules_dump (rules=<optimized out>) at rules_set.cc:270
No locals.
#7  0x00007fa998fa2c7d in ngx_http_modsecurity_merge_conf (cf=<optimized out>, parent=0x55ab89eeb9c8, child=0x55ab89efb7b8)
    at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c:722
        p = 0x55ab89eeb9c8
        c = 0x55ab89efb7b8
        clcf = <optimized out>
        rules = <optimized out>
        error = 0x0
        __func__ = "ngx_http_modsecurity_merge_conf"
#8  0x000055ab88a53324 in ngx_http_merge_locations (cf=cf@entry=0x7ffc9c60f110, locations=0x55ab89e7e168, loc_conf=<optimized out>, 
    module=module@entry=0x7fa9991a8100 <ngx_http_modsecurity_ctx>, ctx_index=ctx_index@entry=48) at src/http/ngx_http.c:648
        rv = <optimized out>
        q = 0x55ab89e7e398
        ctx = 0x55ab89e7bc78
        saved = {main_conf = 0x55ab89e7bc90, srv_conf = 0x55ab89ee8f30, loc_conf = 0x55ab89ee9118}
        clcf = 0x55ab89efa080
        lq = 0x55ab89e7e398
#9  0x000055ab88a5417e in ngx_http_merge_servers (cmcf=0x55ab89e7c248, cmcf=0x55ab89e7c248, ctx_index=48, module=0x7fa9991a8100 <ngx_http_modsecurity_ctx>, cf=0x7ffc9c60f110)
    at src/http/ngx_http.c:605
        rv = <optimized out>
        s = 1
        ctx = 0x55ab89e7bc78
        saved = {main_conf = 0x55ab89e7bc90, srv_conf = 0x55ab89e7be78, loc_conf = 0x55ab89e7c060}
        clcf = <optimized out>
        cscfp = <optimized out>
        rv = <optimized out>
        s = <optimized out>
        ctx = <optimized out>
        saved = <optimized out>
        clcf = <optimized out>
        cscfp = <optimized out>
#10 ngx_http_block (cf=0x7ffc9c60f110, cmd=<optimized out>, conf=<optimized out>) at src/http/ngx_http.c:268
---Type <return> to continue, or q <return> to quit---
        rv = <optimized out>
        m = <optimized out>
        module = 0x7fa9991a8100 <ngx_http_modsecurity_ctx>
        ctx = 0x55ab89e7bc78
        cmcf = 0x55ab89e7c248
        mi = 48
        s = <optimized out>
        pcf = {name = 0x0, args = 0x55ab89e7afa8, cycle = <optimized out>, pool = 0x55ab89e78c90, temp_pool = <optimized out>, conf_file = <optimized out>, log = <optimized out>, 
          ctx = <optimized out>, module_type = <optimized out>, cmd_type = <optimized out>, handler = <optimized out>, handler_conf = <optimized out>}
        clcf = <optimized out>
        cscfp = 0x55ab89e7c4e8
        cmd = <optimized out>
        cf = <optimized out>
        rv = <optimized out>
        m = <optimized out>
        module = <optimized out>
        ctx = <optimized out>
        cmcf = <optimized out>
        conf = <optimized out>
        mi = <optimized out>
        s = <optimized out>
        pcf = <optimized out>
        clcf = <optimized out>
        cscfp = <optimized out>
        rv = <optimized out>
        mi = <optimized out>
        m = <optimized out>
        s = <optimized out>
        pcf = <optimized out>
        module = <optimized out>
        ctx = <optimized out>
        clcf = <optimized out>
        cscfp = <optimized out>
        cmcf = <optimized out>
#11 0x000055ab88a2ce07 in ngx_conf_handler (last=1, cf=0x7ffc9c60f110) at src/core/ngx_conf_file.c:463
        rv = <optimized out>
        conf = <optimized out>
        i = <optimized out>
        confp = <optimized out>
        found = 1
        name = 0x55ab89e7afd0
        cmd = 0x55ab88d35fa0 <ngx_http_commands>
        rv = <optimized out>
        conf = <optimized out>
        confp = <optimized out>
        i = <optimized out>
        found = <optimized out>
        name = <optimized out>
---Type <return> to continue, or q <return> to quit---
        cmd = <optimized out>
#12 ngx_conf_parse (cf=cf@entry=0x7ffc9c60f110, filename=filename@entry=0x55ab89e78ef8) at src/core/ngx_conf_file.c:319
        rv = <optimized out>
        fd = 4
        rc = <optimized out>
        buf = {
          pos = 0x55ab89e74310 "\nno)\ntsa_name\t\t= yes\t# Must the TSA name be included in the reply?\n\t\t\t\t# (optional, default: no)\ness_cert_id_chain\t= no\t# Must the ESS cert id chain be included?\n\t\t\t\t# (optional, default: no)\ness_cert"..., 
          last = 0x55ab89e74311 "no)\ntsa_name\t\t= yes\t# Must the TSA name be included in the reply?\n\t\t\t\t# (optional, default: no)\ness_cert_id_chain\t= no\t# Must the ESS cert id chain be included?\n\t\t\t\t# (optional, default: no)\ness_cert_"..., file_pos = 0, file_last = 0, 
          start = 0x55ab89e739a0 "load_module /home/test/ngx_http_modsecurity_module-debug.so;\n#load_module /home/test/ngx_http_modsecurity_module.so;\n\nuser nginx;\nworker_processes 1;\n\n#master_process off;\nworker_rlimit_core 1000M;\nwo"..., end = 0x55ab89e749a0 "\260J牫U", tag = 0x7200000000, file = 0x7, shadow = 0x0, temporary = 1, memory = 0, 
          mmap = 0, recycled = 1, in_file = 0, flush = 0, sync = 0, last_buf = 0, last_in_chain = 0, last_shadow = 0, temp_file = 0, num = 21931}
        prev = 0x0
        conf_file = {file = {fd = 4, name = {len = 21, data = 0x55ab89e78f97 "/etc/nginx/nginx.conf"}, info = {st_dev = 2051, st_ino = 6031362, st_nlink = 1, st_mode = 33188, 
              st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 2417, st_blksize = 4096, st_blocks = 8, st_atim = {tv_sec = 1611145818, tv_nsec = 67177422}, st_mtim = {
                tv_sec = 1611145789, tv_nsec = 143177422}, st_ctim = {tv_sec = 1611145789, tv_nsec = 143177422}, __glibc_reserved = {0, 0, 0}}, offset = 2417, sys_offset = 16384, 
            log = 0x55ab88d54f40 <ngx_log>, thread_handler = 0x0, thread_ctx = 0x55ab88d54f40 <ngx_log>, thread_task = 0x10, aio = 0x4000, valid_info = 0, directio = 0}, 
          buffer = 0x7ffc9c60ef20, dump = 0x55ab89e7b088, line = 101}
        type = parse_file
#13 0x000055ab88a2a364 in ngx_init_cycle (old_cycle=0x7ffc9c60f2e0) at src/core/ngx_cycle.c:284
        rv = <optimized out>
        senv = 0x7ffc9c60f6a0
        i = <optimized out>
        n = <optimized out>
        log = 0x55ab88d54f40 <ngx_log>
        tp = <optimized out>
        conf = {name = 0x0, args = 0x55ab89e7afa8, cycle = 0x55ab89e78ce0, pool = 0x55ab89e78c90, temp_pool = 0x55ab89e7cca0, conf_file = 0x7ffc9c60ef70, 
          log = 0x55ab88d54f40 <ngx_log>, ctx = 0x55ab89e7bc78, module_type = 1347703880, cmd_type = 33554432, handler = 0x0, handler_conf = 0x0}
        pool = 0x55ab89e78c90
        cycle = 0x55ab89e78ce0
        old = <optimized out>
        shm_zone = <optimized out>
        oshm_zone = <optimized out>
        part = <optimized out>
        opart = <optimized out>
        file = <optimized out>
        ls = <optimized out>
        nls = <optimized out>
        ccf = <optimized out>
        old_ccf = <optimized out>
        module = <optimized out>
        hostname = "vagrant\000\340S剫U\000\000\020\362`\234\374\177\000\000\350},\231\251\177\000\000\037\000\000\000\000\000\000\000\377\265\360\000\000\000\000\000\276\000\000\000\000\000\000\000\326\361`\234\374\177\000\000\001\000\000\000\000\000\000\000%M&\231\251\177\000\000\204\321`\234\000\000\000\000\000\000\303\000\001\000\000\000\203\321`\234\374\177\000\000\000\273\333z\332\320E\214\260\377\377\377\377\377\377\377\276", '\000' <repeats 15 times>, "P\204\326\210\253U\000\000\330D\327\210\253U\000\000\002\000\000\000\000\000\000\000\230\204\326\210\253U\000\000W\373(\231\251\177\000\000\000\000\000\000\000(noX\367`\234\374\177\000\000@OՈ\253U\000\000?\340\243\210\253U\000\000"...
#14 0x000055ab88a16481 in main (argc=<optimized out>, argv=<optimized out>) at src/core/nginx.c:292
        b = <optimized out>
---Type <return> to continue, or q <return> to quit---
        log = <optimized out>
        i = <optimized out>
        cycle = <optimized out>
        init_cycle = {conf_ctx = 0x0, pool = 0x55ab89e5d1d0, log = 0x55ab88d54f40 <ngx_log>, new_log = {log_level = 0, file = 0x0, connection = 0, disk_full_time = 0, 
            handler = 0x0, data = 0x0, writer = 0x0, wdata = 0x0, action = 0x0, next = 0x0}, log_use_stderr = 0, files = 0x0, free_connections = 0x0, free_connection_n = 0, 
          modules = 0x0, modules_n = 0, modules_used = 0, reusable_connections_queue = {prev = 0x0, next = 0x0}, reusable_connections_n = 0, connections_reuse_time = 0, 
          listening = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0}, paths = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0}, config_dump = {elts = 0x0, 
            nelts = 0, size = 0, nalloc = 0, pool = 0x0}, config_dump_rbtree = {root = 0x0, sentinel = 0x0, insert = 0x0}, config_dump_sentinel = {key = 0, left = 0x0, 
            right = 0x0, parent = 0x0, color = 0 '\000', data = 0 '\000'}, open_files = {last = 0x0, part = {elts = 0x0, nelts = 0, next = 0x0}, size = 0, nalloc = 0, pool = 0x0}, 
          shared_memory = {last = 0x0, part = {elts = 0x0, nelts = 0, next = 0x0}, size = 0, nalloc = 0, pool = 0x0}, connection_n = 0, files_n = 0, connections = 0x0, 
          read_events = 0x0, write_events = 0x0, old_cycle = 0x0, conf_file = {len = 21, data = 0x55ab88af6baf "/etc/nginx/nginx.conf"}, conf_param = {len = 0, data = 0x0}, 
          conf_prefix = {len = 11, data = 0x55ab88af6baf "/etc/nginx/nginx.conf"}, prefix = {len = 11, data = 0x55ab88af6ba3 "/etc/nginx/"}, error_log = {len = 24, 
            data = 0x55ab88af6bc5 "/var/log/nginx/error.log"}, lock_file = {len = 0, data = 0x0}, hostname = {len = 0, data = 0x0}}
        cd = <optimized out>
        ccf = <optimized out>
(gdb) 

Output of the nginx-debug -t:

root@vagrant:/var/log/nginx# nginx-debug -t
modsec *** ngx_http_modsecurity_create_main_conf: main conf created at: '0x55b01749a7c8', instance is: '0x55b017496d90' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 625.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b01749a808' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174b6300' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174b8630' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174baf48' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174bcaf0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174bf9c8' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174c17e0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174c3fb8' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174c5c28' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174c6cd8' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174cab58' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174cbbc0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0174cf7b8' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_create_conf: conf created at: '0x55b0183dba68' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 688.
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [(null)] - parent: '0x55b01749a808' child: '0x55b0174baf48' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '-1' child: '-1' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [/] - parent: '0x55b0174baf48' child: '0x55b0174bcaf0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '-1' child: '0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [(null)] - parent: '0x55b01749a808' child: '0x55b0174bf9c8' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '-1' child: '-1' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [/status] - parent: '0x55b0174bf9c8' child: '0x55b0174c17e0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '-1' child: '0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [/204] - parent: '0x55b0174bf9c8' child: '0x55b0174c3fb8' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '-1' child: '0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [/] - parent: '0x55b0174bf9c8' child: '0x55b0174c5c28' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '-1' child: '0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [/upload/] - parent: '0x55b0174bf9c8' child: '0x55b0174c6cd8' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '-1' child: '0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [/modsec-light/] - parent: '0x55b0174bf9c8' child: '0x55b0174cab58' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '1' child: '0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [/modsec-light/upload/] - parent: '0x55b0174bf9c8' child: '0x55b0174cbbc0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '1' child: '0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: NEW CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 731.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: merging loc config [/modsec-full/] - parent: '0x55b0174bf9c8' child: '0x55b0174cf7b8' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 707.
modsec *** ngx_http_modsecurity_merge_conf:                   state - parent: '1' child: '0' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 710.
modsec *** ngx_http_modsecurity_merge_conf: PARENT RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 719.
Phase: 0 (0 rules)
Phase: 1 (0 rules)
Phase: 2 (0 rules)
Phase: 3 (0 rules)
Phase: 4 (0 rules)
Phase: 5 (0 rules)
Phase: 6 (0 rules)
Phase: 7 (0 rules)
modsec *** ngx_http_modsecurity_merge_conf: CHILD RULES at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 721.
Phase: 0 (42 rules)
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-901-INITIALIZATION.conf:434--0x55b01758f800
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9001-DRUPAL-EXCLUSION-RULES.conf:407--0x55b0175a6c10
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9002-WORDPRESS-EXCLUSION-RULES.conf:755--0x55b0175e1080
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9002-WORDPRESS-EXCLUSION-RULES.conf:758--0x55b0175e2100
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9003-NEXTCLOUD-EXCLUSION-RULES.conf:413--0x55b0175f9830
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9003-NEXTCLOUD-EXCLUSION-RULES.conf:415--0x55b0175fa3f0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9004-DOKUWIKI-EXCLUSION-RULES.conf:270--0x55b01760d9c0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9004-DOKUWIKI-EXCLUSION-RULES.conf:272--0x55b01760df10
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9005-CPANEL-EXCLUSION-RULES.conf:63--0x55b01760e350
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9006-XENFORO-EXCLUSION-RULES.conf:583--0x55b017632d80
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-903.9006-XENFORO-EXCLUSION-RULES.conf:585--0x55b017633760
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-910-IP-REPUTATION.conf:292--0x55b017651280
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-910-IP-REPUTATION.conf:294--0x55b0176516f0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-910-IP-REPUTATION.conf:324--0x55b017655830
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-911-METHOD-ENFORCEMENT.conf:75--0x55b017659460
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-912-DOS-PROTECTION.conf:324--0x55b017672620
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-912-DOS-PROTECTION.conf:326--0x55b017672fd0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-913-SCANNER-DETECTION.conf:198--0x55b0176e2430
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-920-PROTOCOL-ENFORCEMENT.conf:569--0x55b01770d6d0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-920-PROTOCOL-ENFORCEMENT.conf:1599--0x55b01777a300
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-921-PROTOCOL-ATTACK.conf:363--0x55b0177a5da0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-930-APPLICATION-ATTACK-LFI.conf:155--0x55b017ace890
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-931-APPLICATION-ATTACK-RFI.conf:152--0x55b017ae2a40
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-932-APPLICATION-ATTACK-RCE.conf:728--0x55b017befcc0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-933-APPLICATION-ATTACK-PHP.conf:733--0x55b017f4cb40
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-934-APPLICATION-ATTACK-NODEJS.conf:95--0x55b017f53690
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-941-APPLICATION-ATTACK-XSS.conf:884--0x55b017ffa690
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-942-APPLICATION-ATTACK-SQLI.conf:1626--0x55b018100c40
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-943-APPLICATION-ATTACK-SESSION-FIXATION.conf:132--0x55b01810eef0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-944-APPLICATION-ATTACK-JAVA.conf:294--0x55b01815f150
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf:73--0x55b018161c30
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf:110--0x55b018166d40
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf:206--0x55b018173020
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-950-DATA-LEAKAGES.conf:139--0x55b01817eb10
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-951-DATA-LEAKAGES-SQL.conf:476--0x55b0182204c0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-952-DATA-LEAKAGES-JAVA.conf:103--0x55b01823d6d0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-953-DATA-LEAKAGES-PHP.conf:137--0x55b0183b7580
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-954-DATA-LEAKAGES-IIS.conf:151--0x55b0183c6e80
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-959-BLOCKING-EVALUATION.conf:84--0x55b0183c9f20
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-959-BLOCKING-EVALUATION.conf:190--0x55b0183d8af0
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-980-CORRELATION.conf:127--0x55b0183f2c40
    Rule ID: /etc/nginx/modsec/owasp-crs/rules/RESPONSE-980-CORRELATION.conf:165--0x55b0183f8220
Phase: 1 (42 rules)
Segmentation fault (core dumped)
defanator commented 3 years ago

With the libmodsecurity 3.0.4 and modsecurity-nginx 1.0.1 there's no segfault, but the CRS v3.3.1-rc2 with tx.blocking_early is still behaving incorrectly:

test@vagrant:/home/test$ curl -H "User-Agent: Mozilla/5.00 (Nikto/2.1.5)" -vi 'http://localhost/modsec-full/ncl_items.shtml?SUBJECT=1'
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1
> Host: localhost
> Accept: */*
> User-Agent: Mozilla/5.00 (Nikto/2.1.5)
> 
<html>
<head><title>403 Forbidden</title></head>
<body>
<center><h1>403 Forbidden</h1></center>
<hr><center>nginx/1.19.6</center>
</body>
</html>
* Connection #0 to host localhost left intact

nginx debug log:

2021/01/20 12:52:39 [debug] 31958#31958: epoll: fd:10 ev:0001 d:00007FB6266D80F8
2021/01/20 12:52:39 [debug] 31958#31958: accept on 0.0.0.0:80, ready: 0
2021/01/20 12:52:39 [debug] 31958#31958: posix_memalign: 0000556BD0E1BC70:512 @16
2021/01/20 12:52:39 [debug] 31958#31958: *1 accept: 127.0.0.1:63316 fd:3
2021/01/20 12:52:39 [debug] 31958#31958: *1 event timer add: 3: 60000:532894722
2021/01/20 12:52:39 [debug] 31958#31958: *1 reusable connection: 1
2021/01/20 12:52:39 [debug] 31958#31958: *1 epoll add event: fd:3 op:1 ev:80002001
2021/01/20 12:52:39 [debug] 31958#31958: timer delta: 4488
2021/01/20 12:52:39 [debug] 31958#31958: worker cycle
2021/01/20 12:52:39 [debug] 31958#31958: epoll timer: 60000
2021/01/20 12:52:39 [debug] 31958#31958: epoll: fd:3 ev:0001 d:00007FB6266D83B0
2021/01/20 12:52:39 [debug] 31958#31958: *1 http wait request handler
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BCF27D1D0:1024
2021/01/20 12:52:39 [debug] 31958#31958: *1 recv: eof:0, avail:-1
2021/01/20 12:52:39 [debug] 31958#31958: *1 recv: fd:3 125 of 1024
2021/01/20 12:52:39 [debug] 31958#31958: *1 reusable connection: 0
2021/01/20 12:52:39 [debug] 31958#31958: *1 posix_memalign: 0000556BCF2F53A0:4096 @16
2021/01/20 12:52:39 [debug] 31958#31958: *1 http process request line
2021/01/20 12:52:39 [debug] 31958#31958: *1 http request line: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http uri: "/modsec-full/ncl_items.shtml"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http args: "SUBJECT=1"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http exten: "shtml"
2021/01/20 12:52:39 [debug] 31958#31958: *1 posix_memalign: 0000556BCF2F63B0:4096 @16
2021/01/20 12:52:39 [debug] 31958#31958: *1 http process request header line
2021/01/20 12:52:39 [debug] 31958#31958: *1 http header: "Host: localhost"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http header: "Accept: */*"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http header: "User-Agent: Mozilla/5.00 (Nikto/2.1.5)"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http header done
2021/01/20 12:52:39 [debug] 31958#31958: *1 event timer del: 3: 532894722
2021/01/20 12:52:39 [debug] 31958#31958: *1 generic phase: 0
2021/01/20 12:52:39 [debug] 31958#31958: *1 rewrite phase: 1
2021/01/20 12:52:39 [debug] 31958#31958: *1 test location: "/"
2021/01/20 12:52:39 [debug] 31958#31958: *1 test location: "modsec-light/"
2021/01/20 12:52:39 [debug] 31958#31958: *1 test location: "modsec-full/"
2021/01/20 12:52:39 [debug] 31958#31958: *1 test location: "upload/"
2021/01/20 12:52:39 [debug] 31958#31958: *1 using configuration "/modsec-full/"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http cl:-1 max:1048576
2021/01/20 12:52:39 [debug] 31958#31958: *1 rewrite phase: 3
modsec *** ngx_http_modsecurity_rewrite_handler: catching a new _rewrite_ phase handler at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 49.
modsec *** ngx_http_modsecurity_rewrite_handler: recovering ctx: (nil) at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 53.
modsec *** ngx_http_modsecurity_create_ctx: creating transaction with the following rules: '0x556bcf31c9c0' -- ms: '0x556bcf2e2620' at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 253.
modsec *** ngx_http_modsecurity_create_ctx: transaction created at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 265.
2021/01/20 12:52:39 [debug] 31958#31958: *1 add cleanup: 0000556BCF2F6218
modsec *** ngx_http_modsecurity_rewrite_handler: ctx was NULL, creating new context: 0x556bcf2f61f8 at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 68.
modsec *** ngx_http_modsecurity_rewrite_handler: Processing intervention with the connection information filled in at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 121.
modsec *** ngx_http_modsecurity_process_intervention: processing intervention at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 142.
modsec *** ngx_http_modsecurity_process_intervention: nothing to do at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 145.
modsec *** ngx_http_modsecurity_rewrite_handler: Processing intervention with the transaction information filled in (uri, method and version) at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 157.
modsec *** ngx_http_modsecurity_process_intervention: processing intervention at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 142.
modsec *** ngx_http_modsecurity_process_intervention: nothing to do at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 145.
modsec *** ngx_http_modsecurity_rewrite_handler: Adding request header: Host with value localhost at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 189.
modsec *** ngx_http_modsecurity_rewrite_handler: Adding request header: Accept with value */* at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 189.
modsec *** ngx_http_modsecurity_rewrite_handler: Adding request header: User-Agent with value Mozilla/5.00 (Nikto/2.1.5) at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 189.
2021/01/20 12:52:39 [info] 31958#31958: *1 ModSecurity: Warning. Matched "Operator `PmFromFile' with parameter `scanners-user-agents.data' against variable `REQUEST_HEADERS:User-Agent' (Value: `Mozilla/5.00 (Nikto/2.1.5)' ) [file "/etc/nginx/modsec/owasp-crs/rules/REQUEST-913-SCANNER-DETECTION.conf"] [line "33"] [id "913100"] [rev ""] [msg "Found User-Agent associated with security scanner"] [data "Matched Data: nikto found within REQUEST_HEADERS:User-Agent: mozilla/5.00 (nikto/2.1.5)"] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-reputation-scanner"] [tag "paranoia-level/1"] [tag "OWASP_CRS"] [tag "capec/1000/118/224/541/310"] [tag "PCI/6.5.10"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "161114715921.894678"] [ref "o14,5v92,26t:lowercase"], client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BD10AB070:4096
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BD10AC080:4096
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10AB070
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10AC080
modsec *** ngx_http_modsecurity_rewrite_handler: Processing intervention with the request headers information filled in at ../ModSecurity-nginx/src/ngx_http_modsecurity_rewrite.c line 205.
modsec *** ngx_http_modsecurity_process_intervention: processing intervention at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 142.
2021/01/20 12:52:39 [error] 31958#31958: *1 [client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 1). Matched "Operator `Ge' with parameter `5' against variable `TX:ANOMALY_SCORE' (Value: `5' ) [file "/etc/nginx/modsec/owasp-crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "154"] [id "949111"] [rev ""] [msg "Inbound Anomaly Score Exceeded in phase 1 (Total Score: 5)"] [data ""] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-generic"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "161114715921.894678"] [ref ""], client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"
modsec *** ngx_http_modsecurity_process_intervention: intervention -- returning code: 403 at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 208.
2021/01/20 12:52:39 [debug] 31958#31958: *1 http finalize request: 403, "/modsec-full/ncl_items.shtml?SUBJECT=1" a:1, c:1
2021/01/20 12:52:39 [debug] 31958#31958: *1 http special response: 403, "/modsec-full/ncl_items.shtml?SUBJECT=1"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http set discard body
modsec *** ngx_http_modsecurity_header_filter: header filter, recovering ctx: 0x556bcf2f61f8 at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 429.
modsec *** ngx_http_modsecurity_header_filter:  Sending header to ModSecurity - header: `Server'. at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 474.
modsec *** ngx_http_modsecurity_header_filter:  Sending header to ModSecurity - header: `Date'. at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 474.
modsec *** ngx_http_modsecurity_header_filter:  Sending header to ModSecurity - header: `Content-Length'. at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 474.
modsec *** ngx_http_modsecurity_header_filter:  Sending header to ModSecurity - header: `Content-Type'. at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 474.
modsec *** ngx_http_modsecurity_header_filter:  Sending header to ModSecurity - header: `Last-Modified'. at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 474.
modsec *** ngx_http_modsecurity_header_filter:  Sending header to ModSecurity - header: `Connection'. at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 474.
modsec *** ngx_http_modsecurity_header_filter:  Sending header to ModSecurity - header: `Transfer-Encoding'. at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 474.
modsec *** ngx_http_modsecurity_header_filter:  Sending header to ModSecurity - header: `Vary'. at ../ModSecurity-nginx/src/ngx_http_modsecurity_header_filter.c line 474.
modsec *** ngx_http_modsecurity_process_intervention: processing intervention at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 142.
2021/01/20 12:52:39 [error] 31958#31958: *1 [client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 3). Matched "Operator `Ge' with parameter `4' against variable `TX:OUTBOUND_ANOMALY_SCORE' (Value: `5' ) [file "/etc/nginx/modsec/owasp-crs/rules/RESPONSE-959-BLOCKING-EVALUATION.conf"] [line "138"] [id "959101"] [rev ""] [msg "Outbound Anomaly Score Exceeded in phase 3 (Total Score: 5)"] [data ""] [severity "2"] [ver "OWASP_CRS/3.3.1"] [maturity "0"] [accuracy "0"] [tag "application-multi"] [tag "language-multi"] [tag "platform-multi"] [tag "attack-generic"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "161114715921.894678"] [ref ""], client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"
modsec *** ngx_http_modsecurity_process_intervention: intervention -- returning code: 403 at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 208.
2021/01/20 12:52:39 [debug] 31958#31958: *1 http output filter "/modsec-full/ncl_items.shtml?SUBJECT=1"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http copy filter: "/modsec-full/ncl_items.shtml?SUBJECT=1"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http postpone filter "/modsec-full/ncl_items.shtml?SUBJECT=1" 0000556BCF2F6388
modsec *** ngx_http_modsecurity_body_filter: body filter, recovering ctx: 0x556bcf2f61f8 at ../ModSecurity-nginx/src/ngx_http_modsecurity_body_filter.c line 53.
modsec *** ngx_http_modsecurity_process_intervention: processing intervention at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 142.
modsec *** ngx_http_modsecurity_process_intervention: nothing to do at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 145.
modsec *** ngx_http_modsecurity_process_intervention: processing intervention at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 142.
modsec *** ngx_http_modsecurity_process_intervention: nothing to do at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 145.
modsec *** ngx_http_modsecurity_process_intervention: processing intervention at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 142.
modsec *** ngx_http_modsecurity_process_intervention: nothing to do at ../ModSecurity-nginx/src/ngx_http_modsecurity_module.c line 145.
2021/01/20 12:52:39 [debug] 31958#31958: *1 write new buf t:0 f:0 0000000000000000, pos 0000556BCDBD4720, size: 100 file: 0, size: 0
2021/01/20 12:52:39 [debug] 31958#31958: *1 write new buf t:0 f:0 0000000000000000, pos 0000556BCDBD4E00, size: 53 file: 0, size: 0
2021/01/20 12:52:39 [debug] 31958#31958: *1 http write filter: l:1 f:0 s:153
2021/01/20 12:52:39 [debug] 31958#31958: *1 http write filter limit 0
2021/01/20 12:52:39 [debug] 31958#31958: *1 writev: 153 of 153
2021/01/20 12:52:39 [debug] 31958#31958: *1 http write filter 0000000000000000
2021/01/20 12:52:39 [debug] 31958#31958: *1 http copy filter: 0 "/modsec-full/ncl_items.shtml?SUBJECT=1"
2021/01/20 12:52:39 [debug] 31958#31958: *1 http finalize request: 0, "/modsec-full/ncl_items.shtml?SUBJECT=1" a:1, c:1
2021/01/20 12:52:39 [debug] 31958#31958: *1 set http keepalive handler
2021/01/20 12:52:39 [debug] 31958#31958: *1 http close request
2021/01/20 12:52:39 [debug] 31958#31958: *1 http log handler
modsec *** ngx_http_modsecurity_log_handler: catching a new _log_ phase handler at ../ModSecurity-nginx/src/ngx_http_modsecurity_log.c line 48.
modsec *** ngx_http_modsecurity_log_handler: recovering ctx: 0x556bcf2f61f8 at ../ModSecurity-nginx/src/ngx_http_modsecurity_log.c line 67.
modsec *** ngx_http_modsecurity_log_handler: calling msc_process_logging for 0x556bcf2f61f8 at ../ModSecurity-nginx/src/ngx_http_modsecurity_log.c line 74.
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BD10ABA50:4096
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BD10ACA60:4096
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10ABA50
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10ACA60
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BD10ABA50:4096
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BD10ACA60:4096
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10ABA50
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10ACA60
2021/01/20 12:52:39 [debug] 31958#31958: *1 posix_memalign: 0000556BD10ABA50:4096 @16
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BD10ACA60:4096
2021/01/20 12:52:39 [debug] 31958#31958: *1 malloc: 0000556BD10ADA70:4096
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10ACA60
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10ADA70
2021/01/20 12:52:39 [debug] 31958#31958: *1 run cleanup: 0000556BCF2F6218
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000000000000000
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000000000000000
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BCF2F53A0, unused: 7
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BCF2F63B0, unused: 8
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BD10ABA50, unused: 3816
2021/01/20 12:52:39 [debug] 31958#31958: *1 free: 0000556BCF27D1D0
2021/01/20 12:52:39 [debug] 31958#31958: *1 hc free: 0000000000000000
2021/01/20 12:52:39 [debug] 31958#31958: *1 hc busy: 0000000000000000 0
2021/01/20 12:52:39 [debug] 31958#31958: *1 tcp_nodelay
2021/01/20 12:52:39 [debug] 31958#31958: *1 reusable connection: 1
2021/01/20 12:52:39 [debug] 31958#31958: *1 event timer add: 3: 75000:532909722
2021/01/20 12:52:39 [debug] 31958#31958: timer delta: 0
2021/01/20 12:52:39 [debug] 31958#31958: worker cycle
2021/01/20 12:52:39 [debug] 31958#31958: epoll timer: 75000
2021/01/20 12:53:54 [debug] 31958#31958: timer delta: 75064
2021/01/20 12:53:54 [debug] 31958#31958: *1 event timer del: 3: 532909722
2021/01/20 12:53:54 [debug] 31958#31958: *1 http keepalive handler
2021/01/20 12:53:54 [debug] 31958#31958: *1 close http connection: 3
2021/01/20 12:53:54 [debug] 31958#31958: *1 reusable connection: 0
2021/01/20 12:53:54 [debug] 31958#31958: *1 free: 0000000000000000
2021/01/20 12:53:54 [debug] 31958#31958: *1 free: 0000556BD0E1BC70, unused: 120
2021/01/20 12:53:54 [debug] 31958#31958: worker cycle
2021/01/20 12:53:54 [debug] 31958#31958: epoll timer: -1
airween commented 3 years ago

Hi @defanator,

BTW, I'm using reproducible environment from https://github.com/defanator/modsecurity-performance/ for tests. You can adjust CRS version in https://github.com/defanator/modsecurity-performance/blob/master/pillars/versions.sls to v3.3.1-rc1 before launching vagrant vm, apply the mentioned patch for crs-setup.conf, and reproduce it with the following request:

thanks for sharing this resource, I built your environment and successfully reproduced the behavior.

With the libmodsecurity 3.0.4 and modsecurity-nginx 1.0.1 there's no segfault, but the CRS v3.3.1-rc2 with tx.blocking_early is still behaving incorrectly:

Just a quick note: I think in this case not the rule set produces this behavior.

First of all, this modification in your nginx.conf fixes it:

102,107d101
< 
<         error_page  500 502 503 504 /50x.html;
<         location = /50x.html {
<           root  html;
<         }
< 

Thanks to @theMiddleBlue for solution.

I think this behavior comes when Nginx uses proxy_pass directive. As I wrote here, I'm really curious why does Nginx continues processing the request if there was a triggered rule which would terminate it (by an action deny)?

Let's see a minimalist rule set:

include /etc/nginx/modsec/modsecurity.conf

SecDefaultAction "phase:1,log,auditlog,pass"
SecDefaultAction "phase:2,log,auditlog,pass"

SecAction "id:900101,phase:1,nolog,pass,t:none,setvar:tx.trigger_phase1=1"
SecAction "id:900103,phase:1,nolog,pass,t:none,setvar:tx.trigger_phase3=1"
SecAction "id:900105,phase:1,nolog,pass,t:none,setvar:tx.trigger_phase5=1"

SecRule TX:TRIGGER_PHASE1 "@eq 1" "id:901111,phase:1,t:none,deny,log"
SecRule REQUEST_BODY "@rx attack" "id:901121,phase:2,t:none,deny,log"
SecRule TX:TRIGGER_PHASE3 "@eq 1" "id:901131,phase:3,t:none,deny,log"
SecRule RESPONSE_BODY "@rx ok" "id:901141,phase:4,t:none,deny,log"
SecRule TX:TRIGGER_PHASE5 "@eq 1" "id:901151,phase:5,t:none,pass,log,msg:'This is the phase 5.'"

The logic of this set is a bit similar to CRS blocking_early feature, but here is not any valid check. I don't use any scoring mechanism here, just set few transaction variables as constant (rules 900101-900105), and the rules in phases checks these - imagine that the anomaly score value reached the minimal, and rule triggered.

A side note: when I started Nginx with this config, I got this line in the log:

2021/01/21 07:49:12 [notice] 6014#6014: ModSecurity-nginx v1.0.1 (rules loaded inline/local/remote: 0/42/0)

which is weird, I don't have 42 local rules - perhaps the reason is the engine counts the loaded rules as many times the modsecurity_rules_file directive occurs.

I ran your request against this set, and I got same behavior as you described. And I have this lines in the log:

2021/01/21 07:50:41 [error] 6016#6016: *1 [client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 1). Matched "Operator `Eq' with parameter `1' against variable `TX:TRIGGER_PHASE1' (Value: `1' ) [file "/etc/nginx/modsec/main.conf"] [line "10"] [id "901111"] [rev ""] [msg ""] [data ""] [severity "0"] [ver ""] [maturity "0"] [accuracy "0"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "1611215441"] [ref ""], client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"

2021/01/21 07:50:41 [error] 6016#6016: *1 [client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 3). Matched "Operator `Eq' with parameter `1' against variable `TX:TRIGGER_PHASE3' (Value: `1' ) [file "/etc/nginx/modsec/main.conf"] [line "12"] [id "901131"] [rev ""] [msg ""] [data ""] [severity "0"] [ver ""] [maturity "0"] [accuracy "0"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "1611215441"] [ref ""], client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"

2021/01/21 07:50:41 [info] 6016#6016: *1 ModSecurity: Warning. Matched "Operator `Eq' with parameter `1' against variable `TX:TRIGGER_PHASE5' (Value: `1' ) [file "/etc/nginx/modsec/main.conf"] [line "14"] [id "901151"] [rev ""] [msg "This is the phase 5."] [data ""] [severity "0"] [ver ""] [maturity "0"] [accuracy "0"] [hostname "127.0.0.1"] [uri "/modsec-full/ncl_items.shtml"] [unique_id "1611215441"] [ref ""] while logging request, client: 127.0.0.1, server: , request: "GET /modsec-full/ncl_items.shtml?SUBJECT=1 HTTP/1.1", host: "localhost"

As you can see, here are two triggered rules which wants to stop the processing of transactions: the first is the 901111 in phase:1, then the 901131 in phase:3. But after the first rule the connection will not terminate - perhaps the proxy (because you configured this server as proxy) waits for the answer from the upstream - don't know. I also don't know what happens when the second rule triggered - may be it blocks to send the response headers... really don't know. Finally, it's also a big mystery why fixes the error_page directive this behavior...

But based on these information I think this is a connector bug, not the rule set.

defanator commented 3 years ago

@airween good to see you were able to trigger that as well.

I'm not blaming CRS - I admit that the bug could be either in library or in connector module, that's fine.

The root cause (as I see it) is that nginx connector tries to do all the processing as early as possible (in the pre-access phase, iirc), and by some unclear reasons it does NOT send response headers in the discussed configuration before starting to send the body (calling ngx_http_finalize_request()).

Most likely, adding error_page logic produces additional internal redirect which involves sending response headers.

I'll try to pick some time to dig into this later. Thanks for your investigations and minimal config.

Re: rules number count - yes, the counter increases every time ngx_conf_set_rules_file() gets called in the configuration parsing phase; result comes from msc_rules_add_file(). This may be confusing, but I don't treat this as wrong behavior - you can configure the same set of rules in every server/location block, and those will NOT be reused in terms of memory consumption etc. Am I wrong?

Update: rules counter question was also raised here: https://github.com/defanator/modsecurity-performance/issues/3

airween commented 3 years ago

Hi @defanator,

I'm not blaming CRS - I admit that the bug could be either in library or in connector module, that's fine.

oh, sure - sorry if I was ambiguous.

The root cause (as I see it) is that nginx connector tries to do all the processing as early as possible (in the pre-access phase, iirc), and by some unclear reasons it does NOT send response headers in the discussed configuration before starting to send the body (calling ngx_http_finalize_request()).

I'm really happy that you found the root case.

Most likely, adding error_page logic produces additional internal redirect which involves sending response headers.

ah, good to know.

I'll try to pick some time to dig into this later. Thanks for your investigations and minimal config.

you're welcome.

Re: rules number count - yes, the counter increases every time ngx_conf_set_rules_file() gets called in the configuration parsing phase; result comes from msc_rules_add_file(). This may be confusing, but I don't treat this as wrong behavior - you can configure the same set of rules in every server/location block, and those will NOT be reused in terms of memory consumption etc. Am I wrong?

I don't know. As a customer, I'm curious how many rules I have. If a rule loaded twice (I mean loaded for two different contexts), IMHO it's only one rule. But it's not an important question...

Should I open an issue under ModSecurity-nginx, or it isn't necessary?

defanator commented 3 years ago

Re: rules number count - yes, the counter increases every time ngx_conf_set_rules_file() gets called in the configuration parsing phase; result comes from msc_rules_add_file(). This may be confusing, but I don't treat this as wrong behavior - you can configure the same set of rules in every server/location block, and those will NOT be reused in terms of memory consumption etc. Am I wrong?

I don't know. As a customer, I'm curious how many rules I have. If a rule loaded twice (I mean loaded for two different contexts), IMHO it's only one rule. But it's not an important question...

Should I open an issue under ModSecurity-nginx, or it isn't necessary?

I don't have any strong opinion here. As you can see from the sources, nginx connector simply counts everything returned by every msc_rules_add() / msc_rules_add_file() / msc_rules_add_remote() library functions. I'm not sure it's a good idea to implement any additional logic at the connector's side as it could be subjected to race conditions (local file as well as remote contents may change between subsequent msc_rules_add*() calls). This topic worths additional discussion / investigations.

airween commented 3 years ago

Should I open an issue under ModSecurity-nginx, or it isn't necessary?

I don't have any strong opinion here. As you can see from the sources, nginx connector simply counts everything returned by every msc_rules_add() / msc_rules_add_file() / msc_rules_add_remote() library functions. I'm not sure it's a good idea to implement any additional logic at the connector's side as it could be subjected to race conditions (local file as well as remote contents may change between subsequent msc_rules_add*() calls). This topic worths additional discussion / investigations.

oh, sorry again - I thought about connector problem (to open an issue), not the rule counting. As I wrote, the counting issue isn't an important thing.