fix(pdk): use deep copies of Route, Service, and Consumer objects whe…

…n log serialize (#11566)

In the function of `kong.log.serialize`, the lifecycle of
three table `ctx.route`, `ctx.service` and `ctx.authenticated_consumer`
is across request. Modifying the sub-items in the current request of
the table will affect the next request, resulting in unexpected behavior
in Kong.

Fix FTI-5357

---------

Signed-off-by: sabertobihwy <sabertobihwy@gmail.com>

CHANGELOG/unreleased/kong/11566.yaml

@@ -0,0 +1,7 @@
+message: "use deep copies of Route, Service, and Consumer objects when log serializing"
+type: bugfix
+scope: PDK
+prs:
+  - 11566
+jiras:
+  - "FTI-5357"

kong/pdk/log.lua

@@ -16,7 +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 cycle_aware_deep_copy = utils.cycle_aware_deep_copy
 
 local sub = string.sub
 local type = type
@@ -802,7 +802,7 @@ do
         end
       end
 
-      -- The value of upstream_status is a string, and status codes may be 
+      -- The value of upstream_status is a string, and status codes may be
       -- seperated by comma or grouped by colon, according to
       -- the nginx doc: http://nginx.org/en/docs/http/ngx_http_upstream_module.html#upstream_status
       local upstream_status = var.upstream_status or ""
@@ -832,9 +832,9 @@ do
         },
         tries = (ctx.balancer_data or {}).tries,
         authenticated_entity = build_authenticated_entity(ctx),
-        route = ctx.route,
-        service = ctx.service,
-        consumer = ctx.authenticated_consumer,
+        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(),
       }
@@ -873,9 +873,9 @@ do
         },
         tries = (ctx.balancer_data or {}).tries,
         authenticated_entity = build_authenticated_entity(ctx),
-        route = ctx.route,
-        service = ctx.service,
-        consumer = ctx.authenticated_consumer,
+        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(),
       }

spec/01-unit/10-log_serializer_spec.lua

@@ -31,7 +31,7 @@ describe("kong.log.serialize", function()
           bytes_sent = "99",
           request_time = "2",
           remote_addr = "1.1.1.1",
-          -- may be a non-numeric string, 
+          -- may be a non-numeric string,
           -- see http://nginx.org/en/docs/http/ngx_http_upstream_module.html#var_upstream_addr
           upstream_status = "500, 200 : 200, 200",
         },
@@ -116,7 +116,7 @@ describe("kong.log.serialize", function()
       end)
 
       it("serializes the Consumer object", function()
-        ngx.ctx.authenticated_consumer = {id = "someconsumer"}
+        ngx.ctx.authenticated_consumer = { id = "someconsumer" }
 
         local res = kong.log.serialize({ngx = ngx, kong = kong, })
         assert.is_table(res)
@@ -186,6 +186,20 @@ describe("kong.log.serialize", function()
 
         assert.equal("/upstream_uri" .. "?" .. args, res.upstream_uri)
       end)
+
+      it("use the deep copies of the Route, Service, Consumer object avoid " ..
+         "modify ctx.authenticated_consumer, ctx.route, ctx.service", function()
+        ngx.ctx.authenticated_consumer = { id = "someconsumer" }
+        ngx.ctx.route = { id = "my_route" }
+        ngx.ctx.service = { id = "my_service" }
+        local res = kong.log.serialize({ngx = ngx, kong = kong, })
+        assert.not_equal(tostring(ngx.ctx.authenticated_consumer),
+                         tostring(res.consumer))
+        assert.not_equal(tostring(ngx.ctx.route),
+                         tostring(res.route))
+        assert.not_equal(tostring(ngx.ctx.service),
+                         tostring(res.service))
+      end)
     end)
   end)
 
@@ -283,7 +297,7 @@ describe("kong.log.serialize", function()
       end)
 
       it("serializes the Consumer object", function()
-        ngx.ctx.authenticated_consumer = {id = "someconsumer"}
+        ngx.ctx.authenticated_consumer = { id = "someconsumer" }
 
         local res = kong.log.serialize({ngx = ngx, kong = kong, })
         assert.is_table(res)
@@ -341,6 +355,20 @@ describe("kong.log.serialize", function()
 
         assert.is_nil(res.tries)
       end)
+
+      it("use the deep copies of the Route, Service, Consumer object avoid " ..
+         "modify ctx.authenticated_consumer, ctx.route, ctx.service", function()
+        ngx.ctx.authenticated_consumer = { id = "someconsumer "}
+        ngx.ctx.route = { id = "my_route" }
+        ngx.ctx.service = { id = "my_service" }
+        local res = kong.log.serialize({ngx = ngx, kong = kong, })
+        assert.not_equal(tostring(ngx.ctx.authenticated_consumer),
+                         tostring(res.consumer))
+        assert.not_equal(tostring(ngx.ctx.route),
+                         tostring(res.route))
+        assert.not_equal(tostring(ngx.ctx.service),
+                         tostring(res.service))
+      end)
     end)
   end)
 end)