feat(dynamic_log_level): support timeout for dynamic log level

Co-authored-by: Murillo <103451714+gruceo@users.noreply.github.com> Co-authored-by: Chrono <chrono_cpp@me.com>
Kong · Apr 27, 2023 · d52bddc · d52bddc
1 parent a6bc93a
commit d52bddc
Show file tree

Hide file tree

Showing 11 changed files with 406 additions and 38 deletions.
diff --git a/.requirements b/.requirements
@@ -12,5 +12,5 @@ RESTY_WEBSOCKET_VERSION=0.4.0
 ATC_ROUTER_VERSION=1.0.5
 LIBYAML_VERSION=0.2.5
 KONG_BUILD_TOOLS_VERSION=4.42.0
-KONG_NGINX_MODULE_BRANCH=0.5.1
+KONG_NGINX_MODULE_BRANCH=0.6.0
 DOCKER_KONG_VERSION=3.0.0
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -52,6 +52,8 @@
   [#10355](https://github.com/Kong/kong/pull/10355)
 - Tracing: rename spans to simplify filtering on tracing backends.
   [#10577](https://github.com/Kong/kong/pull/10577)
+- Support timeout for dynamic log level
+  [#10288](https://github.com/Kong/kong/pull/10288)
 
 #### Admin API
 

diff --git a/autodoc/admin-api/data/admin-api.lua b/autodoc/admin-api/data/admin-api.lua
@@ -737,6 +737,14 @@ return {
           description = [[
             Change the log level of a node.
 
+            #### Request Querystring Parameters
+
+            Attributes | Description
+            ---:| ---
+            `timeout`<br>*optional* | The timeout for dynamic log_level, after that, the log level will be reset to the
+            default `log_level` setting from Nginx configuration immediately. If it is set to `0`, the dynamic log_level
+            will expire immediately. Defaults to `60`.
+
             See http://nginx.org/en/docs/ngx_core_module.html#error_log for a
             list of accepted values.
 
@@ -775,6 +783,14 @@ return {
           description = [[
             Change the log level of all nodes in a cluster.
 
+            #### Request Querystring Parameters
+
+            Attributes | Description
+            ---:| ---
+            `timeout`<br>*optional* | The timeout for dynamic log_level, after that, the log level will be reset to the
+            default `log_level` setting from Nginx configuration immediately. If it is set to `0`, the dynamic log_level
+            will expire immediately. Defaults to `60`.
+
             See http://nginx.org/en/docs/ngx_core_module.html#error_log for a
             list of accepted values.
 
@@ -821,6 +837,14 @@ return {
             Change the log level of all Control Plane nodes deployed in Hybrid
             (CP/DP) cluster.
 
+            #### Request Querystring Parameters
+
+            Attributes | Description
+            ---:| ---
+            `timeout`<br>*optional* | The timeout for dynamic log_level, after that, the log level will be reset to the
+            default `log_level` setting from Nginx configuration immediately. If it is set to `0`, the dynamic log_level
+            will expire immediately. Defaults to `60`.
+
             See http://nginx.org/en/docs/ngx_core_module.html#error_log for a
             list of accepted values.
 

diff --git a/build/openresty/patches/nginx-1.21.4_06-dynamic_log_level.patch b/build/openresty/patches/nginx-1.21.4_06-dynamic_log_level.patch
@@ -0,0 +1,133 @@
+diff --git a/bundle/nginx-1.21.4/src/core/ngx_log.c b/bundle/nginx-1.21.4/src/core/ngx_log.c
+index eb7a989..0862d4d 100644
+--- a/bundle/nginx-1.21.4/src/core/ngx_log.c
++++ b/bundle/nginx-1.21.4/src/core/ngx_log.c
+@@ -171,8 +171,12 @@ ngx_log_error_core(ngx_uint_t level, ngx_log_t *log, ngx_err_t err,
+     debug_connection = (log->log_level & NGX_LOG_DEBUG_CONNECTION) != 0;
+
+     while (log) {
+-
++#if (NGX_HTTP_LUA_KONG)
++        if (ngx_http_lua_kong_get_dynamic_log_level(log->log_level) < level &&
++            !debug_connection) {
++#else
+         if (log->log_level < level && !debug_connection) {
++#endif
+             break;
+         }
+
+@@ -230,7 +234,11 @@ ngx_log_error(ngx_uint_t level, ngx_log_t *log, ngx_err_t err,
+ {
+     va_list  args;
+
++#if (NGX_HTTP_LUA_KONG)
++    if (ngx_http_lua_kong_get_dynamic_log_level(log->log_level) >= level) {
++#else
+     if (log->log_level >= level) {
++#endif
+         va_start(args, fmt);
+         ngx_log_error_core(level, log, err, fmt, args);
+         va_end(args);
+diff --git a/bundle/nginx-1.21.4/src/core/ngx_log.h b/bundle/nginx-1.21.4/src/core/ngx_log.h
+index da81cf0..8fd3348 100644
+--- a/bundle/nginx-1.21.4/src/core/ngx_log.h
++++ b/bundle/nginx-1.21.4/src/core/ngx_log.h
+@@ -72,6 +72,13 @@ struct ngx_log_s {
+     ngx_log_t           *next;
+ };
+
++#if (NGX_HTTP_LUA_KONG)
++ngx_uint_t
++ngx_http_lua_kong_get_dynamic_log_level(ngx_uint_t current_log_level);
++#else
++#define ngx_http_lua_kong_get_dynamic_log_level(expr) (expr)
++#endif
++
+
+ #ifndef NGX_MAX_ERROR_STR
+ #define NGX_MAX_ERROR_STR   4096
+@@ -85,13 +92,13 @@ struct ngx_log_s {
+ #define NGX_HAVE_VARIADIC_MACROS  1
+
+ #define ngx_log_error(level, log, ...)                                        \
+-    if ((log)->log_level >= level) ngx_log_error_core(level, log, __VA_ARGS__)
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) >= level) ngx_log_error_core(level, log, __VA_ARGS__)
+
+ void ngx_log_error_core(ngx_uint_t level, ngx_log_t *log, ngx_err_t err,
+     const char *fmt, ...);
+
+ #define ngx_log_debug(level, log, ...)                                        \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_error_core(NGX_LOG_DEBUG, log, __VA_ARGS__)
+
+ /*********************************/
+@@ -101,13 +108,13 @@ void ngx_log_error_core(ngx_uint_t level, ngx_log_t *log, ngx_err_t err,
+ #define NGX_HAVE_VARIADIC_MACROS  1
+
+ #define ngx_log_error(level, log, args...)                                    \
+-    if ((log)->log_level >= level) ngx_log_error_core(level, log, args)
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) >= level) ngx_log_error_core(level, log, args)
+
+ void ngx_log_error_core(ngx_uint_t level, ngx_log_t *log, ngx_err_t err,
+     const char *fmt, ...);
+
+ #define ngx_log_debug(level, log, args...)                                    \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level) ngx_log_error_core(level, log, args)
+         ngx_log_error_core(NGX_LOG_DEBUG, log, args)
+
+ /*********************************/
+@@ -170,43 +177,43 @@ void ngx_cdecl ngx_log_debug_core(ngx_log_t *log, ngx_err_t err,
+ #else /* no variadic macros */
+
+ #define ngx_log_debug0(level, log, err, fmt)                                  \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt)
+
+ #define ngx_log_debug1(level, log, err, fmt, arg1)                            \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt, arg1)
+
+ #define ngx_log_debug2(level, log, err, fmt, arg1, arg2)                      \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt, arg1, arg2)
+
+ #define ngx_log_debug3(level, log, err, fmt, arg1, arg2, arg3)                \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt, arg1, arg2, arg3)
+
+ #define ngx_log_debug4(level, log, err, fmt, arg1, arg2, arg3, arg4)          \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt, arg1, arg2, arg3, arg4)
+
+ #define ngx_log_debug5(level, log, err, fmt, arg1, arg2, arg3, arg4, arg5)    \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt, arg1, arg2, arg3, arg4, arg5)
+
+ #define ngx_log_debug6(level, log, err, fmt,                                  \
+                        arg1, arg2, arg3, arg4, arg5, arg6)                    \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt, arg1, arg2, arg3, arg4, arg5, arg6)
+
+ #define ngx_log_debug7(level, log, err, fmt,                                  \
+                        arg1, arg2, arg3, arg4, arg5, arg6, arg7)              \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt,                                     \
+                        arg1, arg2, arg3, arg4, arg5, arg6, arg7)
+
+ #define ngx_log_debug8(level, log, err, fmt,                                  \
+                        arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8)        \
+-    if ((log)->log_level & level)                                             \
++    if (ngx_http_lua_kong_get_dynamic_log_level((log)->log_level) & level)    \
+         ngx_log_debug_core(log, err, fmt,                                     \
+                        arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8)
+
diff --git a/build/openresty/patches/ngx_lua-0.10.21_07-dynamic_log_level.patch b/build/openresty/patches/ngx_lua-0.10.21_07-dynamic_log_level.patch
@@ -0,0 +1,29 @@
+diff --git a/bundle/ngx_lua-0.10.21/src/ngx_http_lua_log.c b/bundle/ngx_lua-0.10.21/src/ngx_http_lua_log.c
+index 43ab820..d18fd05 100644
+--- a/bundle/ngx_lua-0.10.21/src/ngx_http_lua_log.c
++++ b/bundle/ngx_lua-0.10.21/src/ngx_http_lua_log.c
+@@ -101,7 +101,11 @@ log_wrapper(ngx_log_t *log, const char *ident, ngx_uint_t level,
+     const char          *msg;
+     lua_Debug            ar;
+
++#if (NGX_HTTP_LUA_KONG)
++    if (level > ngx_http_lua_kong_get_dynamic_log_level(log->log_level)) {
++#else
+     if (level > log->log_level) {
++#endif
+         return 0;
+     }
+
+@@ -427,7 +431,12 @@ ngx_http_lua_ffi_errlog_get_sys_filter_level(ngx_http_request_t *r)
+         log = ngx_cycle->log;
+     }
+
++#if (NGX_HTTP_LUA_KONG)
++    log_level = ngx_http_lua_kong_get_dynamic_log_level(log->log_level);
++#else
+     log_level = log->log_level;
++#endif
++
+     if (log_level == NGX_LOG_DEBUG_ALL) {
+         log_level = NGX_LOG_DEBUG;
+     }
diff --git a/kong/api/routes/debug.lua b/kong/api/routes/debug.lua
@@ -1,16 +1,23 @@
-local get_sys_filter_level = require("ngx.errlog").get_sys_filter_level
-local set_log_level = require("resty.kong.log").set_log_level
+local set_log_level                = require("resty.kong.log").set_log_level
+local cjson                        = require("cjson.safe")
+local constants                    = require("kong.constants")
 
-local LOG_LEVELS = require("kong.constants").LOG_LEVELS
+local LOG_LEVELS                   = constants.LOG_LEVELS
+local DYN_LOG_LEVEL_KEY            = constants.DYN_LOG_LEVEL_KEY
+local DYN_LOG_LEVEL_TIMEOUT_AT_KEY = constants.DYN_LOG_LEVEL_TIMEOUT_AT_KEY
 
-local ngx = ngx
-local kong = kong
-local pcall = pcall
-local type = type
-local tostring = tostring
+local ngx                          = ngx
+local kong                         = kong
+local pcall                        = pcall
+local type                         = type
+local tostring                     = tostring
+
+local get_log_level                = require("resty.kong.log").get_log_level
+
+local NODE_LEVEL_BROADCAST         = false
+local CLUSTER_LEVEL_BROADCAST      = true
+local DEFAULT_LOG_LEVEL_TIMEOUT    = 60 -- 60s
 
-local NODE_LEVEL_BROADCAST = false
-local CLUSTER_LEVEL_BROADCAST = true
 
 local function handle_put_log_level(self, broadcast)
   if kong.configuration.database == "off" then
@@ -19,27 +26,37 @@ local function handle_put_log_level(self, broadcast)
   end
 
   local log_level = LOG_LEVELS[self.params.log_level]
+  local timeout = math.ceil(tonumber(self.params.timeout) or DEFAULT_LOG_LEVEL_TIMEOUT)
 
   if type(log_level) ~= "number" then
     return kong.response.exit(400, { message = "unknown log level: " .. self.params.log_level })
   end
 
-  local sys_filter_level = get_sys_filter_level()
+  if timeout < 0 then
+    return kong.response.exit(400, { message = "timeout must be greater than or equal to 0" })
+  end
+
+  local cur_log_level = get_log_level(LOG_LEVELS[kong.configuration.log_level])
 
-  if sys_filter_level == log_level then
+  if cur_log_level == log_level then
     local message = "log level is already " .. self.params.log_level
     return kong.response.exit(200, { message = message })
   end
 
-  local ok, err = pcall(set_log_level, log_level)
+  local ok, err = pcall(set_log_level, log_level, timeout)
 
   if not ok then
     local message = "failed setting log level: " .. err
     return kong.response.exit(500, { message = message })
   end
 
+  local data = {
+    log_level = log_level,
+    timeout = timeout,
+  }
+
   -- broadcast to all workers in a node
-  ok, err = kong.worker_events.post("debug", "log_level", log_level)
+  ok, err = kong.worker_events.post("debug", "log_level", data)
 
   if not ok then
     local message = "failed broadcasting to workers: " .. err
@@ -48,7 +65,7 @@ local function handle_put_log_level(self, broadcast)
 
   if broadcast then
     -- broadcast to all nodes in a cluster
-    ok, err = kong.cluster_events:broadcast("log_level", tostring(log_level))
+    ok, err = kong.cluster_events:broadcast("log_level", cjson.encode(data))
 
     if not ok then
       local message = "failed broadcasting to cluster: " .. err
@@ -57,28 +74,35 @@ local function handle_put_log_level(self, broadcast)
   end
 
   -- store in shm so that newly spawned workers can update their log levels
-  ok, err = ngx.shared.kong:set("kong:log_level", log_level)
+  ok, err = ngx.shared.kong:set(DYN_LOG_LEVEL_KEY, log_level, timeout)
 
   if not ok then
     local message = "failed storing log level in shm: " .. err
     return kong.response.exit(500, { message = message })
   end
 
+  ok, err = ngx.shared.kong:set(DYN_LOG_LEVEL_TIMEOUT_AT_KEY, ngx.time() + timeout, timeout)
+
+  if not ok then
+    local message = "failed storing the timeout of log level in shm: " .. err
+    return kong.response.exit(500, { message = message })
+  end
+
   return kong.response.exit(200, { message = "log level changed" })
 end
 
+
 local routes = {
   ["/debug/node/log-level"] = {
     GET = function(self)
-      local sys_filter_level = get_sys_filter_level()
-      local cur_level = LOG_LEVELS[sys_filter_level]
+      local cur_level = get_log_level(LOG_LEVELS[kong.configuration.log_level])
 
-      if type(cur_level) ~= "string" then
-        local message = "unknown log level: " .. tostring(sys_filter_level)
+      if type(LOG_LEVELS[cur_level]) ~= "string" then
+        local message = "unknown log level: " .. tostring(cur_level)
         return kong.response.exit(500, { message = message })
       end
 
-      return kong.response.exit(200, { message = "log level: " .. cur_level })
+      return kong.response.exit(200, { message = "log level: " .. LOG_LEVELS[cur_level] })
     end,
   },
   ["/debug/node/log-level/:log_level"] = {
@@ -88,6 +112,7 @@ local routes = {
   },
 }
 
+
 local cluster_name
 
 if kong.configuration.role == "control_plane" then

diff --git a/kong/constants.lua b/kong/constants.lua
@@ -241,6 +241,9 @@ local constants = {
     [ngx.ALERT] = "alert",
     [ngx.EMERG] = "emerg",
   },
+
+  DYN_LOG_LEVEL_KEY = "kong:dyn_log_level",
+  DYN_LOG_LEVEL_TIMEOUT_AT_KEY = "kong:dyn_log_level_timeout_at",
 }
 
 for _, v in ipairs(constants.CLUSTERING_SYNC_STATUS) do

diff --git a/kong/init.lua b/kong/init.lua
@@ -89,6 +89,7 @@ local instrumentation = require "kong.tracing.instrumentation"
 local tablepool = require "tablepool"
 local table_new = require "table.new"
 local utils = require "kong.tools.utils"
+local constants = require "kong.constants"
 local get_ctx_table = require("resty.core.ctx").get_ctx_table
 
 
@@ -206,7 +207,8 @@ local reset_kong_shm
 do
   local preserve_keys = {
     "kong:node_id",
-    "kong:log_level",
+    constants.DYN_LOG_LEVEL_KEY,
+    constants.DYN_LOG_LEVEL_TIMEOUT_AT_KEY,
     "events:requests",
     "events:requests:http",
     "events:requests:https",