nginx LogLevel error not working for pass

[void-in]

Hi, again it is a pleasure to work with ModSecurity day in and out. So the patch in #116 is working as intended as far as deny is concerned. The code mentions that any disruptive action should be able to log with the log level error but the "pass" action which is classified at disruptive at https://github.com/SpiderLabs/ModSecurity/wiki/Reference-Manual-(v2.x)#pass is not logging when the log level is set to error. It only gets logged to the nginx error log when the log level is info.

An example rule:

SecRule SERVER_NAME "@streq example.com" "id:123456,phase:3,pass,capture,t:none,t:urlDecodeUni,msg:'Login',chain"
    SecRule REQUEST_URI "@beginsWith /myapp/login" "chain"
        SecRule REQUEST_BODY "login:usrnam=(.+?)&" "capture,t:none,t:urlDecodeUni,setvar:tx.username=%{TX.1},chain"
            SecRule RESPONSE_HEADERS:Location "@contains /successful" "logdata:'APPLICATION=example.com,ACTION=login,STATUS=valid,USERNAME=%{tx.username},IP_ADDRESS=%{remote_addr}'"

This rule will only gets logged to the nginx error log when the log level is info. With the log level set to error, only deny rules are logged while the above rule isn't.

Following are the version info:

nginx version: nginx/1.17.9
built by gcc 4.8.5 20150623 (Red Hat 4.8.5-39) (GCC)
built with LibreSSL 2.9.2
TLS SNI support enabled
configure arguments: --prefix=/usr/share/nginx --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib64/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --http-client-body-temp-path=/var/lib/nginx/tmp/client_body --http-proxy-temp-path=/var/lib/nginx/tmp/proxy --http-fastcgi-temp-path=/var/lib/nginx/tmp/fastcgi --http-uwsgi-temp-path=/var/lib/nginx/tmp/uwsgi --http-scgi-temp-path=/var/lib/nginx/tmp/scgi --pid-path=/run/nginx.pid --lock-path=/run/lock/subsys/nginx --user=nginx --group=nginx --with-http_ssl_module --with-http_v2_module --with-http_realip_module --with-stream_ssl_preread_module --with-http_addition_module --with-http_xslt_module=dynamic --with-http_image_filter_module=dynamic --with-http_sub_module --with-http_dav_module --with-http_flv_module --with-http_mp4_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_random_index_module --with-http_secure_link_module --with-http_degradation_module --with-http_slice_module --with-http_stub_status_module --with-http_perl_module=dynamic --with-http_auth_request_module --with-mail=dynamic --with-mail_ssl_module --with-pcre --with-pcre-jit --with-stream=dynamic --with-stream_ssl_module --with-google_perftools_module --with-debug --add-module=/opt/ModSecurity-nginx

Modsecurity-nginx version:

v1.0.1

[martinhsv]

Hi @void-in

Thanks for the observation.

I think in this case the current behaviour is probably what we want. The 'pass' action is widely used for rules of a more routine nature like: rules that remove other rules or targets, or rules that set variables, or simply enable certain body parsers. Universally logging all of that rule activity to nginx's error.log under the 'error' setting would probably result in excessive noise to that log for most users (not to mention being counter-intuitive when they are not 'errors' in any real sense).

I agree that the terminology is potentially a little confusing. The 'pass' action is formally classed as a 'disruptive action' ... but of course its effect is explicitly to not 'disrupt' transaction processing. In other words, 'disruptive action' may mean slightly different things depending on the context.

[void-in]

Thank you very much for the explanation @martinhsv

So just one thing more: what is the recommendation in the above case where the SecRule is used primarily for parsing the HTTP request and logging? Should a separate file be used for disruptive actions and logs at info level? The current behavior is to log it at info level but the info level produces a lot of unnecessary noise in the nginx error log such as client terminating sessions etc. In production, it produces a lot of I/O which we can avoid by moving towards a high log level.

There was a discussion a while back to make the log level configurable at the ModSecurity level. Is there any motivation to move towards that at the moment?

[martinhsv]

Hi @void-in ,

I believe that currently the most common thing to do is to have nginx's error log set to a more restrictive level like 'warn' (rather than, say, 'info') for exactly the reason you point out -- it's less noisy for a file that is typically more useful if it contains only more infrequent and more notable events. The audit log can then contain a larger set of messages.

Whether we move towards supporting user-configurability of the server-log-level at which ModSecurity logs ... that could be worth exploring. Likelihood and priority would depend at least in part on the level of interest in the community for such a feature. Thanks for raising it.

[void-in]

Thank you @martinhsv

Just for anyone who face the same issue, for the time being you can change the audit log level at https://github.com/SpiderLabs/ModSecurity-nginx/blob/b55a5778c539529ae1aa10ca49413771d52bb62e/src/ngx_http_modsecurity_log.c#L33 by changing the line from:

ngx_log_error(NGX_LOG_INFO, (ngx_log_t *)log, 0, "%s", msg);

to

ngx_log_error(NGX_LOG_WARN, (ngx_log_t *)log, 0, "%s", msg);

to log at warn level. I will study the code some more and see if I can make the option user configurable.