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 <[email protected]>

* 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: Enrique García Cota <[email protected]>
Co-authored-by: Qi <[email protected]>

.requirements

@@ -9,4 +9,4 @@ RESTY_PCRE_VERSION=8.45
 LIBYAML_VERSION=0.2.5
 KONG_GO_PLUGINSERVER_VERSION=v0.6.1
 KONG_BUILD_TOOLS_VERSION=4.40.1
-KONG_NGINX_MODULE_BRANCH=0.2.1
+KONG_NGINX_MODULE_BRANCH=0.2.2

changelog/unreleased/kong/lua_kong_nginx_module_bump.yml

@@ -0,0 +1,3 @@
+message: Bump lua-kong-nginx-module from 0.2.1 to 0.2.2
+type: dependency
+scope: Core

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

kong-2.8.4-0.rockspec

@@ -472,5 +472,7 @@ build = {
 
     ["kong.vaults.env"] = "kong/vaults/env/init.lua",
     ["kong.vaults.env.schema"] = "kong/vaults/env/schema.lua",
+
+    ["kong.tracing.request_id"] = "kong/tracing/request_id.lua",
   }
 }

kong.conf.default

@@ -667,7 +667,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.
                                  #
@@ -697,6 +697,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
@@ -713,6 +715,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.

kong/conf_loader/init.lua

@@ -107,6 +107,11 @@ local HEADER_KEY_TO_NAME = {
   [string.lower(HEADERS.ADMIN_LATENCY)] = HEADERS.ADMIN_LATENCY,
   [string.lower(HEADERS.UPSTREAM_LATENCY)] = HEADERS.UPSTREAM_LATENCY,
   [string.lower(HEADERS.UPSTREAM_STATUS)] = HEADERS.UPSTREAM_STATUS,
+  [string.lower(HEADERS.REQUEST_ID)] = HEADERS.REQUEST_ID,
+}
+
+local UPSTREAM_HEADER_KEY_TO_NAME = {
+  [string.lower(HEADERS.REQUEST_ID)] = HEADERS.REQUEST_ID,
 }
 
 
@@ -407,6 +412,7 @@ local CONF_INFERENCES = {
   upstream_keepalive_idle_timeout = { typ = "number" },
 
   headers = { typ = "array" },
+  headers_upstream = { typ = "array" },
   trusted_ips = { typ = "array" },
   real_ip_header = {
     typ = "string",
@@ -970,6 +976,15 @@ local function check_and_infer(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[string.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)
@@ -1689,8 +1704,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
@@ -1716,6 +1732,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[string.lower(token)]] = true
+        end
+      end
+    end
+
+    conf.enabled_headers_upstream = setmetatable(enabled_headers_upstream, _nop_tostring_mt)
   end
 
   -- load absolute paths

kong/constants.lua

@@ -107,6 +107,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"
   },

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"
@@ -45,7 +46,8 @@ return function(ctx)
 
   else
     local mime_type = utils.get_mime_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

kong/pdk/log.lua

@@ -32,6 +32,7 @@ local ngx = ngx
 local kong = kong
 local check_phase = phase_checker.check
 local split = utils.split
+local request_id_get = require "kong.tracing.request_id".get
 
 
 local _PREFIX = "[kong] "
@@ -696,6 +697,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.
@@ -720,6 +722,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.
   --
@@ -783,6 +791,7 @@ do
 
       return edit_result(ctx, {
         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
@@ -909,14 +918,14 @@ local function new_log(namespace, format)
     if not buf then
       error(err, 2)
     end
-
+    
     for log_lvl_name, log_lvl in pairs(_LEVELS) do
-      self[log_lvl_name] = gen_log_func(log_lvl, buf)
+            self[log_lvl_name] = gen_log_func(log_lvl, buf)
     end
 
     self.deprecation = new_deprecation(gen_log_func(_LEVELS.warn, buf, nil, 5))
   end
-
+  
   self.set_format(format)
 
   self.inspect = new_inspect(namespace)

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
@@ -1145,7 +1146,8 @@ local function new(self, major_version)
       local actual_message = message or
                              HTTP_MESSAGES["s" .. status] or
                              fmt(HTTP_MESSAGES.default, 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

kong/plugins/correlation-id/handler.lua

@@ -62,6 +62,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

kong/plugins/zipkin/tracing_headers.lua

@@ -364,6 +364,52 @@ local function find_header_type(headers)
 end
 
 
+-- Performs a table merge to add trace ID formats to the current request's
+-- trace ID and returns a table containing all the formats.
+--
+-- Plugins can handle different formats of trace ids depending on their headers
+-- configuration, multiple plugins executions may result in additional formats
+-- of the current request's trace id.
+--
+-- The `propagation_trace_id_all_fmt` table is stored in `ngx.ctx` to keep the
+-- list of formats updated for the current request.
+--
+-- Each item in the resulting `propagation_trace_id_all_fmt` table represents a
+-- format associated with the trace ID for the current request.
+--
+-- @param trace_id_new_fmt table containing the trace ID formats to be added
+-- @returns propagation_trace_id_all_fmt table contains all the formats for
+-- the current request
+--
+-- @example
+--
+--    propagation_trace_id_all_fmt = { datadog = "1234",
+--                                     w3c     = "abcd" }
+--
+--    trace_id_new_fmt             = { ot = "abcd",
+--                                     w3c = "abcd" }
+--
+--    propagation_trace_id_all_fmt = { datadog = "1234",
+--                                     ot = "abcd",
+--                                     w3c = "abcd" }
+--
+local function add_trace_id_formats(trace_id_new_fmt)
+  -- TODO: @samugi - move trace ID table in the unified tracing context
+  local trace_id_all_fmt = ngx.ctx.propagation_trace_id_all_fmt
+  if not trace_id_all_fmt then
+    ngx.ctx.propagation_trace_id_all_fmt = trace_id_new_fmt
+    return trace_id_new_fmt
+  end
+
+  -- add new formats to trace ID formats table
+  for format, value in pairs(trace_id_new_fmt) do
+    trace_id_all_fmt[format] = value
+  end
+
+  return trace_id_all_fmt
+end
+
+
 local function parse(headers, conf_header_type)
   if conf_header_type == "ignore" then
     return nil
@@ -417,9 +463,24 @@ local function set(conf_header_type, found_header_type, proxy_span, conf_default
 
   found_header_type = found_header_type or conf_default_header_type or "b3"
 
+  -- contains all the different formats of the current trace ID, with zero or
+  -- more of the following entries:
+  -- {
+  --   ["b3"] = "<b3_trace_id>", -- the trace_id when the request has a b3 or X-B3-TraceId (zipkin) header
+  --   ["w3c"] = "<w3c_trace_id>", -- the trace_id when the request has a W3C header
+  --   ["jaeger"] = "<jaeger_trace_id>", -- the trace_id when the request has a jaeger tracing header
+  --   ["ot"] = "<ot_trace_id>", -- the trace_id when the request has an OpenTelemetry tracing header
+  --   ["aws"] = "<aws_trace_id>", -- the trace_id when the request has an aws tracing header
+  --   ["gcp"] = "<gcp_trace_id>", -- the trace_id when the request has a gcp tracing header
+  -- }
+  local trace_id_formats = {}
+
   if conf_header_type == "b3" or found_header_type == "b3"
   then
-    set_header("x-b3-traceid", to_hex(proxy_span.trace_id))
+    local trace_id = to_hex(proxy_span.trace_id)
+    trace_id_formats.b3 = trace_id
+
+    set_header("x-b3-traceid", trace_id)
     set_header("x-b3-spanid", to_hex(proxy_span.span_id))
     if proxy_span.parent_id then
       set_header("x-b3-parentspanid", to_hex(proxy_span.parent_id))
@@ -433,30 +494,43 @@ local function set(conf_header_type, found_header_type, proxy_span, conf_default
   end
 
   if conf_header_type == "b3-single" or found_header_type == "b3-single" then
+    local trace_id = to_hex(proxy_span.trace_id)
+    trace_id_formats.b3 = trace_id
+
     set_header("b3", fmt("%s-%s-%s-%s",
-        to_hex(proxy_span.trace_id),
+        trace_id,
         to_hex(proxy_span.span_id),
         proxy_span.should_sample and "1" or "0",
       to_hex(proxy_span.parent_id)))
   end
 
   if conf_header_type == "w3c" or found_header_type == "w3c" then
+    local trace_id = to_hex(proxy_span.trace_id)
+    trace_id_formats.w3c = trace_id
+
     set_header("traceparent", fmt("00-%s-%s-%s",
-        to_hex(proxy_span.trace_id),
+        trace_id,
         to_hex(proxy_span.span_id),
       proxy_span.should_sample and "01" or "00"))
   end
 
   if conf_header_type == "jaeger" or found_header_type == "jaeger" then
+    local trace_id = to_hex(proxy_span.trace_id)
+    trace_id_formats.jaeger = trace_id
+
     set_header("uber-trace-id", fmt("%s:%s:%s:%s",
-        to_hex(proxy_span.trace_id),
+        trace_id,
         to_hex(proxy_span.span_id),
         to_hex(proxy_span.parent_id),
       proxy_span.should_sample and "01" or "00"))
   end
 
   if conf_header_type == "ot" or found_header_type == "ot" then
-    set_header("ot-tracer-traceid", to_hex(proxy_span.trace_id))
+    local trace_id = to_hex(proxy_span.trace_id)
+    trace_id_formats.ot = trace_id
+
+    set_header("ot-tracer-traceid", trace_id)
+
     set_header("ot-tracer-spanid", to_hex(proxy_span.span_id))
     set_header("ot-tracer-sampled", proxy_span.should_sample and "1" or "0")
 
@@ -469,6 +543,10 @@ local function set(conf_header_type, found_header_type, proxy_span, conf_default
     -- XXX: https://github.com/opentracing/specification/issues/117
     set_header("uberctx-"..key, ngx.escape_uri(value))
   end
+
+  trace_id_formats = add_trace_id_formats(trace_id_formats)
+  -- add trace IDs to log serializer output
+  kong.log.set_serialize_value("trace_id", trace_id_formats)
 end