feat(request-debugging): use request_id instead of debug_id

kong/timing/init.lua

@@ -1,5 +1,4 @@
 local context         = require("kong.timing.context")
-local utils           = require("kong.tools.utils")
 local cjson           = require("cjson.safe")
 local req_dyn_hook    = require("kong.dynamic_hook")
 local constants       = require("kong.constants")
@@ -9,6 +8,8 @@ local ngx_var         = ngx.var
 
 local string_format   = string.format
 
+local request_id_get  = require("kong.tracing.request_id").get
+
 local FILTER_ALL_PHASES = {
   ssl_cert      = nil,    -- NYI
                           -- in this phase, we can't get request headers
@@ -89,7 +90,7 @@ function _M.auth()
     log = http_x_kong_request_debug_log == "true",
     loopback = loopback,
   })
-  ctx:set_context_prop("debug_id", utils.uuid())
+  ctx:set_context_prop("request_id", request_id_get())
   ngx.ctx.req_trace_ctx = ctx
   req_dyn_hook.enable_on_this_request("timing")
 end
@@ -149,8 +150,8 @@ function _M.header_filter()
   if #output >= HEADER_JSON_TRUNCATE_LENGTH and not req_tr_ctx:from_loopback() then
     output = assert(cjson.encode({
       truncated = true,
-      debug_id = ngx.ctx.req_trace_ctx:get_root_context_kv("debug_id"),
-      message = "Output is truncated, please check the error_log for full output by filtering with the debug_id.",
+      request_id = ngx.ctx.req_trace_ctx:get_root_context_kv("request_id"),
+      message = "Output is truncated, please check the error_log for full output by filtering with the request_id.",
     }))
 
     ngx.ctx.req_trace_ctx.log = true
@@ -169,7 +170,6 @@ function _M.log()
 
   req_tr_ctx:mock_upstream_phase()
   local output = req_tr_ctx:to_json()
-  local debug_id = req_tr_ctx:get_root_context_kv("debug_id")
 
   if #output >= LOG_JSON_TRUNCATE_LENGTH then
     -- split the output into N parts
@@ -186,18 +186,18 @@ function _M.log()
 
     local nparts = #parts
     for no, part in ipairs(parts) do
-      local msg = string_format("%s id: %s parts: %d/%d output: %s",
+      local msg = string_format("%s parts: %d/%d output: %s",
                                 constants.REQUEST_DEBUG_LOG_PREFIX,
-                                debug_id, no, nparts, part)
+                                no, nparts, part)
       ngx.log(ngx.NOTICE, msg)
     end
 
     return
   end
 
-  local msg = string_format("%s id: %s output: %s",
+  local msg = string_format("%s output: %s",
                             constants.REQUEST_DEBUG_LOG_PREFIX,
-                            debug_id, output)
+                            output)
   ngx.log(ngx.NOTICE, msg)
 end
 

spec/02-integration/21-request-debug/01-request-debug_spec.lua

@@ -191,16 +191,16 @@ local function get_output_log(deployment, path, filter, fake_ip, token)
   end
 
   local output = assert(cjson.decode(res.headers["X-Kong-Request-Debug-Output"]))
-  local debug_id = assert(output.debug_id)
+  local request_id = assert(output.request_id)
 
   local json
   local truncated = false
 
   local buf = string_buffer.new()
 
-  local keyword = "[request-debug] id: " .. debug_id
-  local single_pattern = [[ output: (?<data>.+) while logging request, client]]
-  local multi_pattern = [[ parts: (?<part>\d+)/(?<parts>\d+) output: (?<data>.+) while logging request, client]]
+  local keyword = "[request-debug] "
+  local single_pattern = [[output: (?<data>.+) while logging request, client.+request_id: "]] .. request_id .. [["]]
+  local multi_pattern = [[parts: (?<part>\d+)/(?<parts>\d+) output: (?<data>.+) while logging request, client.+request_id: "]] .. request_id .. [["]]
 
   local deadline = ngx.now() + 5
 
@@ -234,9 +234,6 @@ local function get_output_log(deployment, path, filter, fake_ip, token)
           local data = assert(captures.data)
           json = cjson.decode(data)
           break
-
-        else
-          error("unexpected error.log line: " .. line)
         end
       end
     end
@@ -255,7 +252,7 @@ local function get_output_log(deployment, path, filter, fake_ip, token)
   end
 
   assert.falsy(json.dangling)
-  assert.same(debug_id, json.debug_id)
+  assert.same(request_id, json.request_id)
 
   return json, truncated
 end
@@ -472,7 +469,7 @@ describe(desc, function()
     assert_has_output_header(deployment, "/", "*", "1.1.1.1", TOKEN)
   end)
 
-  it("has debug_id and workspace_id", function()
+  it("has request_id and workspace_id", function()
     local route_id = setup_route("/dummy", upstream)
 
     finally(function()
@@ -486,10 +483,10 @@ describe(desc, function()
     local header_output = assert_has_output_header(deployment, "/dummy", "*")
     local log_output = assert_has_output_log(deployment, "/dummy", "*")
 
-    assert.truthy(header_output.debug_id)
+    assert.truthy(header_output.request_id)
     assert.truthy(header_output.workspace_id)
 
-    assert.truthy(log_output.debug_id)
+    assert.truthy(log_output.request_id)
     assert.truthy(log_output.workspace_id)
   end)