feat(request-id): move trace id set in propagation + bump

setting trace id from propagation allows to set the correct format
of trace id depending on the headers format, instead of defauting to hex

bump lua-kong-nginx-module to 0.7.1

.requirements

@@ -6,7 +6,7 @@ OPENSSL=3.1.2
 PCRE=8.45
 LIBEXPAT=2.5.0
 
-LUA_KONG_NGINX_MODULE=949131f4ccb841c9d9851b413be4a789f56ec7f3 # 0.7.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

kong/plugins/opentelemetry/handler.lua

@@ -1,5 +1,4 @@
 local Queue = require "kong.tools.queue"
-local request_id = require "kong.tracing.request_id"
 local http = require "resty.http"
 local clone = require "table.clone"
 local otlp = require "kong.plugins.opentelemetry.otlp"
@@ -12,7 +11,6 @@ local tostring = tostring
 local ngx_log = ngx.log
 local ngx_ERR = ngx.ERR
 local ngx_DEBUG = ngx.DEBUG
-local ngx_NOTICE = ngx.NOTICE
 local ngx_now = ngx.now
 local ngx_update_time = ngx.update_time
 local ngx_req = ngx.req
@@ -119,10 +117,6 @@ function OpenTelemetryHandler:access(conf)
   if trace_id then
     injected_parent_span.trace_id = trace_id
     kong.ctx.plugin.trace_id = trace_id
-    local _, err = request_id.set(to_hex(trace_id), request_id.TYPES.TRACE)
-    if err then
-      ngx_log(ngx_NOTICE, _log_prefix, err)
-    end
   end
 
   -- overwrite parent span's parent_id

kong/plugins/zipkin/handler.lua

@@ -1,7 +1,6 @@
 local new_zipkin_reporter = require "kong.plugins.zipkin.reporter".new
 local new_span = require "kong.plugins.zipkin.span".new
 local utils = require "kong.tools.utils"
-local request_id = require "kong.tracing.request_id"
 local propagation = require "kong.tracing.propagation"
 local request_tags = require "kong.plugins.zipkin.request_tags"
 local kong_meta = require "kong.meta"
@@ -124,11 +123,6 @@ if subsystem == "http" then
       span_name = method .. ' ' .. path
     end
 
-    local _, err = request_id.set(to_hex(trace_id), request_id.TYPES.TRACE)
-    if err then
-      kong.log.notice(err)
-    end
-
     local request_span = new_span(
       "SERVER",
       span_name,

kong/templates/nginx_kong.lua

@@ -51,10 +51,10 @@ exit_worker_by_lua_block {
 }
 
 > if (role == "traditional" or role == "data_plane") and #proxy_listeners > 0 then
-log_format request_id_access_log_format '[$kong_request_id] '
-                                        '$remote_addr - $remote_user [$time_local] '
+log_format request_id_access_log_format '$remote_addr - $remote_user [$time_local] '
                                         '"$request" $status $body_bytes_sent '
-                                        '"$http_referer" "$http_user_agent"';
+                                        '"$http_referer" "$http_user_agent" '
+                                        'request_id: "$kong_request_id"';
 
 # Load variable indexes
 lua_kong_load_var_index default;

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
 
 

kong/tracing/request_id.lua

@@ -49,7 +49,7 @@ local function set_ctx_request_id(id, type)
 end
 
 
---- Function `should_overwrite_id` determines whether the new request id
+-- Function `should_overwrite_id` determines whether the new request id
 -- should overwrite the current one.
 --
 -- This function uses the provided (new) request id type to compare it with the
@@ -82,10 +82,9 @@ local function get()
   if not rid then
     -- first access to the request id for this request:
     -- try to initialize with the value of $kong_request_id
-    local ok
-    ok, rid = pcall(function() return ngx.var.kong_request_id end)
+    rid = ngx.var.kong_request_id
 
-    if ok and rid then
+    if rid then
       set_ctx_request_id(rid, TYPES.INIT)
     end
   end
@@ -97,7 +96,10 @@ end
 local function set(id, type)
   -- phase and input checks
   local phase = ngx.get_phase()
-  assert(NGX_VAR_PHASES[phase], "cannot set request_id in '" .. phase .. "' phase")
+  if not NGX_VAR_PHASES[phase] then
+    return nil, "cannot set request_id in '" .. phase .. "' phase"
+  end
+
   if not id or not type then
     return nil, "both id and type are required"
   end

spec/01-unit/26-tracing/02-propagation_spec.lua

@@ -851,7 +851,8 @@ describe("propagation.set", function()
     log = {
       warn = function(msg)
         warnings[#warnings + 1] = msg
-      end
+      end,
+      notice = function() end
     }
   }
 

spec/01-unit/30-request-id_spec.lua → spec/01-unit/26-tracing/03-request-id_spec.lua

@@ -73,9 +73,7 @@ describe("Request ID unit tests", function()
         return invalid_phase
       end
 
-      local ok, err = pcall(request_id.set, "abcd", request_id.TYPES.INIT)
-
-      assert.is_false(ok)
+      local _, err = request_id.set( "abcd", request_id.TYPES.INIT)
       assert.matches("cannot set request_id in '" .. invalid_phase .. "' phase", err)
     end)
 

spec/02-integration/05-proxy/18-upstream_tls_spec.lua

@@ -884,7 +884,7 @@ for _, strategy in helpers.each_strategy() do
               end)
             end, 10)
 
-            assert.equals("An invalid response was received from the upstream server", body)
+            assert.matches("An invalid response was received from the upstream server", body)
           end
         end)
       end)
@@ -1038,7 +1038,7 @@ for _, strategy in helpers.each_strategy() do
                  assert(proxy_client:close())
               end)
             end, 10)
-            assert.equals("An invalid response was received from the upstream server", body)
+            assert.matches("An invalid response was received from the upstream server", body)
           end
         end)