Nginx + libmodsecurity + custom 403 page = no audit_log

[averges]

When I configure nginx to show a custom 403 page (without url redirect), modsecurity stops logging into audit_log.

Nginx 1.13.0
Modsecurity v3/master

Nginx config:

server {
       error_page 403 =403 /custom_403.php; <- No logs in audit_log 
       #error_page 403 =403 custom_403.php;  <- Logging OK

       location / {
             modsecurity on;
             modsecurity_rules_file modsecurity.conf;

             proxy_set_header Host $host;
             proxy_pass_header on;
             proxy_pass http://backend;
       }

       location /custom_403.php {
             client_max_body_size    10m;
             client_body_buffer_size 256k;

             include fastcgi_params;
             fastcgi_pass   php-fpm:9000;
             fastcgi_index custom_403.php;
             fastcgi_param  SCRIPT_FILENAME  /var/www/html/custom_403.php;
             fastcgi_intercept_errors on;
             fastcgi_buffer_size 128k;
             fastcgi_buffers 256 16k;
             fastcgi_busy_buffers_size 256k;
             fastcgi_temp_file_write_size 256k;
       }
}

[zimmerle]

HI @averges,

You may want to try to place the ModSecurity configurations in the server entry.

[averges]

Thanks @zimmerle,

If I place ModSecurity configurations in the server entry then error_page directive stops working and nginx shows their 403 default page.

server {
       error_page 403 /custom_403.php;

       modsecurity on;
       modsecurity_rules_file modsecurity.conf;

       location / {
             proxy_set_header Host $host;
             proxy_pass_header on;
             proxy_pass http://backend;
       }

       location /custom_403.php {
             client_max_body_size    10m;
             client_body_buffer_size 256k;

             include fastcgi_params;
             fastcgi_pass   php-fpm:9000;
             fastcgi_index custom_403.php;
             fastcgi_param  SCRIPT_FILENAME  /var/www/html/custom_403.php;
             fastcgi_intercept_errors on;
             fastcgi_buffer_size 128k;
             fastcgi_buffers 256 16k;
             fastcgi_busy_buffers_size 256k;
             fastcgi_temp_file_write_size 256k;
       }
}

[averges]

After some tests I see that requests with score >0 & < anomaly_score_threshold are logged correctly but denied requests (score > anomaly_score_threshold) aren't logged.

If it helps...

SecDefaultAction "phase:1,log,auditlog,pass"
SecDefaultAction "phase:2,log,auditlog,pass"

SecAuditEngine On
SecAuditEngine RelevantOnly
SecAuditLogRelevantStatus "^(?:5|4(?!04))"

Debug log

[4] Rule returned 0.
[4] Matched vars cleaned.
[4] (Rule: 943120) Executing operator "Rx" with param "^(jsessionid|aspsessionid|asp.net_sessionid|phpsession|phpsessid|weblogicsession|session_id|session-id|cfid|cftoken|cfsid|jservsession|jwsession)$" against ARGS_NAMES.
[6] Resolving: TX.0 to: UNION SELECT
[6] Resolving: MATCHED_VAR_NAME to: NULL
[6] Resolving: MATCHED_VAR to: NULL
[9]  T (0) t:urlDecodeUni: "SELECT 1,1,1,1,1 AND 1"
[9]  T (1) t:lowercase: "select 1,1,1,1,1 and 1"
[9] Target value: "select 1,1,1,1,1 and 1" (Variable: ARGS_NAMES)
[4] Rule returned 0.
[4] Matched vars cleaned.
[4] (Rule: 943014) Executing operator "Lt" with param "2" against TX:PARANOIA_LEVEL.
[9] Target value: "2" (Variable: TX:PARANOIA_LEVEL)
[4] Rule returned 0.
[4] Matched vars cleaned.
[4] (Rule: 943016) Executing operator "Lt" with param "3" against TX:PARANOIA_LEVEL.
[9] Target value: "2" (Variable: TX:PARANOIA_LEVEL)
[4] Matched vars updated.
[4] Rule contains a `pass' action
[4] Rule returned 1.
[4] (SecDefaultAction) Running action: log
[9] Saving transaction to logs
[4] (SecDefaultAction) Running action: auditlog
[4] (SecDefaultAction) Running action: pass (rule _does not_ contains a disruptive action)
[8] Running action pass
[4] Running [I] (_non_ disruptive) action: nolog
[4] Running (disruptive) action: pass
[8] Running action pass
[4] Running [I] (_non_ disruptive) action: skipAfter
[5] Setting skipAfter for: END-REQUEST-943-APPLICATION-ATTACK-SESSION-FIXATION
[9] Skipped rule id '943018' due to a SecMarker: END-REQUEST-943-APPLICATION-ATTACK-SESSION-FIXATION
[9] Rule: 
[9] Skipped rule id '0' due to a SecMarker: END-REQUEST-943-APPLICATION-ATTACK-SESSION-FIXATION
[9] Rule: END-REQUEST-943-APPLICATION-ATTACK-SESSION-FIXATION
[4] Out of a SecMarker after skip 2.000000 rules.
[4] (Rule: 949100) Executing operator "Eq" with param "1" against IP.
[6] Resolving: ip.reput_block_reason to: NULL
[4] Rule returned 0.
[4] Matched vars cleaned.
[6] Resolving: tx.inbound_anomaly_score_threshold to: 20
[4] (Rule: 949110) Executing operator "Ge" with param "20" Was: "%{tx.inbound_anomaly_score_threshold}" against TX:ANOMALY_SCORE.
[6] Resolving: TX.ANOMALY_SCORE to: 30
[9] Target value: "30" (Variable: TX:ANOMALY_SCORE)
[6] Resolving: tx.inbound_anomaly_score_threshold to: 20
[4] Matched vars updated.
[4] Running [I] (_non_ disruptive) action: msg
[6] Resolving: TX.ANOMALY_SCORE to: 30
[9] Saving msg: Inbound Anomaly Score Exceeded (Total Score: 30)
[4] Running [I] (_non_ disruptive) action: log
[9] Saving transaction to logs
[4] Running [I] (_non_ disruptive) action: setvar
[6] Resolving: tx.msg to: SQL Injection Attack'
[8] Saving variable: TX:inbound_tx_msg with value: SQL Injection Attack'
[4] Running [I] (_non_ disruptive) action: setvar
[6] Resolving: tx.anomaly_score to: 30
[8] Saving variable: TX:inbound_anomaly_score with value: 30
[4] Rule returned 1.
[4] (SecDefaultAction) Running action: log
[9] Saving transaction to logs
[4] (SecDefaultAction) Running action: auditlog
[4] (SecDefaultAction) _ignoring_ action: pass (rule contains a disruptive action)
[4] Running [I] (_non_ disruptive) action: severity
[9] This rule severity is: 2 current transaction is: 2
[4] Running (disruptive) action: deny
[8] Running action deny
[4] Running [I] (_non_ disruptive) action: tag
[9] Rule tag: application-multi
[4] Running [I] (_non_ disruptive) action: tag
[9] Rule tag: language-multi
[4] Running [I] (_non_ disruptive) action: tag
[9] Rule tag: platform-multi
[4] Running [I] (_non_ disruptive) action: tag
[9] Rule tag: attack-generic
[8] Skipping this phase as this request was already intercepted.
[4] JSON: Cleaning up JSON results

[Roger-Man]

Hi
Same issue here.

Why is this issue closed?
The bug still persists....

Br

[zimmerle]

There is an issue on the nginx connector on the same subject: owasp-modsecurity/ModSecurity-nginx#55

[realpg]

same issue

[victorhora]

@realpg please follow up here: owasp-modsecurity/ModSecurity-nginx#76