From 805251023965eed4c69286097ade34ec6f7b1ac6 Mon Sep 17 00:00:00 2001 From: Artur Date: Fri, 25 Mar 2022 11:42:07 +0100 Subject: [PATCH] Add variable for logging time and add examples how to use it to README --- README.md | 21 +++++++++++++++++++++ src/ngx_http_modsecurity_common.h | 1 + src/ngx_http_modsecurity_log.c | 3 +++ src/ngx_http_modsecurity_module.c | 22 ++++++++++++++++++++++ 4 files changed, 47 insertions(+) diff --git a/README.md b/README.md index 2026d53..c83090d 100644 --- a/README.md +++ b/README.md @@ -176,6 +176,27 @@ using the same unique identificator. String can contain variables. +# Format Variables +ModSecurity-nginx provide times variables for particular phases that you can uses in nginx *log_format*: + + *$modsecurity_req_headers_phase_time* + request headers processing time in seconds with a microseconds resolution; time elapsed for processing headers in first phase by ModSecurity + *$modsecurity_req_body_phase_time* + request body processing time in seconds with a microseconds resolution; time elapsed for processing request body in second phase by ModSecurity + *$modsecurity_resp_headers_phase_time* + resposnse headers processing time in seconds with a microseconds resolution; time elapsed for processing response headers in third phase by ModSecurity + *$modsecurity_resp_body_phase_time* + response body processing time in seconds with a microseconds resolution; time elapsed for processing response body in fourth phase by ModSecurity + *$modsecurity_logging_phase_time* + logging processing time in seconds with a microseconds resolution; time elapsed for processing logging in fifth phase by ModSecurity + +The following example show how to configure custom *log_format* with variables above and use them with custom *access.log*: + +```nginx + log_format format_modsecurity 'modsecurity_req_headers_phase_time: $modsecurity_req_headers_phase_time, modsecurity_req_body_phase_time: $modsecurity_req_body_phase_time, modsecurity_resp_headers_phase_time: $modsecurity_resp_headers_phase_time, modsecurity_resp_body_phase_time: $modsecurity_resp_body_phase_time, modsecurity_logging_phase_time: $modsecurity_logging_phase_time'; + + access_log /usr/local/nginx/logs/modsecurity.log format_modsecurity; +``` # Contributing diff --git a/src/ngx_http_modsecurity_common.h b/src/ngx_http_modsecurity_common.h index acd371c..dc3e5a8 100644 --- a/src/ngx_http_modsecurity_common.h +++ b/src/ngx_http_modsecurity_common.h @@ -103,6 +103,7 @@ typedef struct { ngx_msec_int_t req_body_phase_time; ngx_msec_int_t resp_headers_phase_time; ngx_msec_int_t resp_body_phase_time; + ngx_msec_int_t logging_phase_time; } ngx_http_modsecurity_ctx_t; diff --git a/src/ngx_http_modsecurity_log.c b/src/ngx_http_modsecurity_log.c index d713a65..3a62a12 100644 --- a/src/ngx_http_modsecurity_log.c +++ b/src/ngx_http_modsecurity_log.c @@ -71,11 +71,14 @@ ngx_http_modsecurity_log_handler(ngx_http_request_t *r) dd("already logged earlier"); return NGX_OK; } + struct timeval start_tv; + ngx_gettimeofday(&start_tv); dd("calling msc_process_logging for %p", ctx); old_pool = ngx_http_modsecurity_pcre_malloc_init(r->pool); msc_process_logging(ctx->modsec_transaction); ngx_http_modsecurity_pcre_malloc_done(old_pool); + ctx->logging_phase_time = ngx_http_modsecurity_compute_processing_time(start_tv); return NGX_OK; } diff --git a/src/ngx_http_modsecurity_module.c b/src/ngx_http_modsecurity_module.c index b53a812..da69ec3 100644 --- a/src/ngx_http_modsecurity_module.c +++ b/src/ngx_http_modsecurity_module.c @@ -41,6 +41,8 @@ static ngx_int_t ngx_http_modsecurity_resp_headers_phase_time(ngx_http_request_t ngx_http_variable_value_t *v, uintptr_t data); static ngx_int_t ngx_http_modsecurity_resp_body_phase_time(ngx_http_request_t *r, ngx_http_variable_value_t *v, uintptr_t data); +static ngx_int_t ngx_http_modsecurity_logging_phase_time(ngx_http_request_t *r, + ngx_http_variable_value_t *v, uintptr_t data); static ngx_int_t ngx_http_modsecurity_time_variable(ngx_http_request_t *r, ngx_http_variable_value_t *v, uintptr_t data, ngx_msec_int_t usec); @@ -283,6 +285,7 @@ ngx_http_modsecurity_create_ctx(ngx_http_request_t *r) ctx->req_body_phase_time = -1; ctx->resp_headers_phase_time = -1; ctx->resp_body_phase_time = -1; + ctx->logging_phase_time = -1; mmcf = ngx_http_get_module_main_conf(r, ngx_http_modsecurity_module); mcf = ngx_http_get_module_loc_conf(r, ngx_http_modsecurity_module); @@ -553,6 +556,10 @@ static ngx_http_variable_t ngx_http_modsecurity_vars[] = { ngx_http_modsecurity_resp_body_phase_time, 0, NGX_HTTP_VAR_NOCACHEABLE, 0 }, + { ngx_string("modsecurity_logging_phase_time"), NULL, + ngx_http_modsecurity_logging_phase_time, 0, + NGX_HTTP_VAR_NOCACHEABLE, 0 }, + ngx_http_null_variable }; @@ -897,6 +904,21 @@ ngx_http_modsecurity_resp_body_phase_time(ngx_http_request_t *r, return ngx_http_modsecurity_time_variable(r, v, data, ctx->resp_body_phase_time); } + +static ngx_int_t +ngx_http_modsecurity_logging_phase_time(ngx_http_request_t *r, + ngx_http_variable_value_t *v, uintptr_t data) +{ + ngx_http_modsecurity_ctx_t *ctx; + + ctx = ngx_http_get_module_ctx(r, ngx_http_modsecurity_module); + if (ctx == NULL) { + return NGX_ERROR; + } + return ngx_http_modsecurity_time_variable(r, v, data, ctx->logging_phase_time); +} + + static ngx_int_t ngx_http_modsecurity_time_variable(ngx_http_request_t *r, ngx_http_variable_value_t *v, uintptr_t data, ngx_msec_int_t usec)