feat(request-id): introduce Request ID (#11624)

* 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 message * remove unneeded conditional --------- Co-authored-by: Enrique García Cota <kikito@gmail.com>
Kong · Sep 26, 2023 · 22439e0 · 22439e0 · khcp-gha-bot · Sep 26, 2023
1 parent e8d2fe7
commit 22439e0
Show file tree

Hide file tree

Showing 51 changed files with 1,441 additions and 192 deletions.
diff --git a/.requirements b/.requirements
@@ -6,7 +6,7 @@ OPENSSL=3.1.2
 PCRE=8.45
 LIBEXPAT=2.5.0
 
-LUA_KONG_NGINX_MODULE=4d19e8d19c6dbc07eba5cf6f5ebacad95266f928 # 0.6.0
+LUA_KONG_NGINX_MODULE=8296b70ee1256b2cd59f246137b727f049174787 # 0.7.1
 LUA_RESTY_LMDB=951926f20b674a0622236a0e331b359df1c02d9b # 1.3.0
 LUA_RESTY_EVENTS=8448a92cec36ac04ea522e78f6496ba03c9b1fd8 # 0.2.0
 LUA_RESTY_WEBSOCKET=60eafc3d7153bceb16e6327074e0afc3d94b1316 # 0.4.0

diff --git a/changelog/unreleased/kong/11624-2.yml b/changelog/unreleased/kong/11624-2.yml
@@ -0,0 +1,7 @@
+message: Bump lua-kong-nginx-module from 0.6.0 to 0.7.1
+type: dependency
+scope: Core
+prs:
+  - 11624
+jiras:
+  - "KAG-2034"
diff --git a/changelog/unreleased/kong/11624.yml b/changelog/unreleased/kong/11624.yml
@@ -0,0 +1,10 @@
+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
+prs:
+  - 11624
+jiras:
+  - "KAG-2034"
diff --git a/kong-3.5.0-0.rockspec b/kong-3.5.0-0.rockspec
@@ -531,5 +531,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
@@ -237,14 +237,18 @@
 #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:
+                                 # 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>
                                  # ```
@@ -253,22 +257,22 @@
                                  # 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.
+                                 # 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.
+                                 # 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
                                  #
                                  # Similarly to `error_template_html`, the template
-                                 # is required to contain one single `%s` placeholder for
-                                 # the error message.
+                                 # may contain up to two `%s` placeholders for
+                                 # the error message and the request ID respectively.
 
 #------------------------------------------------------------------------------
 # HYBRID MODE
@@ -865,7 +869,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.
                                  #
@@ -895,6 +899,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
@@ -911,6 +917,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",
@@ -1005,6 +1011,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)
@@ -2093,8 +2108,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
@@ -2120,6 +2136,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
@@ -16,6 +16,7 @@ local inspect = require "inspect"
 local ngx_ssl = require "ngx.ssl"
 local phase_checker = require "kong.pdk.private.phases"
 local utils = require "kong.tools.utils"
+local request_id = require "kong.tracing.request_id"
 local cycle_aware_deep_copy = utils.cycle_aware_deep_copy
 
 local sub = string.sub
@@ -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
@@ -1170,7 +1171,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,6 +43,7 @@ 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
@@ -1419,6 +1421,17 @@ 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
+
+      local request_id_header = constants.HEADERS.REQUEST_ID
+      if kong.configuration.enabled_headers_upstream[request_id_header] and rid then
+        set_header(request_id_header, rid)
+      end
     end
   },
   header_filter = {
@@ -1513,6 +1526,17 @@ 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
+
+      local request_id_header = constants.HEADERS.REQUEST_ID
+      if kong.configuration.enabled_headers[request_id_header] and rid then
+        header[request_id_header] = 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
@@ -51,6 +51,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: "$kong_request_id"';
+
 # Load variable indexes
 lua_kong_load_var_index default;
 
@@ -76,7 +81,13 @@ 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}};
+    set $kong_request_id $request_id;
+
+    # 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 $kong_request_id;
+
+    access_log ${{PROXY_ACCESS_LOG}} kong_log_format;
     error_log  ${{PROXY_ERROR_LOG}} ${{LOG_LEVEL}};
 
 > if proxy_ssl_enabled then

diff --git a/kong/tools/utils.lua b/kong/tools/utils.lua
@@ -1427,18 +1427,21 @@ do
   <body>
     <h1>Error</h1>
     <p>%s.</p>
+    <p>request_id: %s</p>
   </body>
 </html>
 ]],
     [CONTENT_TYPE_JSON]   = [[
 {
-  "message":"%s"
+  "message":"%s",
+  "request_id":"%s"
 }]],
-    [CONTENT_TYPE_PLAIN]  = "%s\n",
+    [CONTENT_TYPE_PLAIN]  = "%s\nrequest_id: %s\n",
     [CONTENT_TYPE_XML]    = [[
 <?xml version="1.0" encoding="UTF-8"?>
 <error>
   <message>%s</message>
+  <requestid>%s</requestid>
 </error>
 ]],
   }