chore(pdk/log): optimize log serialize

### Summary

Just some miscellaneous optimizations to log serializer:
- avoid unnecessary table creation and modification
- move variable creation closer to usage
- do not use tail calls
- remove EMPTY_TAB

Signed-off-by: Aapo Talvensaari <[email protected]>

kong/pdk/log.lua

@@ -16,14 +16,18 @@ local ngx_re = require("ngx.re")
 local inspect = require("inspect")
 local phase_checker = require("kong.pdk.private.phases")
 local constants = require("kong.constants")
+local clear_tab = require("table.clear")
+
 
 local request_id_get = require("kong.tracing.request_id").get
 local cycle_aware_deep_copy = require("kong.tools.table").cycle_aware_deep_copy
 local get_tls1_version_str = require("ngx.ssl").get_tls1_version_str
 local get_workspace_name = require("kong.workspaces").get_workspace_name
 
+
 local sub = string.sub
 local type = type
+local error = error
 local pairs = pairs
 local ipairs = ipairs
 local find = string.find
@@ -42,7 +46,36 @@ local split = require("kong.tools.string").split
 local byte = string.byte
 
 
-local EMPTY_TAB  = require("pl.tablex").readonly({})
+local DEFAULT_SERIALIZE_VALUES, get_serialize_values do
+  if ngx.config.subsystem == "http" then
+    get_serialize_values = function(data)
+      return {
+        {
+          key = "request.headers.authorization",
+          value = "REDACTED",
+          mode = "replace"
+        },
+        {
+          key = "request.headers.proxy-authorization",
+          value = "REDACTED",
+          mode = "replace"
+        },
+        data,
+      }
+    end
+    DEFAULT_SERIALIZE_VALUES = get_serialize_values()
+
+  else
+      get_serialize_values = function(data)
+        return {
+          data,
+        }
+      end
+      DEFAULT_SERIALIZE_VALUES = get_serialize_values()
+  end
+end
+
+
 local _PREFIX = "[kong] "
 local _DEFAULT_FORMAT = "%file_src:%line_src %message"
 local _DEFAULT_NAMESPACED_FORMAT = "%file_src:%line_src [%namespace] %message"
@@ -552,17 +585,6 @@ local _log_mt = {
 }
 
 
-local function get_default_serialize_values()
-  if ngx.config.subsystem == "http" then
-    return {
-      { key = "request.headers.authorization", value = "REDACTED", mode = "replace" },
-      { key = "request.headers.proxy-authorization", value = "REDACTED", mode = "replace" },
-    }
-  end
-
-  return {}
-end
-
 ---
 -- Sets a value to be used on the `serialize` custom table.
 --
@@ -606,27 +628,36 @@ end
 local function set_serialize_value(key, value, options)
   check_phase(phases_with_ctx)
 
-  options = options or {}
-  local mode = options.mode or "set"
-
   if type(key) ~= "string" then
     error("key must be a string", 2)
   end
 
+  local mode = options and options.mode or "set"
   if mode ~= "set" and mode ~= "add" and mode ~= "replace" then
     error("mode must be 'set', 'add' or 'replace'", 2)
   end
 
-  local ongx = options.ngx or ngx
+  local data = {
+    key = key,
+    value = value,
+    mode = mode,
+  }
+
+  local ongx = options and options.ngx or ngx
   local ctx = ongx.ctx
-  ctx.serialize_values = ctx.serialize_values or get_default_serialize_values()
-  ctx.serialize_values[#ctx.serialize_values + 1] =
-    { key = key, value = value, mode = mode }
+  local serialize_values = ctx.serialize_values
+  if serialize_values then
+    serialize_values[#serialize_values + 1] = data
+  else
+    ctx.serialize_values = get_serialize_values(data)
+  end
 end
 
 
 local serialize
 do
+  local VISITED = {}
+
   local function is_valid_value(v, visited)
     local t = type(v)
     if v == nil or t == "number" or t == "string" or t == "boolean" then
@@ -637,17 +668,20 @@ do
       return false
     end
 
-    if visited[v] then
+    if not visited then
+      clear_tab(VISITED)
+      visited = VISITED
+
+    elseif visited[v] then
       return false
     end
+
     visited[v] = true
 
     for k, val in pairs(v) do
       t = type(k)
-      if (t ~= "string"
-          and t ~= "number"
-          and t ~= "boolean")
-        or not is_valid_value(val, visited)
+      if (t ~= "string" and t ~= "number" and t ~= "boolean")
+      or not is_valid_value(val, visited)
       then
         return false
       end
@@ -656,41 +690,43 @@ do
     return true
   end
 
+
   -- Modify returned table with values set with kong.log.set_serialize_values
-  local function edit_result(ctx, root)
-    local serialize_values = ctx.serialize_values or get_default_serialize_values()
-    local key, mode, new_value, subkeys, node, subkey, last_subkey, existing_value
+  local function edit_result(serialize_values, root)
     for _, item in ipairs(serialize_values) do
-      key, mode, new_value = item.key, item.mode, item.value
-
-      if not is_valid_value(new_value, {}) then
+      local new_value = item.value
+      if not is_valid_value(new_value) then
         error("value must be nil, a number, string, boolean or a non-self-referencial table containing numbers, string and booleans", 2)
       end
 
       -- Split key by ., creating subtables when needed
-      subkeys = setmetatable(split(key, "."), nil)
-      node = root -- start in root, iterate with each subkey
-      for i = 1, #subkeys - 1 do -- note that last subkey is treated differently, below
-        subkey = subkeys[i]
+      local key = item.key
+      local mode = item.mode
+      local is_set_or_add = mode == "set" or mode == "add"
+      local subkeys = setmetatable(split(key, "."), nil)
+      local node = root -- start in root, iterate with each subkey
+      local subkeys_count = #subkeys
+      for i = 1, subkeys_count - 1 do -- note that last subkey is treated differently, below
+        local subkey = subkeys[i]
         if node[subkey] == nil then
-          if mode == "set" or mode == "add" then
+          if is_set_or_add then
             node[subkey] = {} -- add subtables as needed
           else
             node = nil
             break -- mode == replace; and we have a missing link on the "chain"
           end
-        end
 
-        if type(node[subkey]) ~= "table" then
+        elseif type(node[subkey]) ~= "table" then
           error("The key '" .. key .. "' could not be used as a serialize value. " ..
                 "Subkey '" .. subkey .. "' is not a table. It's " .. tostring(node[subkey]))
         end
 
         node = node[subkey]
       end
+
       if type(node) == "table" then
-        last_subkey = subkeys[#subkeys]
-        existing_value = node[last_subkey]
+        local last_subkey = subkeys[subkeys_count]
+        local existing_value = node[last_subkey]
         if (mode == "set")
         or (mode == "add" and existing_value == nil)
         or (mode == "replace" and existing_value ~= nil)
@@ -704,29 +740,32 @@ do
   end
 
   local function build_authenticated_entity(ctx)
-    local authenticated_entity
-    if ctx.authenticated_credential ~= nil then
-      authenticated_entity = {
-        id = ctx.authenticated_credential.id,
-        consumer_id = ctx.authenticated_credential.consumer_id,
+    local credential = ctx.authenticated_credential
+    if credential ~= nil then
+      local consumer_id = credential.consumer_id
+      if not consumer_id then
+        local consumer = ctx.authenticate_consumer
+        if consumer ~= nil then
+          consumer_id = consumer.id
+        end
+      end
+
+      return {
+        id = credential.id,
+        consumer_id = consumer_id,
       }
     end
-
-    return authenticated_entity
   end
 
   local function build_tls_info(var, override)
-    local tls_info
     local tls_info_ver = get_tls1_version_str()
     if tls_info_ver then
-      tls_info = {
+      return {
         version = tls_info_ver,
         cipher = var.ssl_cipher,
         client_verify = override or var.ssl_client_verify,
       }
     end
-
-    return tls_info
   end
 
   local function to_decimal(str)
@@ -796,49 +835,42 @@ do
     function serialize(options)
       check_phase(PHASES_LOG)
 
-      options = options or EMPTY_TAB
-      local ongx = options.ngx or ngx
-      local okong = options.kong or kong
+      local ongx = options and options.ngx or ngx
+      local okong = options and options.kong or kong
       local okong_request = okong.request
 
       local ctx = ongx.ctx
       local var = ongx.var
 
-      local request_uri = var.request_uri or ""
-
-      local host_port = ctx.host_port or tonumber(var.server_port, 10)
-
+      local request_uri = ctx.request_uri or var.request_uri or ""
       local upstream_uri = var.upstream_uri or ""
       if upstream_uri ~= "" and not find(upstream_uri, "?", nil, true) then
-        if byte(ctx.request_uri or var.request_uri, -1) == QUESTION_MARK then
+        if byte(request_uri, -1) == QUESTION_MARK then
           upstream_uri = upstream_uri .. "?"
         elseif var.is_args == "?" then
           upstream_uri = upstream_uri .. "?" .. (var.args or "")
         end
       end
 
-      local request_headers, response_headers = nil, nil
       -- THIS IS AN INTERNAL ONLY FLAG TO SKIP FETCHING HEADERS,
       -- AND THIS FLAG MIGHT BE REMOVED IN THE FUTURE
       -- WITHOUT ANY NOTICE AND DEPRECATION.
-      if not options.__skip_fetch_headers__ then
+      local request_headers
+      local response_headers
+      if not (options and options.__skip_fetch_headers__) then
         request_headers = okong_request.get_headers()
         response_headers = ongx.resp.get_headers()
       end
 
-      local upstream_status = var.upstream_status or ctx.buffered_status or ""
-
-      local response_source = okong.response.get_source(ongx.ctx)
-      local response_source_name = TYPE_NAMES[response_source]
-
       local url
+      local host_port = ctx.host_port or tonumber(var.server_port, 10)
       if host_port then
         url = var.scheme .. "://" .. var.host .. ":" .. host_port .. request_uri
       else
         url = var.scheme .. "://" .. var.host .. request_uri
       end
 
-      local root = {
+      local root = edit_result(ctx.serialize_values or DEFAULT_SERIALIZE_VALUES, {
         request = {
           id = request_id_get() or "",
           uri = request_uri,
@@ -850,7 +882,7 @@ do
           tls = build_tls_info(var, ctx.CLIENT_VERIFY_OVERRIDE),
         },
         upstream_uri = upstream_uri,
-        upstream_status = upstream_status,
+        upstream_status = var.upstream_status or ctx.buffered_status or "",
         response = {
           status = ongx.status,
           headers = response_headers,
@@ -862,42 +894,38 @@ do
           request = tonumber(var.request_time) * 1000,
           receive = ctx.KONG_RECEIVE_TIME or 0,
         },
-        tries = (ctx.balancer_data or EMPTY_TAB).tries,
+        tries = ctx.balancer_data and ctx.balancer_data.tries,
         authenticated_entity = build_authenticated_entity(ctx),
         route = cycle_aware_deep_copy(ctx.route),
         service = cycle_aware_deep_copy(ctx.service),
         consumer = cycle_aware_deep_copy(ctx.authenticated_consumer),
         client_ip = var.remote_addr,
         started_at = okong_request.get_start_time(),
-        source = response_source_name,
-
+        source = TYPE_NAMES[okong.response.get_source(ctx)],
         workspace = ctx.workspace,
         workspace_name = get_workspace_name(),
-      }
+      })
 
-      return edit_result(ctx, root)
+      return root
     end
 
   else
     function serialize(options)
       check_phase(PHASES_LOG)
 
-      options = options or EMPTY_TAB
-      local ongx = options.ngx or ngx
-      local okong = options.kong or kong
+      local ongx = options and options.ngx or ngx
+      local okong = options and options.kong or kong
 
       local ctx = ongx.ctx
       local var = ongx.var
 
-      local host_port = ctx.host_port or tonumber(var.server_port, 10)
-
-      local root = {
+      local root = edit_result(ctx.serialize_values or DEFAULT_SERIALIZE_VALUES, {
         session = {
           tls = build_tls_info(var, ctx.CLIENT_VERIFY_OVERRIDE),
           received = to_decimal(var.bytes_received),
           sent = to_decimal(var.bytes_sent),
           status = ongx.status,
-          server_port = host_port,
+          server_port = ctx.host_port or tonumber(var.server_port, 10),
         },
         upstream = {
           received = to_decimal(var.upstream_bytes_received),
@@ -907,19 +935,18 @@ do
           kong = ctx.KONG_PROXY_LATENCY or ctx.KONG_RESPONSE_LATENCY or 0,
           session = var.session_time * 1000,
         },
-        tries = (ctx.balancer_data or EMPTY_TAB).tries,
+        tries = ctx.balancer_data and ctx.balancer_data.tries,
         authenticated_entity = build_authenticated_entity(ctx),
         route = cycle_aware_deep_copy(ctx.route),
         service = cycle_aware_deep_copy(ctx.service),
         consumer = cycle_aware_deep_copy(ctx.authenticated_consumer),
         client_ip = var.remote_addr,
         started_at = okong.request.get_start_time(),
-
         workspace = ctx.workspace,
         workspace_name = get_workspace_name(),
-      }
+      })
 
-      return edit_result(ctx, root)
+      return root
     end
   end
 end