ModSecurity-nginx icon indicating copy to clipboard operation
ModSecurity-nginx copied to clipboard

reopen audit log on SIGUSR1 and SIGHUP

Open suddenhead opened this issue 7 years ago • 30 comments

Modsecurity should reopen audit log on these two signals for proper logrotate operation.

suddenhead avatar Aug 06 '18 15:08 suddenhead

Sorry for hijacking this issue, but I didn't want to raise a duplicated issue as this sounds like the same problem we are having.

Seeing the same behaviour with

nginx/1.12.2
Libmodsecurity: v3/master

nginx configuration snippet

  modsecurity_rules '

  # RuleEngine toggle
  SecRuleEngine On

  # Body Access
  SecRequestBodyAccess On
  SecRequestBodyLimit 64107200

  SecRequestBodyNoFilesLimit 64000

  SecResponseBodyAccess On
  SecResponseBodyLimit 10000000

  SecUploadDir /tmp/

  # Log Directory
  SecAuditLog /var/log/nginx/modsec_audit.log
  SecAuditEngine RelevantOnly
  SecAuditLogRelevantStatus "^(?:5|4(?!04))"
  SecAuditLogParts ABIJDEFHZ
  SecAuditLogType Serial
  SecAuditLogFormat JSON
  SecAuditLogDirMode 0755
  SecAuditLogFileMode 0644

  # Paranoia Level
  SecAction "id:900000, phase:1, nolog, pass, t:none, setvar:tx.paranoia_level=3"

  # Whitelist

  # Inactive Rules

  # Applications

 ';

Using the default nginx logrotation script

/var/log/nginx/*.log {
        daily
        missingok
        rotate 14
        compress
        delaycompress
        notifempty
        create 640 nginx adm
        sharedscripts
        postrotate
                [ -f /var/run/nginx.pid ] && kill -USR1 `cat /var/run/nginx.pid`
        endscript
}

However despite the access log and error logs being rotated and nginx reload relasing the file handles on them this isn't the case for /var/log/nginx/modsec_audit.log

ledzepp4eva avatar Aug 07 '18 08:08 ledzepp4eva

@suddenhead @ledzepp4eva thanks for reporting this.

@zimmerle @victorhora do you think that having some interface between library and connectors to perform such kind of tasks worth to implement?

defanator avatar Aug 08 '18 11:08 defanator

Hey @defanator

Indeed I don't see such interface at shared_files. It might be interesting for sure, I'm curious if we could use a similar approach as this: https://forum.nginx.org/read.php?29,247488,247500#msg-247500

I'll let @zimmerle weight-in as well :)

victorhora avatar Aug 17 '18 14:08 victorhora

twimc, until it's fixed, workaround is to use 'copytruncate' option in logrotate

suddenhead avatar Sep 12 '18 11:09 suddenhead

@victorhora you can leverage approach described at https://forum.nginx.org/read.php?29,247488,247500#msg-247500 (i.e. use standard nginx API to open some stub-file with ngx_conf_open_file(), add required handler, and use it for detecting USR1 and HUP signals from master process) - the question is that libmodsecurity currently does not have an interface to initiate audit/debug log files reopening by connector's request, am I right?

defanator avatar Sep 12 '18 11:09 defanator

@victorhora @zimmerle just for the reference, here's a dirty PoC on how to catch SIGUSR1 in modsecurity connector, code diff:

diff --git a/src/ngx_http_modsecurity_common.h b/src/ngx_http_modsecurity_common.h
index 79355d1..2510c31 100644
--- a/src/ngx_http_modsecurity_common.h
+++ b/src/ngx_http_modsecurity_common.h
@@ -97,6 +97,7 @@ typedef struct {
     void *pool;
 
     ngx_http_complex_value_t  *transaction_id;
+    ngx_open_file_t           *logfile;
 } ngx_http_modsecurity_conf_t;
 
 
diff --git a/src/ngx_http_modsecurity_module.c b/src/ngx_http_modsecurity_module.c
index d00d813..1d90a45 100644
--- a/src/ngx_http_modsecurity_module.c
+++ b/src/ngx_http_modsecurity_module.c
@@ -31,6 +31,7 @@ static char *ngx_http_modsecurity_merge_loc_conf(ngx_conf_t *cf, void *parent, v
 static char *ngx_http_modsecurity_merge_srv_conf(ngx_conf_t *cf, void *parent, void *child);
 static void ngx_http_modsecurity_config_cleanup(void *data);
 static char *ngx_http_modsecurity_init_main_conf(ngx_conf_t *cf, void *conf);
+static void ngx_http_modsecurity_log_flush(ngx_open_file_t *file, ngx_log_t *log);
 
 
 /*
@@ -606,6 +607,7 @@ static void *ngx_http_modsecurity_create_conf(ngx_conf_t *cf)
      *     conf->rules_set = NULL;
      *     conf->pool = NULL;
      *     conf->transaction_id = NULL;
+     *     conf->logfile = NULL;
      */
 
     conf->enable = NGX_CONF_UNSET;
@@ -622,10 +624,30 @@ static void *ngx_http_modsecurity_create_conf(ngx_conf_t *cf)
     cln->handler = ngx_http_modsecurity_config_cleanup;
     cln->data = conf;
 
+    /* this should be configurable ideally; also, maybe unlinking a file after opening would be nice */
+    ngx_str_t logfile = ngx_string("/var/run/modsec-stub-log-for-handling-usr1");
+
+    conf->logfile = ngx_conf_open_file(cf->cycle, &logfile);
+    if (conf->logfile == NULL) {
+        return NGX_CONF_ERROR;
+    }
+
+    conf->logfile->flush = ngx_http_modsecurity_log_flush;
+
     return conf;
 }
 
 
+static void
+ngx_http_modsecurity_log_flush(ngx_open_file_t *file, ngx_log_t *log)
+{
+    ngx_log_debug0(NGX_LOG_DEBUG_EVENT, log, 0,
+                   "modsecurity log buffer flush");
+
+    /* library call to reopen audit/debug logs should be here */
+}
+
+
 static char *
 ngx_http_modsecurity_merge_srv_conf(ngx_conf_t *cf, void *parent, void *child)
 {

Logs after sending SIGUSR1 to master process:

2018/11/28 03:32:32 [notice] 32059#32059: signal 10 (SIGUSR1) received from 31892, reopening logs
2018/11/28 03:32:32 [debug] 32059#32059: wake up, sigio 0
2018/11/28 03:32:32 [notice] 32059#32059: reopening logs
2018/11/28 03:32:32 [debug] 32059#32059: reopen file "/var/log/nginx/error.log", old:4 new:14
2018/11/28 03:32:32 [debug] 32059#32059: modsecurity log buffer flush
2018/11/28 03:32:32 [debug] 32059#32059: reopen file "/var/run/modsec-stub-log-for-handling-usr1", old:8 new:4
2018/11/28 03:32:32 [debug] 32059#32059: child: 0 32060 e:0 t:0 d:0 r:1 j:0
2018/11/28 03:32:32 [debug] 32059#32059: child: 1 32061 e:0 t:0 d:0 r:1 j:0
2018/11/28 03:32:32 [debug] 32059#32059: sigsuspend
2018/11/28 03:32:32 [debug] 32061#32061: epoll: fd:13 ev:0001 d:00007F89AF74F200
2018/11/28 03:32:32 [debug] 32061#32061: channel handler
2018/11/28 03:32:32 [debug] 32061#32061: channel: 32
2018/11/28 03:32:32 [debug] 32061#32061: channel command: 5
2018/11/28 03:32:32 [debug] 32061#32061: channel: -2
2018/11/28 03:32:32 [debug] 32061#32061: timer delta: 24815
2018/11/28 03:32:32 [notice] 32061#32061: reopening logs
2018/11/28 03:32:32 [debug] 32061#32061: reopen file "/var/log/nginx/error.log", old:4 new:11
2018/11/28 03:32:32 [debug] 32061#32061: modsecurity log buffer flush
2018/11/28 03:32:32 [debug] 32061#32061: reopen file "/var/run/modsec-stub-log-for-handling-usr1", old:8 new:4
2018/11/28 03:32:32 [debug] 32061#32061: worker cycle
2018/11/28 03:32:32 [debug] 32061#32061: epoll timer: -1
2018/11/28 03:32:32 [debug] 32060#32060: epoll: fd:11 ev:0001 d:00007F89AF74F200
2018/11/28 03:32:32 [debug] 32060#32060: channel handler
2018/11/28 03:32:32 [debug] 32060#32060: channel: 32
2018/11/28 03:32:32 [debug] 32060#32060: channel command: 5
2018/11/28 03:32:32 [debug] 32060#32060: channel: -2
2018/11/28 03:32:32 [debug] 32060#32060: timer delta: 24499
2018/11/28 03:32:32 [notice] 32060#32060: reopening logs
2018/11/28 03:32:32 [debug] 32060#32060: reopen file "/var/log/nginx/error.log", old:4 new:15
2018/11/28 03:32:32 [debug] 32060#32060: modsecurity log buffer flush
2018/11/28 03:32:32 [debug] 32060#32060: reopen file "/var/run/modsec-stub-log-for-handling-usr1", old:8 new:4
2018/11/28 03:32:32 [debug] 32060#32060: worker cycle
2018/11/28 03:32:32 [debug] 32060#32060: epoll timer: -1

Please note that ngx_http_modsecurity_log_flush() is called in every worker process.

defanator avatar Nov 28 '18 11:11 defanator

Thanks @defanator! We can try turning this PoC into a feature for the next release :)

I've created https://github.com/SpiderLabs/ModSecurity/issues/1968 to track this feature in libModSecurity.

victorhora avatar Nov 28 '18 21:11 victorhora

Tried adding the "copytruncate" option in the logrotation script but I got the following:

logrotate_script: 2: logrotate_script: copytruncate: not found

deeztek avatar Jun 04 '19 09:06 deeztek

While this is a fine workaround that I've employed myself, it's not the ideal solution for a couple of reasons. First, there's the possibility of losing logs between the copy and the truncate. It's a small chance, but possible -- and you might not want to lose your modsecurity audit logs. Second, not all systems have logrotate with copytruncate installed. For example, FreeBSD's newsyslog does not support copytruncate. I've had to install logrotate simply to rotate the modsecurity audit log.

mhoran avatar Jun 04 '19 13:06 mhoran

Ubuntu's logrotate doesn't seem to support copytruncate either it seems. Unless it has to be re-compiled with that option. So what's the solution?

deeztek avatar Jun 04 '19 13:06 deeztek

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 5 days

github-actions[bot] avatar Jan 29 '20 00:01 github-actions[bot]

We've just experienced a related issue: on our server modsec audit log events were logged into modsec_audit.log.1 instead of modsec_audit.log (until nginx restart).

I suspect modsec kept open the file handle during rename. Unfortunately this way logcheck wasn't able to alert us about security incidents as it was set to process the .log files only.

stuntsman avatar Jan 29 '20 13:01 stuntsman

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 5 days

github-actions[bot] avatar Feb 29 '20 00:02 github-actions[bot]

This is still an issue.

mhoran avatar Mar 01 '20 19:03 mhoran

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 5 days

github-actions[bot] avatar Apr 02 '20 00:04 github-actions[bot]

This is still an issue, but I can't remove the stale tag.

mhoran avatar Apr 02 '20 00:04 mhoran

@mhoran The "nostale" tag has been set for this one. We'll get to it when possible. Thank you.

victorhora avatar Apr 07 '20 20:04 victorhora

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 5 days

github-actions[bot] avatar Jul 25 '20 00:07 github-actions[bot]

This should stay open until #198 is merged.

mhoran avatar Jul 25 '20 01:07 mhoran

Any estimate when https://github.com/SpiderLabs/ModSecurity-nginx/pull/198 (and https://github.com/SpiderLabs/ModSecurity/pull/2304) might merge into master? we could definitely use this fix. thank you!!!

mmelo-yottaa avatar Jul 30 '20 17:07 mmelo-yottaa

Any estimate when #198 (and SpiderLabs/ModSecurity#2304) might merge into master? we could definitely use this fix. thank you!!!

Hey @mmelo-yottaa

Not yet. I would call that more a feature than a fix. It is in our queue.

It is likely to hit version v3.1. Notice that this is a coordinated effort that also adds new functionality to libModSecurity as stated at SpiderLabs/ModSecurity#2304.

zimmerle avatar Jul 30 '20 17:07 zimmerle

ok thanks @zimmerle

mmelo-yottaa avatar Jul 30 '20 18:07 mmelo-yottaa

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 5 days

github-actions[bot] avatar Aug 31 '20 00:08 github-actions[bot]

Still waiting for https://github.com/SpiderLabs/ModSecurity-nginx/pull/198 to be merged. Which is blocked:

@zimmerle commented

This patch depends on some changes on libModSecurity as stated at SpiderLabs/ModSecurity#2304; Without the changes in the linked issues, this is not functional. The review will be started as soon as we got SpiderLabs/ModSecurity#2304 merged.

pgassmann avatar Sep 01 '20 12:09 pgassmann

/var/log/nginx/*.log { daily missingok rotate 14 compress delaycompress notifempty create 640 nginx adm sharedscripts postrotate [ -f /var/run/nginx.pid ] && kill -USR1 cat /var/run/nginx.pid endscript }

Hi! Try logrotate with copytruncate option, without postrotate scritp. This is an alternative solution...

krizbaipeter avatar Apr 07 '21 14:04 krizbaipeter

I don't know how nginx does the signal handling, but I use nginx -s reopen in my postrotate scripts and this also suffers from the handles not switched over correctly error.

duckasylum avatar Apr 23 '21 09:04 duckasylum

reloading nginx doesn't appear to work but restarting does. If you're ok with this then:

postrotate if [ -f /var/run/nginx.pid ]; then /usr/sbin/service nginx restart fi

appears to work for me.

mark4409 avatar Nov 01 '21 07:11 mark4409

twimc, until it's fixed, workaround is to use 'copytruncate' option in logrotate

This is actually a good work-around but if you want to filbeat (or similar) to push logs to a remote logging system you are in trouble beacuse of inodes and how those system works.

luigimolinaro avatar Nov 03 '21 10:11 luigimolinaro

Some news? (to work without copytruncate and with the default nginx logrorate configuration file).

luigifab avatar Jul 05 '22 12:07 luigifab

If using filebeat i think the best solution would probably be to use "SecAuditLogType HTTPS" this can be send directly to a remote or localhost filebeat

SecAuditLogType HTTPS SecAuditLog http://127.0.0.1:80

with concurrent + filebeat -> performance issues (it doesnt seem to like large files)

amsnek avatar May 10 '23 10:05 amsnek