diff src/core/ngx_log.c @ 9299:2706b60dc225 default tip

Core: error logging rate limiting. With this change, error logging to files can be rate-limited with the "rate=" parameter. The parameter specifies allowed log messages rate to a particular file (per worker), in messages per second (m/s). By default, "rate=1000m/s" is used. Rate limiting is implemented using the "leaky bucket" method, similarly to the limit_req module. Maximum burst size is set to the number of log messages per second for each severity level, so "error" messages are logged even if the rate limit is hit by "info" messages (but not vice versa). When the limit is reached for a particular level, the "too many log messages, limiting" message is logged at this level. If debug logging is enabled, either for the particular log file or for the particular connection, rate limiting is not used.
author Maxim Dounin <mdounin@mdounin.ru>
date Tue, 25 Jun 2024 22:58:56 +0300
parents 14770557be17
children
line wrap: on
line diff
--- a/src/core/ngx_log.c
+++ b/src/core/ngx_log.c
@@ -9,8 +9,9 @@
 #include <ngx_core.h>
 
 
+static ngx_int_t ngx_log_check_rate(ngx_log_t *log, ngx_uint_t level);
 static char *ngx_error_log(ngx_conf_t *cf, ngx_command_t *cmd, void *conf);
-static char *ngx_log_set_levels(ngx_conf_t *cf, ngx_log_t *log);
+static char *ngx_log_set_params(ngx_conf_t *cf, ngx_log_t *log);
 static void ngx_log_insert(ngx_log_t *log, ngx_log_t *new_log);
 
 
@@ -164,6 +165,12 @@ ngx_log_error_core(ngx_uint_t level, ngx
             break;
         }
 
+        if (log->limit && !debug_connection) {
+            if (ngx_log_check_rate(log, level) == NGX_BUSY) {
+                goto next;
+            }
+        }
+
         if (log->writer) {
             log->writer(log, level, errstr, p - errstr);
             goto next;
@@ -314,6 +321,69 @@ ngx_log_errno(u_char *buf, u_char *last,
 }
 
 
+static ngx_int_t
+ngx_log_check_rate(ngx_log_t *log, ngx_uint_t level)
+{
+    ngx_log_t          temp_log;
+    ngx_int_t          excess, changed, burst;
+    ngx_atomic_int_t   ms;
+    ngx_atomic_uint_t  now, last;
+
+    now = ngx_current_msec;
+
+    last = log->limit->last;
+    excess = log->limit->excess;
+
+    ms = (ngx_atomic_int_t) (now - last);
+
+    if (ms < -60000) {
+        ms = 1;
+
+    } else if (ms < 0) {
+        ms = 0;
+    }
+
+    changed = excess - log->limit->rate * ms / 1000 + 1000;
+
+    if (changed < 0) {
+        changed = 0;
+    }
+
+    burst = (log->log_level - level + 1) * log->limit->rate;
+
+    if (changed > burst) {
+        if (excess <= burst) {
+
+            ngx_atomic_fetch_add(&log->limit->excess, 1000);
+
+            /* log message to this log only */
+
+            temp_log = *log;
+            temp_log.connection = 0;
+            temp_log.handler = NULL;
+            temp_log.limit = NULL;
+            temp_log.next = NULL;
+
+            ngx_log_error(level, &temp_log, 0,
+                          "too many log messages, limiting");
+        }
+
+        return NGX_BUSY;
+    }
+
+    if (ms > 0
+        && ngx_atomic_cmp_set(&log->limit->last, last, now))
+    {
+        ngx_atomic_fetch_add(&log->limit->excess, changed - excess);
+
+    } else {
+        ngx_atomic_fetch_add(&log->limit->excess, 1000);
+    }
+
+    return NGX_OK;
+}
+
+
 ngx_log_t *
 ngx_log_init(u_char *prefix, u_char *error_log)
 {
@@ -598,7 +668,7 @@ ngx_log_set_log(ngx_conf_t *cf, ngx_log_
         }
     }
 
-    if (ngx_log_set_levels(cf, new_log) != NGX_CONF_OK) {
+    if (ngx_log_set_params(cf, new_log) != NGX_CONF_OK) {
         return NGX_CONF_ERROR;
     }
 
@@ -611,13 +681,17 @@ ngx_log_set_log(ngx_conf_t *cf, ngx_log_
 
 
 static char *
-ngx_log_set_levels(ngx_conf_t *cf, ngx_log_t *log)
+ngx_log_set_params(ngx_conf_t *cf, ngx_log_t *log)
 {
+    size_t       len;
+    ngx_int_t    rate;
     ngx_uint_t   i, n, d;
     ngx_str_t   *value;
 
     value = cf->args->elts;
 
+    rate = 1000;
+
     for (i = 2; i < cf->args->nelts; i++) {
 
         for (n = 1; n <= NGX_LOG_DEBUG; n++) {
@@ -649,8 +723,33 @@ ngx_log_set_levels(ngx_conf_t *cf, ngx_l
             }
         }
 
-        ngx_conf_log_error(NGX_LOG_EMERG, cf, 0,
-                           "invalid log level \"%V\"", &value[i]);
+        if (ngx_strncmp(value[i].data, "rate=", 5) == 0) {
+
+            len = value[i].len;
+
+            if (ngx_strncmp(value[i].data + len - 3, "m/s", 3) == 0) {
+                len -= 3;
+            }
+
+            rate = ngx_atoi(value[i].data + 5, len - 5);
+            if (rate < 0) {
+                ngx_conf_log_error(NGX_LOG_EMERG, cf, 0,
+                                   "invalid rate \"%V\"", &value[i]);
+                return NGX_CONF_ERROR;
+            }
+
+            continue;
+        }
+
+        if (log->log_level) {
+            ngx_conf_log_error(NGX_LOG_EMERG, cf, 0,
+                               "invalid parameter \"%V\"", &value[i]);
+
+        } else {
+             ngx_conf_log_error(NGX_LOG_EMERG, cf, 0,
+                                "invalid log level \"%V\"", &value[i]);
+        }
+
         return NGX_CONF_ERROR;
 
     next:
@@ -666,6 +765,17 @@ ngx_log_set_levels(ngx_conf_t *cf, ngx_l
         log->log_level = NGX_LOG_DEBUG_ALL;
     }
 
+    if (rate > 0
+        && log->log_level < NGX_LOG_DEBUG)
+    {
+        log->limit = ngx_pcalloc(cf->pool, sizeof(ngx_log_limit_t));
+        if (log->limit == NULL) {
+            return NGX_CONF_ERROR;
+        }
+
+        log->limit->rate = rate * 1000;
+    }
+
     return NGX_CONF_OK;
 }