ModSecurity not finding SecMarker in phase 2

[TomCan]

Not sure if this is a ModSecurity bug or a CoreRuleSet bug, but starting here.

OS: Debian 11
Versions: libapache2-mod-security2 2.9.3-3+deb11u1 with modsecurity-crs 3.3.0-1+deb11u1, both installed from Debian stable repositories.

With SecDebugLogLevel 9, following relevant lines appear in the debug log when making a PUT request to /tomc4 (which should be blocked by default).

[/tomc4][4] Recipe: Invoking rule 7f3a5e3c8778; [file "/usr/share/modsecurity-crs/rules/REQUEST-903.9001-DRUPAL-EXCLUSION-RULES.conf"] [line "72"] [id "9001000"].
[/tomc4][5] Rule 7f3a5e3c8778: SecRule "&TX:crs_exclusions_drupal|TX:crs_exclusions_drupal" "@eq 0" "phase:1,auditlog,id:9001000,t:none,nolog,ver:OWASP_CRS/3.3.0,skipAfter:END-DRUPAL-RULE-EXCLUSIONS"
[/tomc4][4] Transformation completed in 0 usec.
[/tomc4][4] Executing operator "eq" with param "0" against &TX:crs_exclusions_drupal.
[/tomc4][9] Target value: "0"
[/tomc4][4] Operator completed in 0 usec.
[/tomc4][4] Warning. Operator EQ matched 0 at TX. [file "/usr/share/modsecurity-crs/rules/REQUEST-903.9001-DRUPAL-EXCLUSION-RULES.conf"] [line "72"] [id "9001000"] [ver "OWASP_CRS/3.3.0"]
[/tomc4][4] Rule returned 1.
[/tomc4][9] Skipping after rule 7f3a5e3c8778 id="END-DRUPAL-RULE-EXCLUSIONS" -> mode SKIP_RULES.
[/tomc4][9] Found rule 7f3a5e387188 id="END-DRUPAL-RULE-EXCLUSIONS".
[/tomc4][4] Continuing execution after rule id="END-DRUPAL-RULE-EXCLUSIONS".
[/tomc4][4] Recipe: Invoking rule 7f3a5e387d68; [file "/usr/share/modsecurity-crs/rules/REQUEST-903.9002-WORDPRESS-EXCLUSION-RULES.conf"] [line "26"] [id "9002000"].
[/tomc4][4] Recipe: Invoking rule 7f3a5e387d68; [file "/usr/share/modsecurity-crs/rules/REQUEST-903.9002-WORDPRESS-EXCLUSION-RULES.conf"] [line "26"] [id "9002000"].
[/tomc4][5] Rule 7f3a5e387d68: SecRule "&TX:crs_exclusions_wordpress|TX:crs_exclusions_wordpress" "@eq 0" "phase:1,auditlog,id:9002000,t:none,nolog,ver:OWASP_CRS/3.3.0,skipAfter:END-WORDPRESS"
[/tomc4][4] Transformation completed in 1 usec.
[/tomc4][4] Executing operator "eq" with param "0" against &TX:crs_exclusions_wordpress.

This is during phase:1, which is expected. Rule 9001000 triggers a skipAfter to END-DRUPAL-RULE-EXCLUSIONS, which is defined at the end of the same file, REQUEST-903.9001-DRUPAL-EXCLUSION-RULES.conf.

When it processes phase 2 however, a similar rules 9001001 is executed, also triggering the skipAfter to the same END-DRUPAL-RULE-EXCLUSIONS SecMarker. However, this time it does not seem to find the marker, skipping each and every other phase 2 rule.

[/tomc4][4] Starting phase REQUEST_BODY.
[/tomc4][9] This phase consists of 470 rule(s).
...
[/tomc4][4] Recipe: Invoking rule 7f3a5e3c0190; [file "/usr/share/modsecurity-crs/rules/REQUEST-903.9001-DRUPAL-EXCLUSION-RULES.conf"] [line "81"] [id "9001001"].
[/tomc4][5] Rule 7f3a5e3c0190: SecRule "&TX:crs_exclusions_drupal|TX:crs_exclusions_drupal" "@eq 0" "phase:2,auditlog,id:9001001,t:none,nolog,ver:OWASP_CRS/3.3.0,skipAfter:END-DRUPAL-RULE-EXCLUSIONS"
[/tomc4][4] Transformation completed in 0 usec.
[/tomc4][4] Executing operator "eq" with param "0" against &TX:crs_exclusions_drupal.
[/tomc4][9] Target value: "0"
[/tomc4][4] Operator completed in 0 usec.
[/tomc4][4] Warning. Operator EQ matched 0 at TX. [file "/usr/share/modsecurity-crs/rules/REQUEST-903.9001-DRUPAL-EXCLUSION-RULES.conf"] [line "81"] [id "9001001"] [ver "OWASP_CRS/3.3.0"]
[/tomc4][4] Rule returned 1.
[/tomc4][9] Skipping after rule 7f3a5e3c0190 id="END-DRUPAL-RULE-EXCLUSIONS" -> mode SKIP_RULES.
[/tomc4][9] Current rule is id="9001100" [chained 0] is trying to find the SecMarker="END-DRUPAL-RULE-EXCLUSIONS" [stater 0]
[/tomc4][9] Current rule is id="9001110" [chained 0] is trying to find the SecMarker="END-DRUPAL-RULE-EXCLUSIONS" [stater 0]
...
[/tomc4][9] Current rule is id="9001216" [chained 0] is trying to find the SecMarker="END-DRUPAL-RULE-EXCLUSIONS" [stater 0]
[/tomc4][9] Current rule is id="9002001" [chained 0] is trying to find the SecMarker="END-DRUPAL-RULE-EXCLUSIONS" [stater 0]
....
[/tomc4][9] Current rule is id="980018" [chained 0] is trying to find the SecMarker="END-DRUPAL-RULE-EXCLUSIONS" [stater 0]
[/tomc4][4] Hook insert_filter: Adding output filter (r 7f3a5ee6a0a0).
[/tomc4][9] Output filter: Receiving output (f 7f3a5ee3b6d8, r 7f3a5ee6a0a0).
[/tomc4][4] Starting phase RESPONSE_HEADERS.

After skipping rule 9001216 (defined in REQUEST-903.9001-DRUPAL-EXCLUSION-RULES.conf), it should hit the END-DRUPAL-RULE-EXCLUSIONS SecMarker, but instead continues to skip rule 9002001 which is defined in REQUEST-903.9002-WORDPRESS-EXCLUSION-RULES.conf.

[martinhsv]

Hello @TomCan ,

I have not been able to reproduce the effect that you have described. In my setup (attempted with both ModSecurity v2.9.3 and v2.9.7) the skipAfter functionality is working correctly (both in general, and for the specific CRS END-DRUPAL-RULE-EXCLUSIONS SecMarker in your example).

One thing you could try: Your version of ModSecurity is pretty old. You could try upgrading and see if your issue persists.

If you're looking for an immediate alternative, one option could be to exclude the relevant rules by excluding the ids instead of using skipAfter, e.g.:

ctl:ruleRemoveById=9001100-9001216

[martinhsv]

If you are interested in investigating on your end, you could consider trying to see if you can reproduce it with minimal configuration and a minimal set of rules (i.e. no CRS rules), e.g.:

SecRule REQUEST_FILENAME "@rx .*" "phase:1,log,pass,id:7000,skipAfter:TEST-END"
SecRule REQUEST_FILENAME "@rx .*" "phase:2,log,pass,id:7001,skipAfter:TEST-END"

SecRule ARGS "@rx a1" "phase:1,log,deny,status:403,id:7002"
SecRule ARGS "@rx a2" "phase:2,log,deny,status:403,id:7003"
SecMarker "TEST-END"
SecRule ARGS "@rx a3" "phase:1,log,deny,status:403,id:7004"
SecRule ARGS "@rx a4" "phase:2,log,deny,status:403,id:7005"

[TomCan]

Thank you for investigating. I've done some triage and have come to a situation where I can no longer reproduce the problem myself. Both the minimal configuration, as the full configuration with CRS now appear to work correctly. Not sure why, as when debugging the initial problem, I have restarted and even reinstalled the packages and config multiple times.

Anyway, if I encounter this problem on other new installs, I will further investigate and test. But for now I can't provide you with any other useful information.

[TomCan]

I managed to reproduce this on another server, and pinned it down to following:
In /etc/modsecurity/allowlist_drupal.conf, we had Apache config that uses SecRuleRemoveById to disable a number of rules. If we exclude one rule specifically, rule 950100 which is defined in /usr/share/modsecurity-crs/rules/RESPONSE-950-DATA-LEAKAGES.conf, the problem occurs and it can't find the SecMarker in phase 2.

# /etc/modsecurity/allowlist_drupal.conf
<LocationMatch />
    SecRuleRemoveById 950100
</LocationMatch>

[martinhsv]

@TomCan : Is this still with ModSecurity v2.9.3? Or have you upgraded to a more recent version?

[martinhsv]

I did try your Feb. 10 example, btw, and was not able to reproduce the effect you described.

It could be that there is something else distinctive in your configuration that contributing to this. It's still likely worth upgrading to a new ModSecurity v2.9.x, in case that version from 2018 is part of the problem.

[tvlooy]

we are using Debian 11 packaged versions
libapache2-mod-security2 2.9.3-3+deb11u1
modsecurity-crs 3.3.0-1+deb11u1
so indeed 2.9.3
I can send you the complete config that we have now if that helps. Should I open an MR on this repo with it or do you prefer email?

[stevenMondelaers]

When using Debian 12 packaged versions, we still experience the same problem
libapache2-mod-security2, 2.9.7-1+b1 with modsecurity-crs 3.3.4-1

We can provide you with a complete config to help you reproduce it. Should we open a MR on this repo with it or do you prefer email?

[tvlooy]

this is reproducible if you add this to your config

<LocationMatch "/">
  SecRuleRemoveById 950100 #
</LocationMatch>

we placed an inline comment "# for saml login" there, but that's not how the system works and I think that # gets interpreted somehow

while this can be classified as PEBCAC :-), it wouldn't be bad to let SecRuleRemoveById fail if a # is given

[TomCan]

I think it's not just user error, but also a bug.
In the docs, SecRuleRemoveById is defined as:
SecRuleRemoveById ID ID RANGE ...
If an invalid ID or range has been specified, it should either be ignored, or throw an error. In this case, it results in unexpected behaviour further down the processing.
But at least it's reproducable now, and no longer blocking due to the easy workaround.

[marcstern]

We should validate the syntax of the parameter in cmd_rule_remove_by_id()