fix(pdk): fix log serialize upstream_status entry nil bug in subrequ…

…est case (#12953)

FTI-5844

changelog/unreleased/kong/fix-log-upstream-status-nil-subrequest.yml

@@ -0,0 +1,4 @@
+message: |
+  **PDK**: Fixed a bug that log serializer will log `upstream_status` as nil in the requests that contains subrequest
+type: bugfix
+scope: PDK

kong/pdk/log.lua

@@ -814,10 +814,7 @@ do
         end
       end
 
-      -- 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 ""
+      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]

spec/03-plugins/04-file-log/01-log_spec.lua

@@ -247,6 +247,36 @@ for _, strategy in helpers.each_strategy() do
         },
       }
 
+      local route10 = bp.routes:insert {
+        hosts = { "file_logging10.test" },
+        response_buffering = true,
+      }
+
+      bp.plugins:insert({
+        name = "pre-function",
+        route = { id = route10.id },
+        config = {
+          access = {
+            [[
+              kong.service.request.enable_buffering()
+            ]],
+          },
+        }
+      })
+
+      bp.plugins:insert {
+        route = { id = route10.id },
+        name     = "file-log",
+        config   = {
+          path   = FILE_LOG_PATH,
+          reopen = true,
+          custom_fields_by_lua = {
+            new_field = "return 123",
+            route = "return nil", -- unset route field
+          },
+        },
+      }
+
       assert(helpers.start_kong({
         database   = strategy,
         nginx_conf = "spec/fixtures/custom_nginx.template",
@@ -337,6 +367,28 @@ for _, strategy in helpers.each_strategy() do
         assert.is_number(log_message.response.size)
         assert.same(nil, log_message.route)
       end)
+      it("correct upstream status when we use response phase", function()
+        local uuid = random_string()
+
+        -- Making the request
+        local res = assert(proxy_client:send({
+          method = "GET",
+          path = "/status/200",
+          headers = {
+            ["file-log-uuid"] = uuid,
+            ["Host"] = "file_logging10.test"
+          }
+        }))
+        assert.res_status(200, res)
+
+        local log_message = wait_for_json_log_entry()
+        assert.same("127.0.0.1", log_message.client_ip)
+        assert.same(uuid, log_message.request.headers["file-log-uuid"])
+        assert.is_number(log_message.request.size)
+        assert.is_number(log_message.response.size)
+        assert.same(nil, log_message.route)
+        assert.same(200, log_message.upstream_status)
+      end)
     end)
 
     it("logs to file #grpc", function()

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

@@ -66,7 +66,12 @@ qq{
                         },
                        response = {
                           get_source = function() return "service" end,
-                       },
+                        },
+                       service = {
+                          response = {
+                            get_status = function() return 200 end,
+                          },
+                        },
                      }
                   }
                 },