feat(log-serializer): add source property to log-serializer (#12052)

changelog/unreleased/kong/log-serializer-source-property.yml

@@ -0,0 +1,3 @@
+message: 'Add `source` property to log serializer, indicating the response is generated by `kong` or `upstream`.'
+type: feature
+scope: Core

kong/constants.lua

@@ -253,6 +253,19 @@ local constants = {
   SCHEMA_NAMESPACES = {
     PROXY_WASM_FILTERS = "proxy-wasm-filters",
   },
+
+  RESPONSE_SOURCE = {
+    TYPES = {
+      ERROR = "error",
+      EXIT = "exit",
+      SERVICE = "service",
+    },
+    NAMES = {
+      error = "kong",
+      exit = "kong",
+      service = "upstream",
+    }
+  }
 }
 
 for _, v in ipairs(constants.CLUSTERING_SYNC_STATUS) do

kong/pdk/log.lua

@@ -18,6 +18,7 @@ local ngx_ssl = require "ngx.ssl"
 local phase_checker = require "kong.pdk.private.phases"
 local utils = require "kong.tools.utils"
 local cycle_aware_deep_copy = utils.cycle_aware_deep_copy
+local constants = require "kong.constants"
 
 local sub = string.sub
 local type = type
@@ -46,6 +47,7 @@ local _DEFAULT_NAMESPACED_FORMAT = "%file_src:%line_src [%namespace] %message"
 local PHASES = phase_checker.phases
 local PHASES_LOG = PHASES.log
 local QUESTION_MARK = byte("?")
+local TYPE_NAMES = constants.RESPONSE_SOURCE.NAMES
 
 local phases_with_ctx =
     phase_checker.new(PHASES.rewrite,
@@ -817,6 +819,9 @@ do
       -- the nginx doc: http://nginx.org/en/docs/http/ngx_http_upstream_module.html#upstream_status
       local upstream_status = var.upstream_status or ""
 
+      local response_source = okong.response.get_source(ongx.ctx)
+      local response_source_name = TYPE_NAMES[response_source]
+
       local root = {
         request = {
           id = request_id_get() or "",
@@ -848,6 +853,7 @@ do
         consumer = cycle_aware_deep_copy(ctx.authenticated_consumer),
         client_ip = var.remote_addr,
         started_at = okong.request.get_start_time(),
+        source = response_source_name,
       }
 
       return edit_result(ctx, root)

kong/pdk/response.lua

@@ -18,6 +18,7 @@ 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 constants = require "kong.constants"
 
 
 local ngx = ngx
@@ -40,6 +41,7 @@ local is_http_subsystem = ngx and ngx.config.subsystem == "http"
 if is_http_subsystem then
   add_header = require("ngx.resp").add_header
 end
+local RESPONSE_SOURCE_TYPES = constants.RESPONSE_SOURCE.TYPES
 
 
 local PHASES = phase_checker.phases
@@ -349,15 +351,15 @@ local function new(self, major_version)
     end
 
     if ctx.KONG_UNEXPECTED then
-      return "error"
+      return RESPONSE_SOURCE_TYPES.ERROR
     end
 
     if ctx.KONG_EXITED then
-      return "exit"
+      return RESPONSE_SOURCE_TYPES.EXIT
     end
 
     if ctx.KONG_PROXIED then
-      return "service"
+      return RESPONSE_SOURCE_TYPES.SERVICE
     end
 
     return "error"

spec/01-unit/10-log_serializer_spec.lua

@@ -20,6 +20,7 @@ describe("kong.log.serialize", function()
               },
             },
           },
+          KONG_PROXIED = true,
         },
         var = {
           kong_request_id = "1234",
@@ -43,7 +44,7 @@ describe("kong.log.serialize", function()
           get_uri_args = function() return {"arg1", "arg2"} end,
           get_method = function() return "POST" end,
           get_headers = function() return {header1 = "header1", header2 = "header2", authorization = "authorization"} end,
-          start_time = function() return 3 end
+          start_time = function() return 3 end,
         },
         resp = {
           get_headers = function() return {header1 = "respheader1", header2 = "respheader2", ["set-cookie"] = "delicious=delicacy"} end
@@ -99,6 +100,8 @@ describe("kong.log.serialize", function()
 
         -- Tries
         assert.is_table(res.tries)
+
+        assert.equal("upstream", res.source)
       end)
 
       it("uses port map (ngx.ctx.host_port) for request url ", function()
@@ -173,6 +176,24 @@ describe("kong.log.serialize", function()
           }, res.tries)
       end)
 
+      it("serializes the response.source", function()
+        ngx.ctx.KONG_EXITED = true
+        ngx.ctx.KONG_PROXIED = nil
+        ngx.ctx.KONG_UNEXPECTED = nil
+
+        local res = kong.log.serialize({ngx = ngx, kong = kong, })
+        assert.is_table(res)
+        assert.same("kong", res.source)
+
+        ngx.ctx.KONG_UNEXPECTED = nil
+        ngx.ctx.KONG_EXITED = nil
+        ngx.ctx.KONG_PROXIED = nil
+
+        local res = kong.log.serialize({ngx = ngx, kong = kong, })
+        assert.is_table(res)
+        assert.same("kong", res.source)
+      end)
+
       it("does not fail when the 'balancer_data' structure is missing", function()
         ngx.ctx.balancer_data = nil
 

t/01-pdk/02-log/00-phase_checks.t

@@ -64,6 +64,9 @@ qq{
                           get_headers = function() return {} end,
                           get_start_time = function() return 1 end,
                         },
+                       response = {
+                          get_source = function() return "service" end,
+                       },
                      }
                   }
                 },