From f7dcccdb1c65bea1676594ef877f56fe90e9524c Mon Sep 17 00:00:00 2001 From: Michael Martin Date: Wed, 27 Mar 2024 09:55:20 -0700 Subject: [PATCH] fix(log-serializer): do not add receive time to `latencies.kong` --- .../unreleased/kong/log-serializer-kong-latency.yml | 10 ++++++++++ kong/pdk/log.lua | 3 +-- spec/01-unit/10-log_serializer_spec.lua | 6 ++++-- 3 files changed, 15 insertions(+), 4 deletions(-) create mode 100644 changelog/unreleased/kong/log-serializer-kong-latency.yml diff --git a/changelog/unreleased/kong/log-serializer-kong-latency.yml b/changelog/unreleased/kong/log-serializer-kong-latency.yml new file mode 100644 index 00000000000..b1760fca7df --- /dev/null +++ b/changelog/unreleased/kong/log-serializer-kong-latency.yml @@ -0,0 +1,10 @@ +message: | + The value of `latencies.kong` in the log serializer payload no longer includes + the response receive time, so it now has the same value as the + `X-Kong-Proxy-Latency` response header. Response receive time is recorded in + the new `latencies.receive` metric, so if desired, the old value can be + calculated as `latencies.kong + latencies.receive`. **Note:** this also + affects payloads from all logging plugins that use the log serializer: + `file-log`, `tcp-log`, `udp-log`,`http-log`, `syslog`, and `loggly`. +type: bugfix +scope: PDK diff --git a/kong/pdk/log.lua b/kong/pdk/log.lua index a4c0d077d21..96f696e36ae 100644 --- a/kong/pdk/log.lua +++ b/kong/pdk/log.lua @@ -841,8 +841,7 @@ do size = to_decimal(var.bytes_sent), }, latencies = { - kong = (ctx.KONG_PROXY_LATENCY or ctx.KONG_RESPONSE_LATENCY or 0) + - (ctx.KONG_RECEIVE_TIME or 0), + kong = ctx.KONG_PROXY_LATENCY or ctx.KONG_RESPONSE_LATENCY or 0, proxy = ctx.KONG_WAITING_TIME or -1, request = tonumber(var.request_time) * 1000, receive = ctx.KONG_RECEIVE_TIME or 0, diff --git a/spec/01-unit/10-log_serializer_spec.lua b/spec/01-unit/10-log_serializer_spec.lua index 7c2d45dbfeb..682e7fbd7e4 100644 --- a/spec/01-unit/10-log_serializer_spec.lua +++ b/spec/01-unit/10-log_serializer_spec.lua @@ -21,6 +21,8 @@ describe("kong.log.serialize", function() }, }, KONG_PROXIED = true, + KONG_RECEIVE_TIME = 100, + KONG_PROXY_LATENCY = 200, }, var = { kong_request_id = "1234", @@ -73,10 +75,10 @@ describe("kong.log.serialize", function() -- Latencies assert.is_table(res.latencies) - assert.equal(0, res.latencies.kong) + assert.equal(200, res.latencies.kong) assert.equal(-1, res.latencies.proxy) assert.equal(2000, res.latencies.request) - assert.equal(0, res.latencies.receive) + assert.equal(100, res.latencies.receive) -- Request assert.is_table(res.request)