Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

reopen audit log on SIGUSR1 and SIGHUP #121

Open
suddenhead opened this issue Aug 6, 2018 · 30 comments · May be fixed by #198
Open

reopen audit log on SIGUSR1 and SIGHUP #121

suddenhead opened this issue Aug 6, 2018 · 30 comments · May be fixed by #198
Assignees
Labels
enhancement no-issue-activity nostale The label to apply when an issue is exempt from being marked stale

Comments

@suddenhead
Copy link

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

@ledzepp4eva
Copy link

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

@defanator
Copy link
Collaborator

@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?

@victorhora
Copy link
Contributor

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 :)

@suddenhead
Copy link
Author

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

@defanator
Copy link
Collaborator

@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
Copy link
Collaborator

@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.

@victorhora
Copy link
Contributor

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

I've created owasp-modsecurity/ModSecurity#1968 to track this feature in libModSecurity.

@deeztek
Copy link

deeztek commented Jun 4, 2019

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

logrotate_script: 2: logrotate_script: copytruncate: not found

@mhoran
Copy link

mhoran commented Jun 4, 2019

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.

@deeztek
Copy link

deeztek commented Jun 4, 2019

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?

@github-actions
Copy link

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 github-actions bot added the stale label Jan 29, 2020
@zimmerle zimmerle removed the stale label Jan 29, 2020
@stuntsman
Copy link

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.

@github-actions
Copy link

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 github-actions bot added the stale label Feb 29, 2020
@mhoran
Copy link

mhoran commented Mar 1, 2020

This is still an issue.

@zimmerle zimmerle removed the stale label Mar 2, 2020
@github-actions
Copy link

github-actions bot commented Apr 2, 2020

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 github-actions bot added the stale label Apr 2, 2020
@mhoran
Copy link

mhoran commented Apr 2, 2020

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

@victorhora victorhora added nostale The label to apply when an issue is exempt from being marked stale and removed stale labels Apr 7, 2020
@victorhora
Copy link
Contributor

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

@brandonpayton brandonpayton linked a pull request May 1, 2020 that will close this issue
@github-actions
Copy link

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

@mhoran
Copy link

mhoran commented Jul 25, 2020

This should stay open until #198 is merged.

@mmelo-yottaa
Copy link

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

@zimmerle
Copy link
Contributor

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 owasp-modsecurity/ModSecurity#2304.

@mmelo-yottaa
Copy link

ok thanks @zimmerle

@github-actions
Copy link

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

@pgassmann
Copy link

Still waiting for #198 to be merged. Which is blocked:

@zimmerle commented

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

@krizbaipeter
Copy link

/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...

@duckasylum
Copy link

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.

@mark4409
Copy link

mark4409 commented Nov 1, 2021

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.

@luigimolinaro
Copy link

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.

@luigifab
Copy link

luigifab commented Jul 5, 2022

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

@amsnek
Copy link

amsnek commented May 10, 2023

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)

osnyx added a commit to flyingcircusio/fc-nixos that referenced this issue Apr 4, 2024
Because modsecurity is not re-opening its logfile after rotation and continues to write into the same file descriptor, we need to use `copytruncate`.
Better handling of that situation is stuck upstream for several years. owasp-modsecurity/ModSecurity-nginx#121

We use the presence of `/var/log/modesc_*.log` as a heuristic for modsecurity being enabled, these files are now rotated with copytruncate.
All other nginx logs are still rotated by moving and reloading.
Note that, due to overlapping wildcard matches, this specific case got a higher logrotate match priority and needs an `ignoreduplicates`.

`copytruncate` is non-atomic and might loose some logs written between
copying and the truncation being done.

PL-132296
osnyx added a commit to flyingcircusio/fc-nixos that referenced this issue Apr 4, 2024
Because modsecurity is not re-opening its logfile after rotation and continues to write into the same file descriptor, we need to use `copytruncate`.
Better handling of that situation is stuck upstream for several years. owasp-modsecurity/ModSecurity-nginx#121

We use the presence of `/var/log/modesc_*.log` as a heuristic for modsecurity being enabled, these files are now rotated with copytruncate.
All other nginx logs are still rotated by moving and reloading.
Note that, due to overlapping wildcard matches, this specific case got a higher logrotate match priority and needs an `ignoreduplicates`.

`copytruncate` is non-atomic and might loose some logs written between
copying and the truncation being done.

PL-132296
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement no-issue-activity nostale The label to apply when an issue is exempt from being marked stale
Projects
None yet
Development

Successfully merging a pull request may close this issue.