Question about the audit log when RelevantOnly is specified

[AirisX]

Hello, @zimmerle.

https://github.com/SpiderLabs/ModSecurity/blob/ec86b242e15f9df1d143c1b7f86a27889658b4cb/src/audit_log/audit_log.cc#L299-L302

I have some doubts about the correct handling of the "noauditlog" action in "saveIfRelevant".
In my case I defined next config with the relevant statuses and the only one non disruptive rule for simplifying (other setting is omitted). Pay attention that I am not using "nouauditlog" in the rule:

...
SecAuditEngine RelevantOnly
SecAuditLogRelevantStatus "^(?:500|403)"
...
SecRule &REQUEST_HEADERS:Accept "@eq 0" \
  "msg:'Request Missing an Accept Header',\
   phase:request,\
   rev:'3',\
   ver:'OWASP_CRS/3.0.0',\
   maturity:'9',\
   accuracy:'8',\
   t:none,\
   pass,\
   severity:'NOTICE',\
   id:3067"
...

Then I send the request without the "Accept" header. Eventually I get an audit log record with a 200 status code, although it's not the relevant status.
Debug log:

[4] Initializing transaction
[4] Transaction context created.
[4] Starting phase CONNECTION. (SecRules 0)
[9] This phase consists of 0 rule(s).
[4] Starting phase URI. (SecRules 0 + 1/2)
[4] Starting phase REQUEST_HEADERS.  (SecRules 1)
[9] This phase consists of 0 rule(s).
[9] Appending request body: 2 bytes. Limit set to: 0.000000
[9] Appending request body: 0 bytes. Limit set to: 0.000000
[4] Starting phase REQUEST_BODY. (SecRules 2)
[4] Don't use timeout
[9] This phase consists of 1 rule(s).
[4] (Rule: 3067) Executing operator "Eq" with param "0" against REQUEST_HEADERS:Accept.
[9] Target value: "0" (Variable: REQUEST_HEADERS:Accept)
[9] Matched vars updated.
[4] Rule returned 1.
[9] This rule severity is: 5 current transaction is: 255
[9] Saving msg: Request Missing an Accept Header
[4] Running (disruptive)     action: pass.
[8] Running action pass
[4] Starting phase RESPONSE_HEADERS. (SecRules 3)
[9] This phase consists of 0 rule(s).
[4] Not appending response body. Response Content-Type is application/x-www-form-urlencoded. It is not marked to be inspected.
[4] Starting phase RESPONSE_BODY. (SecRules 4)
[4] Don't use timeout
[5] Response Content-Type is application/x-www-form-urlencoded. It is not marked to be inspected.
[8] Content-Type(s) marked to be inspected: application/json application/xml text/html text/plain text/xml
[4] Starting phase LOGGING. (SecRules 5)
[9] This phase consists of 0 rule(s).
[8] Checking if this request is suitable to be saved as an audit log.
[8] Checking if this request is relevant to be part of the audit logs.
[5] Saving this request as part of the audit logs.
[8] Request was relevant to be saved. Parts: 8174

Could you please help to inspect this case?

[AirisX]

Also, saving messages is disabled here:
https://github.com/SpiderLabs/ModSecurity/blob/ec86b242e15f9df1d143c1b7f86a27889658b4cb/src/actions/no_audit_log.cc#L29-L35
But here is an attempt to analyze messages for a noauditlog:
https://github.com/SpiderLabs/ModSecurity/blob/ec86b242e15f9df1d143c1b7f86a27889658b4cb/src/audit_log/audit_log.cc#L298-L303

Other confusing thing follows from the doc:
https://github.com/SpiderLabs/ModSecurity/wiki/Reference-Manual-%28v2.x%29#noauditlog

The noauditlog action affects only the current rule. If you prevent audit logging in one rule only, a match in another rule will still cause audit logging to take place.

but it seems that the current implementation provides for disabling logging in any case, even when another rule matches.

[AirisX]

@zimmerle,
Seems that quick fix looks like this #2643

[martinhsv]

Hello @AirisX ,

It is possible that I'm not fully understanding the nature of your concern/inquiry. However, one thing to clarify immediately is that using something like ...

SecAuditEngine RelevantOnly
SecAuditLogRelevantStatus "^(?:500|403)"

... does not literally mean to only write to the audit log when the HTTP response code returned to the client matches the specified regex. If we were to be that restrictive in terms of audit log writing, we would break the DetectionOnly functionality.

With DetectionOnly we explicitly do not want to interfere with clients' getting web-server-generated responses, so they will receive a response code of 200. However, that does not mean we want to omit logging suspicious content (say SQLi) that has triggered one of our rules.

Note that a default assumption of 'auditlog' is explicitly mentioned in the v2 Reference Manual (granted, the v2 manual will occasionally differ from how v3 works):

"Additionally, the auditlog action is present by default in rules, this will make the engine bypass the 'SecAuditLogRelevantStatus' and send rule matches to the audit log regardless of status. You must specify noauditlog in the rules manually or set it in SecDefaultAction."

[AirisX]

Hello @martinhsv ,

Thanks for answering. I had to mention, that I'm using SecRuleEngine On, not SecRuleEngine DetectionOnly.

As for:

"Additionally, the auditlog action is present by default in rules, this will make the engine bypass the 'SecAuditLogRelevantStatus' and send rule matches to the audit log regardless of status. You must specify noauditlog in the rules manually or set it in SecDefaultAction."

You do not find that this is fundamentally contrary to the essence of the RelevantOnly? If I have explicitly defined RelevantOnly, I expect only the specified statuses to appear in the log. Otherwise it doesn't make sense.
I have attached the PR #2643 and tested it manually. Now it works as I expect.

[AirisX]

Hello @martinhsv ,

I also added some regression test cases (noauditlog-relevant.json). Before the changes, cases 1 and 4 did not work. Now they work:

ModSecurity 3.0.5 - tests
(options are not available -- missing GetOpt)

 # File Name                                         Test Name                                                             Passed?   
--- ---------                                         ---------                                                             -------   
 1 noauditlog-relevant.json                          Case 1. Rule matches the request but the return status code '403' is not relevant. The 'noauditlog' action is not specified.passed!
 2 noauditlog-relevant.json                          Case 2. Rule matches the request but the return status code '403' is not relevant. The 'noauditlog' action is specified.passed!
 3 noauditlog-relevant.json                          Case 3. Rule matches the request and the return status code '403' is relevant. The 'noauditlog' action is not specified.passed!
 4 noauditlog-relevant.json                          Case 4. Rule matches the request and the return status code '403' is relevant. The 'noauditlog' action is specified.passed!

Ran a total of: 4 regression tests - All tests passed. 0 skipped test(s). 0 disabled test(s).

[martinhsv]

Hello @AirisX ,

I agree that the audit logging behaviour is less clear than it could be. In particular, the names of the two cited configuration items can be easy to misinterpret as to their effect.

That aside, I'm not convinced that the current functionality is fundamentally problematic in the way that you suggest.

You write:

You do not find that this is fundamentally contrary to the essence of the RelevantOnly? If I have explicitly defined RelevantOnly, I expect only the specified statuses to appear in the log. Otherwise it doesn't make sense.

Again, the naming of those configuration items may lead one to that conclusion, but that is a mistake. Leave aside the names for a moment and consider the underlying motivation for the configuration items (and here I am in part interpreting my predecessors' thinking):

There are three high level options for the question 'Should logging to the audit log occur?': 1) Yes, for every request 2) No, never 3) Yes, but only for 'interesting things'.

For 'interesting things', why have an extra configuration item such as SecAuditLogRelevantStatus? Why not simply allow the internal logic of ModSecurity (a rule has detected) and a rule's associated actions (especially the logging actions: log,nolog,auditlog,noauditlog) to make the determination?

One answer is that it allows one to categorize requests as 'interesting things', and thus worth audit logging, even if no ModSecurity rules are triggered at all. It is reasonable to think of certain types of response codes generated by the web server to be of interest in having an overall view of possible attacks.

In other words, 'SecAuditLogRelevantStatus' is not properly understood as a full and complete definition of what is meant by 'Relevant' in 'SecAuditEngine RelevantOnly'. Rather, it defines a set of status codes that make a request an 'interesting thing' (i.e. Relevant) in addition to other factors that may independently do that.

I'll also reiterate my earlier point about DetectionOnly. Even though that is not the setting you are using, we still need to consider it. Your pull request will break that functionality. With your pull request, DetectionOnly, and a simple rule like ...

SecRule ARGS "@streq abcdef" "id:2001,phase:2,log,deny,status:403"

... even if the rule triggers, no information will be written to the audit log.

[AirisX]

Hello @martinhsv ,

I checked the next case (with DetectionOnly specified) and it really doesn't work:

 {
        "enabled":1,
        "version_min":300000,
        "title":"Case 5. DetectionOnly.",
        "client":{
          "ip":"127.0.0.1",
          "port":1234
        },
        "server":{
          "ip":"127.0.0.1",
          "port":80
        },
        "request":{
          "headers":{
            "Host":"localhost",
            "User-Agent":"curl/7.38.0",
            "Accept":"*/*"
          },
          "uri":"index.php?foo=bar",
          "method":"GET",
          "body": ""
        },
        "expected": {
          "http_code": 200,
          "error_log": "ModSecurity: Warning. Matched \"Operator `Rx' with parameter `\\^bar\\$' against variable `ARGS:foo'",
          "audit_log": "ModSecurity: Warning. Matched \"Operator `Rx' with parameter `\\^bar\\$' against variable `ARGS:foo'",
          "debug_log": "Request was relevant to be saved"
        },
        "rules":[
          "SecRuleEngine DetectionOnly",
          "SecAuditEngine RelevantOnly",
          "SecAuditLogParts ABIJDEFHZ",
          "SecAuditLog /tmp/test/modsec_audit.log",
          "SecAuditLogDirMode 0766",
          "SecAuditLogFileMode 0666",
          "SecAuditLogType Serial",
          "SecAuditLogRelevantStatus \"^403\"",
          "SecRule ARGS:foo \"@rx ^bar$\" \"id:1234,phase:request,log,deny,status:403\""
        ]
      }

But if DetectionOnly is the only one stumbling stone, what if we explicitly handle it here like this:

if ((m_status == RelevantOnlyAuditLogStatus
        && this->isRelevant(transaction->m_httpCodeReturned) == false
        && transaction->getRuleEngineState() != static_cast<int>(RulesSetProperties::DetectionOnlyRuleEngine)) 
        || saveAnyway == false ) {

In this case, all test cases work fine:

  # File Name                                         Test Name                                                             Passed?   
--- ---------                                         ---------                                                             -------   
  1 noauditlog-relevant.json                          Case 1. Rule matches the request but the return status code '403' is not relevant. The 'noauditlog' action is not specified.passed!
  2 noauditlog-relevant.json                          Case 2. Rule matches the request but the return status code '403' is not relevant. The 'noauditlog' action is specified.passed!
  3 noauditlog-relevant.json                          Case 3. Rule matches the request and the return status code '403' is relevant. The 'noauditlog' action is not specified.passed!
  4 noauditlog-relevant.json                          Case 4. Rule matches the request and the return status code '403' is relevant. The 'noauditlog' action is specified.passed!
  5 noauditlog-relevant.json                          Case 5. DetectionOnly.                                                passed!

The rest of the behavior, that this PR brings, also looks harmonious in relation to the current implementation.

[AirisX]

Maybe there are other pitfalls to consider?

[martinhsv]

Hi @AirisX ,

I'm going to go ahead and close this since it seems we have adequately clarified the misconception at the heart of this issue's creation: namely, that SecAuditLogRelevantStatus is not intended to be (and indeed cannot ever be) a full and complete definition of the 'Relevant' in 'SecAuditEngine RelevantOnly'

I'm not at all clear what you are hoping to achieve with your more recent posting. If you think you have an important use case that cannot be reasonably addressed using existing ModSecurity controls, please feel free to open a fresh issue. If you do so, please provide as much detail as possible as to the scenario being addressed and why other tools (such as the nolog and noauditlog actions) are insufficient.