feat(request-id): introduce unique Request ID (#11663)

* feat(request-id): add Request ID * Add an immutable request ID * Include request ID + trace and correlation IDs to the log serializer * update Access log and Error log to append request id * update the error templates to include the request id * Bump lua-kong-nginx-module to version 0.7.1 * Use the new directive `lua_kong_error_log_request_id` introduced in 0.7.0 which adds the request id to the error log output Includes: * unit tests for the new `request_id` module * integration tests to check: * request id, correlation id, trace ids are added to log serializer * feat(request-id): add request-id to error templates * feat(request-id): request ID header + span attribute * add the x-kong-request-id downstream header which contains the value of the request_id, and can be controlled via the `headers` config option * add the x-kong-request-id upstream header which contains the value of the request_id, and can be controlled via the `headers_upstream` config option * add the `kong.request.id` span attribute which contains the value of the request_id * tests for all the above * docs(conf): request ID Co-authored-by: Enrique García Cota <kikito@gmail.com> * feat(request-id): address PR feedback * rephrase log messages * remove unneeded conditional * better changelog * use upvalues to cache headers access * use request id instead of kong_request_id (no longer needed as we don't need write access) * cache locals in hot path * improved performance of add_trace_id_formats function * refactored docs in kong.conf.default * perf: cache `request_id.get()` at the module level KAG-2034 FTI-4837 --------- Co-authored-by: samugi <samuele@konghq.com> Co-authored-by: Enrique García Cota <kikito@gmail.com> Co-authored-by: Qi <qiqi.zhang@konghq.com>
Kong · Nov 20, 2023 · ef7ec33 · ef7ec33
1 parent 07ef2cc
commit ef7ec33
Show file tree

Hide file tree

Showing 51 changed files with 1,457 additions and 197 deletions.
diff --git a/changelog/unreleased/kong/lua_kong_nginx_module_bump.yml b/changelog/unreleased/kong/lua_kong_nginx_module_bump.yml
@@ -0,0 +1,3 @@
+message: Bump lua-kong-nginx-module from 0.6.0 to 0.7.1
+type: dependency
+scope: Core
diff --git a/changelog/unreleased/kong/request_id.yml b/changelog/unreleased/kong/request_id.yml
@@ -0,0 +1,6 @@
+message: >
+  A unique Request ID is now populated in the error log, access log, error templates,
+  log serializer, and in a new X-Kong-Request-Id header (configurable for upstream/downstream
+  using the `headers` and `headers_upstream` configuration options). 
+type: feature
+scope: Core
diff --git a/kong-3.4.3-0.rockspec b/kong-3.4.3-0.rockspec
@@ -529,5 +529,6 @@ build = {
 
     ["kong.tracing.instrumentation"] = "kong/tracing/instrumentation.lua",
     ["kong.tracing.propagation"] = "kong/tracing/propagation.lua",
+    ["kong.tracing.request_id"] = "kong/tracing/request_id.lua",
   }
 }
diff --git a/kong.conf.default b/kong.conf.default
@@ -235,40 +235,52 @@
                                  # setting to specify a certificate authority.
 
 #error_template_html =           # Path to the custom html error template to
-                                 # override the default html kong error template.
-                                 #
-                                 # The template is required to contain one single `%s`
-                                 # placeholder for the error message, as in the
-                                 # following example:
+                                 # override the default html kong error
+                                 # template.
+                                 #
+                                 # The template may contain up to two `%s`
+                                 # placeholders. The first one will expand to
+                                 # the error message. The second one will
+                                 # expand to the request ID. Both placeholders
+                                 # are optional, but recommended.
+                                 # Adding more than two placeholders will
+                                 # result in a runtime error when trying to
+                                 # render the template:
                                  # ```
                                  # <html>
                                  #   <body>
                                  #     <h1>My custom error template</h1>
-                                 #     <p>%s.</p>
+                                 #     <p>error: %s</p>
+                                 #     <p>request_id: %s</p>
                                  #   </body>
                                  # </html>
                                  # ```
 
 #error_template_json =           # Path to the custom json error template to
-                                 # override the default json kong error template.
+                                 # override the default json kong error
+                                 # template.
                                  #
-                                 # Similarly to `error_template_html`, the template
-                                 # is required to contain one single `%s` placeholder for
-                                 # the error message.
+                                 # Similarly to `error_template_html`, the
+                                 # template may contain up to two `%s`
+                                 # placeholders for the error message and the
+                                 # request ID respectively.
 
 #error_template_xml =            # Path to the custom xml error template to
                                  # override the default xml kong error template
                                  #
-                                 # Similarly to `error_template_html`, the template
-                                 # is required to contain one single `%s` placeholder for
-                                 # the error message.
+                                 # Similarly to `error_template_html`, the
+                                 # template may contain up to two `%s`
+                                 # placeholders for the error message and the
+                                 # request ID respectively.
 
 #error_template_plain =          # Path to the custom plain error template to
-                                 # override the default plain kong error template
+                                 # override the default plain kong error
+                                 # template
                                  #
-                                 # Similarly to `error_template_html`, the template
-                                 # is required to contain one single `%s` placeholder for
-                                 # the error message.
+                                 # Similarly to `error_template_html`, the
+                                 # template may contain up to two `%s`
+                                 # placeholders for the error message and the
+                                 # request ID respectively.
 
 #------------------------------------------------------------------------------
 # HYBRID MODE
@@ -863,7 +875,7 @@
                                  #
                                  # See docs for `ssl_cert_key` for detailed usage.
 
-#headers = server_tokens, latency_tokens
+#headers = server_tokens, latency_tokens, X-Kong-Request-Id
                                  # Comma-separated list of headers Kong should
                                  # inject in client responses.
                                  #
@@ -893,6 +905,8 @@
                                  #   This is particularly useful for clients to
                                  #   distinguish upstream statuses if the
                                  #   response is rewritten by a plugin.
+                                 # - `X-Kong-Request-Id`: Unique identifier of
+                                 #   the request.
                                  # - `server_tokens`: Same as specifying both
                                  #   `Server` and `Via`.
                                  # - `latency_tokens`: Same as specifying
@@ -909,6 +923,20 @@
                                  #
                                  # Example: `headers = via, latency_tokens`
 
+#headers_upstream = X-Kong-Request-Id
+                                 # Comma-separated list of headers Kong should
+                                 # inject in requests to upstream.
+                                 #
+                                 # At this time, the only accepted value is:
+                                 # - `X-Kong-Request-Id`: Unique identifier of
+                                 #   the request.
+                                 #
+                                 # In addition, this value can be set
+                                 # to `off`, which prevents Kong from injecting
+                                 # the above header. Note that this
+                                 # does not prevent plugins from injecting
+                                 # headers of their own.
+
 #trusted_ips =                   # Defines trusted IP addresses blocks that are
                                  # known to send correct `X-Forwarded-*`
                                  # headers.

diff --git a/kong/conf_loader/init.lua b/kong/conf_loader/init.lua
@@ -153,6 +153,11 @@ local HEADER_KEY_TO_NAME = {
   [lower(HEADERS.ADMIN_LATENCY)] = HEADERS.ADMIN_LATENCY,
   [lower(HEADERS.UPSTREAM_LATENCY)] = HEADERS.UPSTREAM_LATENCY,
   [lower(HEADERS.UPSTREAM_STATUS)] = HEADERS.UPSTREAM_STATUS,
+  [lower(HEADERS.REQUEST_ID)] = HEADERS.REQUEST_ID,
+}
+
+local UPSTREAM_HEADER_KEY_TO_NAME = {
+  [lower(HEADERS.REQUEST_ID)] = HEADERS.REQUEST_ID,
 }
 
 
@@ -374,6 +379,7 @@ local CONF_PARSERS = {
   allow_debug_header = { typ = "boolean" },
 
   headers = { typ = "array" },
+  headers_upstream = { typ = "array" },
   trusted_ips = { typ = "array" },
   real_ip_header = {
     typ = "string",
@@ -1017,6 +1023,15 @@ local function check_and_parse(conf, opts)
     end
   end
 
+  if conf.headers_upstream then
+    for _, token in ipairs(conf.headers_upstream) do
+      if token ~= "off" and not UPSTREAM_HEADER_KEY_TO_NAME[lower(token)] then
+        errors[#errors + 1] = fmt("headers_upstream: invalid entry '%s'",
+                                  tostring(token))
+      end
+    end
+  end
+
   if conf.dns_resolver then
     for _, server in ipairs(conf.dns_resolver) do
       local dns = utils.normalize_ip(server)
@@ -2105,8 +2120,9 @@ local function load(path, custom_conf, opts)
 
   do
     -- load headers configuration
-    local enabled_headers = {}
 
+    -- (downstream)
+    local enabled_headers = {}
     for _, v in pairs(HEADER_KEY_TO_NAME) do
       enabled_headers[v] = false
     end
@@ -2132,6 +2148,23 @@ local function load(path, custom_conf, opts)
     end
 
     conf.enabled_headers = setmetatable(enabled_headers, _nop_tostring_mt)
+
+
+    -- (upstream)
+    local enabled_headers_upstream = {}
+    for _, v in pairs(UPSTREAM_HEADER_KEY_TO_NAME) do
+      enabled_headers_upstream[v] = false
+    end
+
+    if #conf.headers_upstream > 0 and conf.headers_upstream[1] ~= "off" then
+      for _, token in ipairs(conf.headers_upstream) do
+        if token ~= "off" then
+          enabled_headers_upstream[UPSTREAM_HEADER_KEY_TO_NAME[lower(token)]] = true
+        end
+      end
+    end
+
+    conf.enabled_headers_upstream = setmetatable(enabled_headers_upstream, _nop_tostring_mt)
   end
 
   for _, prefix in ipairs({ "ssl", "admin_ssl", "admin_gui_ssl", "status_ssl", "client_ssl", "cluster" }) do

diff --git a/kong/constants.lua b/kong/constants.lua
@@ -116,6 +116,7 @@ local constants = {
     FORWARDED_PATH = "X-Forwarded-Path",
     FORWARDED_PREFIX = "X-Forwarded-Prefix",
     ANONYMOUS = "X-Anonymous-Consumer",
+    REQUEST_ID = "X-Kong-Request-Id",
     VIA = "Via",
     SERVER = "Server"
   },

diff --git a/kong/error_handlers.lua b/kong/error_handlers.lua
@@ -2,6 +2,7 @@ local kong = kong
 local find = string.find
 local fmt  = string.format
 local utils = require "kong.tools.utils"
+local request_id = require "kong.tracing.request_id"
 
 
 local CONTENT_TYPE    = "Content-Type"
@@ -64,7 +65,8 @@ return function(ctx)
 
   else
     local mime_type = utils.get_response_type(accept_header)
-    message = fmt(utils.get_error_template(mime_type), message)
+    local rid = request_id.get() or ""
+    message = fmt(utils.get_error_template(mime_type), message, rid)
     headers = { [CONTENT_TYPE] = mime_type }
 
   end

diff --git a/kong/pdk/log.lua b/kong/pdk/log.lua
@@ -36,6 +36,7 @@ local kong = kong
 local check_phase = phase_checker.check
 local split = utils.split
 local byte = string.byte
+local request_id_get = require "kong.tracing.request_id".get
 
 
 local _PREFIX = "[kong] "
@@ -735,6 +736,7 @@ do
   -- The following fields are included in the returned table:
   -- * `client_ip` - client IP address in textual format.
   -- * `latencies` - request/proxy latencies.
+  -- * `request.id` - request id.
   -- * `request.headers` - request headers.
   -- * `request.method` - request method.
   -- * `request.querystring` - request query strings.
@@ -759,6 +761,12 @@ do
   -- * `request.tls.cipher` - TLS/SSL cipher used by the connection.
   -- * `request.tls.client_verify` - mTLS validation result. Contents are the same as described in [$ssl_client_verify](https://nginx.org/en/docs/http/ngx_http_ssl_module.html#var_ssl_client_verify).
   --
+  -- The following field is only present in requests where a tracing plugin (OpenTelemetry or Zipkin) is executed:
+  -- * `trace_id` - trace ID.
+  --
+  -- The following field is only present in requests where the Correlation ID plugin is executed:
+  -- * `correlation_id` - correlation ID.
+  --
   -- **Warning:** This function may return sensitive data (e.g., API keys).
   -- Consider filtering before writing it to unsecured locations.
   --
@@ -809,6 +817,7 @@ do
 
       local root = {
         request = {
+          id = request_id_get() or "",
           uri = request_uri,
           url = var.scheme .. "://" .. var.host .. ":" .. host_port .. request_uri,
           querystring = okong.request.get_query(), -- parameters, as a table

diff --git a/kong/pdk/response.lua b/kong/pdk/response.lua
@@ -16,6 +16,7 @@ local cjson = require "cjson.safe"
 local checks = require "kong.pdk.private.checks"
 local phase_checker = require "kong.pdk.private.phases"
 local utils = require "kong.tools.utils"
+local request_id = require "kong.tracing.request_id"
 
 
 local ngx = ngx
@@ -1169,7 +1170,8 @@ local function new(self, major_version)
     local body
     if content_type ~= CONTENT_TYPE_GRPC then
       local actual_message = message or get_http_error_message(status)
-      body = fmt(utils.get_error_template(content_type), actual_message)
+      local rid = request_id.get() or ""
+      body = fmt(utils.get_error_template(content_type), actual_message, rid)
     end
 
     local ctx = ngx.ctx

diff --git a/kong/plugins/correlation-id/handler.lua b/kong/plugins/correlation-id/handler.lua
@@ -63,6 +63,8 @@ function CorrelationIdHandler:access(conf)
     end
   end
 
+  kong.log.set_serialize_value("correlation_id", correlation_id)
+
   if conf.echo_downstream then
     -- For later use, to echo it back downstream
     kong.ctx.plugin.correlation_id = correlation_id

diff --git a/kong/runloop/handler.lua b/kong/runloop/handler.lua
@@ -12,6 +12,7 @@ local constants    = require "kong.constants"
 local concurrency  = require "kong.concurrency"
 local lrucache     = require "resty.lrucache"
 local ktls         = require "resty.kong.tls"
+local request_id   = require "kong.tracing.request_id"
 
 
 
@@ -42,10 +43,12 @@ local log               = ngx.log
 local exit              = ngx.exit
 local exec              = ngx.exec
 local header            = ngx.header
+local set_header        = ngx.req.set_header
 local timer_at          = ngx.timer.at
 local subsystem         = ngx.config.subsystem
 local clear_header      = ngx.req.clear_header
 local http_version      = ngx.req.http_version
+local request_id_get    = request_id.get
 local escape            = require("kong.tools.uri").escape
 local encode            = require("string.buffer").encode
 
@@ -1326,6 +1329,9 @@ return {
     end,
     -- Only executed if the `router` module found a route and allows nginx to proxy it.
     after = function(ctx)
+      local enabled_headers_upstream = kong.configuration.enabled_headers_upstream
+      local headers = constants.HEADERS
+
       -- Nginx's behavior when proxying a request with an empty querystring
       -- `/foo?` is to keep `$is_args` an empty string, hence effectively
       -- stripping the empty querystring.
@@ -1420,6 +1426,16 @@ return {
       if var.http_proxy_connection then
         clear_header("Proxy-Connection")
       end
+
+      -- X-Kong-Request-Id upstream header
+      local rid, rid_get_err = request_id_get()
+      if not rid then
+        log(WARN, "failed to get Request ID: ", rid_get_err)
+      end
+
+      if enabled_headers_upstream[headers.REQUEST_ID] and rid then
+        set_header(headers.REQUEST_ID, rid)
+      end
     end
   },
   header_filter = {
@@ -1513,6 +1529,16 @@ return {
           end
         end
       end
+
+      -- X-Kong-Request-Id downstream header
+      local rid, rid_get_err = request_id_get()
+      if not rid then
+        log(WARN, "failed to get Request ID: ", rid_get_err)
+      end
+
+      if enabled_headers[headers.REQUEST_ID] and rid then
+        header[headers.REQUEST_ID] = rid
+      end
     end
   },
   log = {

diff --git a/kong/templates/kong_defaults.lua b/kong/templates/kong_defaults.lua
@@ -65,7 +65,8 @@ admin_gui_ssl_cert = NONE
 admin_gui_ssl_cert_key = NONE
 status_ssl_cert = NONE
 status_ssl_cert_key = NONE
-headers = server_tokens, latency_tokens
+headers = server_tokens, latency_tokens, x-kong-request-id
+headers_upstream = x-kong-request-id
 trusted_ips = NONE
 error_default_type = text/plain
 upstream_keepalive_pool_size = 512

diff --git a/kong/templates/nginx_kong.lua b/kong/templates/nginx_kong.lua
@@ -47,6 +47,11 @@ exit_worker_by_lua_block {
 }
 
 > if (role == "traditional" or role == "data_plane") and #proxy_listeners > 0 then
+log_format kong_log_format '$remote_addr - $remote_user [$time_local] '
+                           '"$request" $status $body_bytes_sent '
+                           '"$http_referer" "$http_user_agent" '
+                           'kong_request_id: "$request_id"';
+
 # Load variable indexes
 lua_kong_load_var_index default;
 
@@ -72,7 +77,11 @@ server {
     error_page 400 404 405 408 411 412 413 414 417 494 /kong_error_handler;
     error_page 500 502 503 504                     /kong_error_handler;
 
-    access_log ${{PROXY_ACCESS_LOG}};
+    # Append the kong request id to the error log
+    # https://github.com/Kong/lua-kong-nginx-module#lua_kong_error_log_request_id
+    lua_kong_error_log_request_id $request_id;
+
+    access_log ${{PROXY_ACCESS_LOG}} kong_log_format;
     error_log  ${{PROXY_ERROR_LOG}} ${{LOG_LEVEL}};
 
 > if proxy_ssl_enabled then