Modsecurity: Audit Log does not have explanation of why request was blocked

[ChrisRovers]

My configuration :

nginx/1.11.6, libmodsecurity from current head of v3/master, modsecurity-nginx from current head of master, OWASP CRS v3.0.0.

Request:

curl -i --insecure 'https://localhost/?param="><script>alert(1);</script>'

Access log:

127.0.0.1 - - [28/Nov/2016:16:45:48 +0000] "GET /?param=\x22><script>alert(1);</script> HTTP/1.1" 403 162 "-" "curl/7.47.0"

Auditing configuration:

# -- Audit log configuration -------------------------------------------------

# Log the transactions that are marked by a rule, as well as those that
# trigger a server error (determined by a 5xx or 4xx, excluding 404,  
# level response status codes).
#
SecAuditEngine RelevantOnly
SecAuditLogRelevantStatus "^(?:5|4(?!04))"

# Log everything we know about a transaction.
SecAuditLogParts ABIJDEFHZ

# Use a single file for logging. This is much easier to look at, but
# assumes that you will use the audit log only ocassionally.
#
SecAuditLogDirMode 1733
SecAuditLogFileMode 0550
SecAuditLogType Concurrent
SecAuditLogStorageDir /var/log/nginx/securityaudit

And finally, the actual report in /var/log/nginx/securityaudit/20161128/20161128-1645

{
    "transaction": {
        "client_ip": "127.0.0.1",
        "time_stamp": "Mon Nov 28 16:45:48 2016",
        "server_id": "xxxx",
        "client_port": 52372,
        "host_ip": "127.0.0.1",
        "host_port": 443,
        "id": "148035154863.348139",
        "request": {
            "protocol": "GET",
            "http_version": 1.1,
            "uri": "/?param=\"><script>alert(1);</script>",
            "headers": {
                "REQUEST_HEADERS:Host": "localhost",
                "REQUEST_HEADERS:User-Agent": "curl/7.47.0",
                "REQUEST_HEADERS:Accept": "*/*"
            }
        },
        "response": {
            "http_code": 403,
            "headers": {
                "RESPONSE_HEADERS:Server": "nginx",
                "RESPONSE_HEADERS:Date": "Mon, 28 Nov 2016 16:45:48 GMT",
                "RESPONSE_HEADERS:Content-Length": "162",
                "RESPONSE_HEADERS:Content-Type": "text/html",
                "RESPONSE_HEADERS:Connection": "keep-alive"
            }
        },
        "producer": {
            "modsecurity": "ModSecurity v3.0.0-alpha (Linux)",
            "connector": "ModSecurity-nginx v0.1.1-beta",
            "secrules_engine": "Enabled",
            "components": [
                "OWASP_CRS/3.0.0\""
            ]
        },
        "messages": [

        ]
    }
}

This was clearly blocked by modsecurity (the same request without the script returns 200) but there is nothing in messages and I believe there should be. The error log is blank.

Any suggestions?

[ChrisRovers]

I note that I'm clearly using JSON format. I tried to set the format to Native with

 SecAuditLogFormat Native

From the documentation, but that doesn't seem to work (nginx -t shows an error in the config)

[ChrisRovers]

If I set SecAuditLogType Serial, I do get the Native log format in the serial log, but that also has the same issue :

root@proxy02-waftest:/var/log/nginx# more modsec_audit.log 
---yqqhP0VK---A--
[28/Nov/2016:22:11:26 +0000] 148037108618.056378 127.0.0.1 52464 127.0.0.1 443
---yqqhP0VK---B--
GET /?param="><script>alert(1);</script> HTTP/1.1
REQUEST_HEADERS:Host: localhost
REQUEST_HEADERS:User-Agent: curl/7.47.0
REQUEST_HEADERS:Accept: */*
---yqqhP0VK---D--
---yqqhP0VK---E--
---yqqhP0VK---F--
RESPONSE_HEADERS:Server: nginx
RESPONSE_HEADERS:Date: Mon, 28 Nov 2016 22:11:26 GMT
RESPONSE_HEADERS:Content-Length: 162
RESPONSE_HEADERS:Content-Type: text/html
RESPONSE_HEADERS:Connection: keep-alive
---yqqhP0VK---H--
---yqqhP0VK---I--
---yqqhP0VK---J--
---yqqhP0VK---K--
---yqqhP0VK---Z--

[defanator]

Hi @ChrisRovers, I've opened a similar one here: https://github.com/SpiderLabs/ModSecurity/issues/1268

For the error log, you may set "error_log" level to "info", this will bring more messages into nginx's error log from libmodsecurity.

[zimmerle]

Hi @ChrisRovers thank you for the report. I am currently working on a fix to this issue.

[theMiddleBlue]

Hi,

i've the same problem. I'm able to see all additional informations about blocked requests on error.log by setting error_log level to info, but it not contains the "data" informations :(

2016/12/04 15:46:19 [info] 14600#0: *140 [client 1.2.3.4] ModSecurity: Warning. detected XSS using libinjection. [file "/usr/local/openresty/nginx/conf/owasp-modsecurity-crs/rules/REQUEST-941-APPLICATION-ATTACK-XSS.conf"] [line "17"] [id "941100"] [rev "2"] [msg "XSS Attack Detected via libinjection"] **[data ""]** [severity "0"] [ver "OWASP_CRS/3.0.0"] [maturity "1"] [accuracy "9"] [hostname "93.38.16.245"] [uri "/"] [unique_id "148086637925.495090"], client: 1.2.3.4, server: bla.xy, request: "GET /?a=<script>alert(123);</script> HTTP/1.1", host: "bla.xy"

the "msg" is set in the error.log but not in the audit log (JSON). Unfortunately the data is empty.

-theMiddle

[ChrisRovers]

@zimmerle Any idea when this fix will be ready? Not trying to be a pain, just trying to schedule getting back to rules tuning

[zimmerle]

Fixed. 317808fe5488a17ef12464d6847bd43cc14ab4a7.

[ChrisRovers]

Thanks, that's great!