feat(request-id): add a request ID to logs and error templates

.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

CHANGELOG/unreleased/kong/11308.yaml

@@ -0,0 +1,7 @@
+message: Add a Request ID (which matches the trace_id or correlation_id when available) to error templates and logs.
+type: feature
+scope: Core
+prs:
+  - 11308
+jiras:
+  - "KAG-2034"

kong-3.5.0-0.rockspec

@@ -530,5 +530,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",
   }
 }

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

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 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.
@@ -809,6 +811,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

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

kong/plugins/correlation-id/handler.lua

@@ -1,6 +1,7 @@
 -- Copyright (C) Kong Inc.
 local uuid = require "kong.tools.utils".uuid
 local kong_meta = require "kong.meta"
+local request_id = require "kong.tracing.request_id"
 
 
 local kong = kong
@@ -63,6 +64,13 @@ function CorrelationIdHandler:access(conf)
     end
   end
 
+  if correlation_id then
+    local _, err = request_id.set(correlation_id, request_id.TYPES.CORR)
+    if err then
+      kong.log.notice(err)
+    end
+  end
+
   if conf.echo_downstream then
     -- For later use, to echo it back downstream
     kong.ctx.plugin.correlation_id = correlation_id

kong/runloop/handler.lua

@@ -2,6 +2,7 @@
 
 local meta         = require "kong.meta"
 local utils        = require "kong.tools.utils"
+local request_id   = require "kong.tracing.request_id"
 local Router       = require "kong.router"
 local balancer     = require "kong.runloop.balancer"
 local events       = require "kong.runloop.events"
@@ -1118,6 +1119,7 @@ return {
       local server_port = var.server_port
       ctx.host_port = HOST_PORTS[server_port] or server_port
       instrumentation.request(ctx)
+      request_id.rewrite()
     end,
   },
   access = {

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 request_id_access_log_format '$remote_addr - $remote_user [$time_local] '
+                                        '"$request" $status $body_bytes_sent '
+                                        '"$http_referer" "$http_user_agent" '
+                                        'request_id: "$kong_request_id"';
+
 # Load variable indexes
 lua_kong_load_var_index default;
 
@@ -76,7 +81,10 @@ 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;
+    lua_kong_error_log_request_id $kong_request_id;
+
+    access_log ${{PROXY_ACCESS_LOG}} request_id_access_log_format;
     error_log  ${{PROXY_ERROR_LOG}} ${{LOG_LEVEL}};
 
 > if proxy_ssl_enabled then

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>
 ]],
   }

kong/tracing/propagation.lua

@@ -1,5 +1,6 @@
 local to_hex = require "resty.string".to_hex
 local openssl_bignum = require "resty.openssl.bn"
+local request_id = require "kong.tracing.request_id"
 local table_merge = require "kong.tools.utils".table_merge
 local split = require "kong.tools.utils".split
 local strip = require "kong.tools.utils".strip
@@ -589,9 +590,12 @@ 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"
 
+  local request_trace_id
+
   if conf_header_type == "b3" or found_header_type == "b3"
   then
-    set_header("x-b3-traceid", to_hex(proxy_span.trace_id))
+    request_trace_id = to_hex(proxy_span.trace_id)
+    set_header("x-b3-traceid", request_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))
@@ -605,31 +609,35 @@ 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
-    set_header("b3", to_hex(proxy_span.trace_id) ..
+    request_trace_id = to_hex(proxy_span.trace_id)
+    set_header("b3", request_trace_id ..
         "-" .. to_hex(proxy_span.span_id) ..
         "-" .. (proxy_span.should_sample and "1" or "0") ..
         (proxy_span.parent_id and "-" .. to_hex(proxy_span.parent_id) or ""))
   end
 
   if conf_header_type == "w3c" or found_header_type == "w3c" then
     -- OTEL uses w3c trace context format so to_ot_trace_id works here
+    request_trace_id = to_hex(to_w3c_trace_id(proxy_span.trace_id))
     set_header("traceparent", fmt("00-%s-%s-%s",
-        to_hex(to_w3c_trace_id(proxy_span.trace_id)),
+        request_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
+    request_trace_id = to_hex(proxy_span.trace_id)
     set_header("uber-trace-id", fmt("%s:%s:%s:%s",
-        to_hex(proxy_span.trace_id),
+        request_trace_id,
         to_hex(proxy_span.span_id),
         proxy_span.parent_id and to_hex(proxy_span.parent_id) or "0",
       proxy_span.should_sample and "01" or "00"))
   end
 
   if conf_header_type == "ot" or found_header_type == "ot" then
     to_ot_trace_id = to_ot_trace_id or require "kong.plugins.opentelemetry.otlp".to_ot_trace_id
-    set_header("ot-tracer-traceid", to_hex(to_ot_trace_id(proxy_span.trace_id)))
+    request_trace_id = to_hex(to_ot_trace_id(proxy_span.trace_id))
+    set_header("ot-tracer-traceid", request_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")
 
@@ -644,21 +652,30 @@ local function set(conf_header_type, found_header_type, proxy_span, conf_default
   end
 
   if conf_header_type == "aws" or found_header_type == "aws" then
-    local trace_id = to_hex(proxy_span.trace_id)
+    request_trace_id = to_hex(proxy_span.trace_id)
+
     set_header("x-amzn-trace-id", "Root=" .. AWS_TRACE_ID_VERSION .. "-" ..
-        sub(trace_id, 1, AWS_TRACE_ID_TIMESTAMP_LEN) .. "-" ..
-        sub(trace_id, AWS_TRACE_ID_TIMESTAMP_LEN + 1, #trace_id) ..
+        sub(request_trace_id, 1, AWS_TRACE_ID_TIMESTAMP_LEN) .. "-" ..
+        sub(request_trace_id, AWS_TRACE_ID_TIMESTAMP_LEN + 1, #request_trace_id) ..
         ";Parent=" .. to_hex(proxy_span.span_id) .. ";Sampled=" ..
         (proxy_span.should_sample and "1" or "0")
     )
   end
 
   if conf_header_type == "gcp" or found_header_type == "gcp" then
-    set_header("x-cloud-trace-context", to_gcp_trace_id(to_hex(proxy_span.trace_id)) .. 
+    request_trace_id = to_gcp_trace_id(to_hex(proxy_span.trace_id))
+    set_header("x-cloud-trace-context", request_trace_id .. 
       "/" .. openssl_bignum.from_binary(proxy_span.span_id):to_dec() .. 
       ";o=" .. (proxy_span.should_sample and "1" or "0")
     )
   end
+
+  if request_trace_id then
+    local _, err = request_id.set(request_trace_id, request_id.TYPES.TRACE)
+    if err then
+      kong.log.notice(err)
+    end
+  end
 end