Audit log no longer written since update to 3.0.14

Start with utils/shared_files.cc and AuditLog::init(), then trace the SharedFiles open and close calls shown in the diagnostic output. Reproduce the issue with the provided nginx configuration and a request that should create an audit entry. Done means the audit log remains writable and an audit log entry is produced without the “file is not open” error.

Hi!

After updating ModSecurity to version 3.0.14, the audit log files are no longer written.
With a debug log configured, I just see a
Cannot save the audit log: file is not open: ...
as error.

As far as my research goes, this has been introduced with the rewriting of utils/shared_files.cc in ModSecurity 3.0.13. Version 3.0.12 works like a charm with the same setup.

Logs and dumps

Excerpt from debug log:

[175005793234.240265] [] [4] Initializing transaction
[175005793234.240265] [] [4] Transaction context created.
[175005793234.240265] [] [4] Starting phase CONNECTION. (SecRules 0)
[175005793234.240265] [] [9] This phase consists of 27 rule(s).
[175005793234.240265] [] [4] Starting phase URI. (SecRules 0 + 1/2)
[175005793234.240265] [/foobar] [4] Starting phase REQUEST_HEADERS.  (SecRules 1)
...
[175005793234.240265] [/foobar] [9] Running action: noauditlog
[175005793234.240265] [/foobar] [4] Running (disruptive)     action: pass.
[175005793234.240265] [/foobar] [8] Running action pass
[175005793234.240265] [/foobar] [8] Checking if this request is suitable to be saved as an audit log.
[175005793234.240265] [/foobar] [8] Checking if this request is relevant to be part of the audit logs.
[175005793234.240265] [/foobar] [5] Saving this request as part of the audit logs.
[175005793234.240265] [/foobar] [1] Cannot save the audit log: file is not open: nginx-1-audit.log

Error logs says the same time:

2025-06-16T07:12:12.637Z ggd193 waf_6_1[10861]: 2025/06/16 07:12:12 [error] 10861#0: *1 [client 172.16.0.192] ModSecurity: Access denied with code 403 (phase 2). Matched "Operator `Ge' with parameter `5' against variable `TX:BLOCKING_INBOUND_ANOMALY_SCORE' (Value: `5' ) [file "/usr/local/share/crs/rules/REQUEST-949-BLOCKING-EVALUATION.conf"] [line "222"] [id "949110"] [rev ""] [msg "Inbound Anomaly Score Exceeded (Total Score: 5)"] [data ""] [severity "0"] [ver "OWASP_CRS/4.3.0"] [maturity "0"] [accuracy "0"] [tag "anomaly-evaluation"] [tag "OWASP_CRS"] [hostname "127.128.0.6"] [uri "/foobar"] [unique_id "175005793234.240265"] [ref ""], client: 172.16.0.192, server: www.foobar.de, request: "POST /foobar HTTP/1.1", host: "www.foobar.de"

Minimal nginx.conf I'm running to test this:

env TZ=UTC;
load_module "modules/ngx_http_modsecurity_module.so";
user __nginx __nginx;
worker_processes 1;
worker_rlimit_nofile 16000;
events { worker_connections 16000; }
http {
    error_log syslog:sendsyslog,facility=daemon,tag=waf_6,severity=info;

    map $time_iso8601 $time_iso8601_no_postfix {
        ~([^+]+) $1;
    }
    map $msec $millisec {
        ~\.([0-9]+)$ $1;
    }
    map $logtag $logtag {
        default 'waf_6';
    }
    log_format syslogified
        '$time_iso8601_no_postfix.$millisec' 'Z' ' $host '
        '$logtag[$pid]: $remote_addr - $remote_user '
        '"$request" $status $body_bytes_sent "$http_referer" '
        '"$http_user_agent" "$http_x_forwarded_for"';

    # Default 64 can be too low
    server_names_hash_bucket_size 128;

    server {
        set $logtag "waf_0_0";
        error_log syslog:sendsyslog,facility=daemon,tag=waf_0_0,severity=error;
        access_log syslog:sendsyslog,facility=daemon,tag=waf_0_0,severity=info syslogified;
        listen 127.128.0.6:12345 default_server;
        listen [::127.128.0.6]:12345 default_server;
        server_name _;
        
        return 403;
    }
    server {
        set $logtag "waf_6_1";
        error_log syslog:sendsyslog,facility=daemon,tag=waf_6_1,severity=error;
        access_log syslog:sendsyslog,facility=daemon,tag=waf_6_1,severity=info syslogified;
        listen 127.128.0.6:12345;
        listen [::127.128.0.6]:12345;
        server_name www.foobar.de;
        modsecurity on;
        
        # Additional options
        
        location / { # TEST
            proxy_pass http://127.0.0.1:12345;
            
            modsecurity_rules_file /etc/nginx/waf/modsecurity-Default_ModSecurity.conf;
            modsecurity_rules 'SecAuditLog /cage/nginx_waf/logs/6/nginx-1-audit.log';
            
            client_max_body_size 128m;

            # Additional options
            modsecurity_rules 'SecDebugLog /cage/nginx_waf/logs/6/nginx-1-debug.log';
            modsecurity_rules 'SecDebugLogLevel 9';
        }
    }
}

To Reproduce

Steps to reproduce the behavior:

Using the configuration from above and sending a request which would cause an audit log entry, only the error log message is written.
As far as I understand, a writer for the audit log is opened multiple times but then closed immediately again when in AuditLog::init() the old m_writer is removed.

Expected behavior

I would expect that also an audit log entry would be written as seen in the debug log.

Server (please complete the following information):

• ModSecurity version (and connector): ModSecurity 3.0.14 with nginx-connector v1.0.3
• WebServer: nginx-1.26.3
• OS (and distro): OpenBSD 7.7

Rule Set (please complete the following information):

• Running any public or commercial rule set? OWAP Core Rule Set
• What is the version number? 4.3.0

Additional context
I tried to debug the problem myself and added some output to understand whats going on:

# /usr/local/sbin/nginx -c nginx-WAF.conf -g "pid /var/run/nginx-waf-WAF.pid; daemon off; master_process off;" -p /cage/nginx_waf                                          
AuditLog::merge called   
AL_MERGE_STRING_CONF replace '' with '/tmp/dummy_audit_log_for_syntax_check'
AL_MERGE_STRING_CONF replace '' with '^(?:5|4(?!04))'
AuditLog::init =>  New tmp_writer 0xb8ee402b990 for /tmp/dummy_audit_log_for_syntax_check
AuditLog::init =>  Initializing new writer 0xb8ee402b990
Serial::init => Init serial writer for /tmp/dummy_audit_log_for_syntax_check
SharedFiles::open => No handler for /tmp/dummy_audit_log_for_syntax_check found
SharedFiles::add_new_handler => Opened file /tmp/dummy_audit_log_for_syntax_check with FD 5
SharedFiles::open => Open file: /tmp/dummy_audit_log_for_syntax_check refcount=1
AuditLog::merge called
AL_MERGE_STRING_CONF replace '/tmp/dummy_audit_log_for_syntax_check' with 'nginx-1-audit.log'
AuditLog::init =>  New tmp_writer 0xb8ee402b220 for nginx-1-audit.log
AuditLog::init =>  Initializing new writer 0xb8ee402b220
Serial::init => Init serial writer for nginx-1-audit.log
SharedFiles::open => No handler for nginx-1-audit.log found
SharedFiles::add_new_handler => Opened file nginx-1-audit.log with FD 6
SharedFiles::open => Open file: nginx-1-audit.log refcount=1
AuditLog::init =>  Removing old writer 0xb8ee402b990 for nginx-1-audit.log
Serial::~Serial => destructor called for nginx-1-audit.log
SharedFiles::close =>  SharedFiles::close: file nginx-1-audit.log refcount=0
SharedFiles::close =>  Closing file: nginx-1-audit.log with FD 6
SharedFiles::open => No handler for nginx-1-debug.log found
SharedFiles::add_new_handler => Opened file nginx-1-debug.log with FD 6
SharedFiles::open => Open file: nginx-1-debug.log refcount=1
AuditLog::merge called
AuditLog::init =>  New tmp_writer 0xb8e9521df50 for nginx-1-audit.log
AuditLog::init =>  Initializing new writer 0xb8e9521df50
Serial::init => Init serial writer for nginx-1-audit.log
SharedFiles::open => No handler for nginx-1-audit.log found
SharedFiles::add_new_handler => Opened file nginx-1-audit.log with FD 7
SharedFiles::open => Open file: nginx-1-audit.log refcount=1
AuditLog::init =>  Removing old writer 0xb8ee402b220 for nginx-1-audit.log
Serial::~Serial => destructor called for nginx-1-audit.log
SharedFiles::close =>  SharedFiles::close: file nginx-1-audit.log refcount=0
SharedFiles::close =>  Closing file: nginx-1-audit.log with FD 7
SharedFiles::open => Open file: nginx-1-debug.log refcount=2
SharedFiles::close =>  SharedFiles::close: file nginx-1-debug.log refcount=1
AuditLog::merge called
AuditLog::init =>  New tmp_writer 0xb8ee402b1a0 for nginx-1-audit.log
AuditLog::init =>  Initializing new writer 0xb8ee402b1a0
Serial::init => Init serial writer for nginx-1-audit.log
SharedFiles::open => No handler for nginx-1-audit.log found
SharedFiles::add_new_handler => Opened file nginx-1-audit.log with FD 7
SharedFiles::open => Open file: nginx-1-audit.log refcount=1
AuditLog::init =>  Removing old writer 0xb8e9521df50 for nginx-1-audit.log
Serial::~Serial => destructor called for nginx-1-audit.log
SharedFiles::close =>  SharedFiles::close: file nginx-1-audit.log refcount=0
SharedFiles::close =>  Closing file: nginx-1-audit.log with FD 7
AuditLog::merge called
AuditLog::merge called
AuditLog::merge called
AuditLog::init =>  New tmp_writer 0xb8e8e999570 for nginx-1-audit.log
AuditLog::init =>  Initializing new writer 0xb8e8e999570
Serial::init => Init serial writer for nginx-1-audit.log
SharedFiles::open => No handler for nginx-1-audit.log found
SharedFiles::add_new_handler => Opened file nginx-1-audit.log with FD 7
SharedFiles::open => Open file: nginx-1-audit.log refcount=1
AuditLog::init =>  Removing old writer 0xb8ee402b1a0 for nginx-1-audit.log
Serial::~Serial => destructor called for nginx-1-audit.log
SharedFiles::close =>  SharedFiles::close: file nginx-1-audit.log refcount=0
SharedFiles::close =>  Closing file: nginx-1-audit.log with FD 7
SharedFiles::write =>  Write to file: nginx-1-debug.log

As you can see, FD 7 is openend and immediately closed again, ending in no open writer for the audit log.
Furthermore FD 5 imo leaks, as it is openend for /tmp/dummy_audit_log_for_syntax_check but never closed as the file name on the dummy audit log is replaced with the real name and thus the old writer for FD5 can no longer be found in the unordered map in SharedFiles.