From 1994d79b8fb1c0a2b9429d35999955e7c2e4f307 Mon Sep 17 00:00:00 2001 From: samugi Date: Thu, 28 Sep 2023 17:46:49 +0800 Subject: [PATCH] feat(request-id): introduce unique Request ID (#11663) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * feat(request-id): add Request ID * Add an immutable request ID * Include request ID + trace and correlation IDs to the log serializer * update Access log and Error log to append request id * update the error templates to include the request id * Bump lua-kong-nginx-module to version 0.7.1 * Use the new directive `lua_kong_error_log_request_id` introduced in 0.7.0 which adds the request id to the error log output Includes: * unit tests for the new `request_id` module * integration tests to check: * request id, correlation id, trace ids are added to log serializer * feat(request-id): add request-id to error templates * feat(request-id): request ID header + span attribute * add the x-kong-request-id downstream header which contains the value of the request_id, and can be controlled via the `headers` config option * add the x-kong-request-id upstream header which contains the value of the request_id, and can be controlled via the `headers_upstream` config option * add the `kong.request.id` span attribute which contains the value of the request_id * tests for all the above * docs(conf): request ID Co-authored-by: Enrique García Cota * feat(request-id): address PR feedback * rephrase log messages * remove unneeded conditional * better changelog * use upvalues to cache headers access * use request id instead of kong_request_id (no longer needed as we don't need write access) * cache locals in hot path * improved performance of add_trace_id_formats function * refactored docs in kong.conf.default * perf: cache `request_id.get()` at the module level KAG-2034 FTI-4837 --------- Co-authored-by: Enrique García Cota Co-authored-by: Qi --- .requirements | 2 +- .../kong/lua_kong_nginx_module_bump.yml | 3 + changelog/unreleased/kong/request_id.yml | 6 + kong-2.8.4-0.rockspec | 2 + kong.conf.default | 18 +- kong/conf_loader/init.lua | 35 +- kong/constants.lua | 1 + kong/error_handlers.lua | 4 +- kong/pdk/log.lua | 15 +- kong/pdk/response.lua | 4 +- kong/plugins/correlation-id/handler.lua | 2 + kong/plugins/zipkin/tracing_headers.lua | 88 ++++- kong/runloop/handler.lua | 74 ++-- kong/templates/kong_defaults.lua | 3 +- kong/templates/nginx_kong.lua | 11 +- kong/tools/utils.lua | 7 +- kong/tracing/request_id.lua | 44 +++ spec/01-unit/04-prefix_handler_spec.lua | 4 +- spec/01-unit/10-log_serializer_spec.lua | 8 + .../01-unit/26-tracing/03-request-id_spec.lua | 62 ++++ spec/02-integration/05-proxy/06-ssl_spec.lua | 8 +- .../05-proxy/12-error_default_type_spec.lua | 25 +- .../05-proxy/13-error_handlers_spec.lua | 2 +- .../05-proxy/18-upstream_tls_spec.lua | 16 +- .../05-proxy/33-request-id-header_spec.lua | 333 ++++++++++++++++++ .../10-go_plugins/01-reports_spec.lua | 10 +- .../14-tracing/04-trace-ids-log_spec.lua | 200 +++++++++++ .../03-plugins/09-key-auth/02-access_spec.lua | 46 ++- .../10-basic-auth/03-access_spec.lua | 18 +- .../10-basic-auth/05-declarative_spec.lua | 3 +- .../11-correlation-id/01-access_spec.lua | 66 +++- .../01-access_spec.lua | 18 +- .../14-request-termination/02-access_spec.lua | 1 + .../17-ip-restriction/02-access_spec.lua | 67 ++-- spec/03-plugins/18-acl/02-access_spec.lua | 51 ++- .../19-hmac-auth/03-access_spec.lua | 6 +- .../23-rate-limiting/04-access_spec.lua | 46 ++- .../02-access_spec.lua | 9 +- .../34-zipkin/tracing_headers_spec.lua | 3 +- t/01-pdk/08-response/13-error.t | 104 +++--- 40 files changed, 1221 insertions(+), 204 deletions(-) create mode 100644 changelog/unreleased/kong/lua_kong_nginx_module_bump.yml create mode 100644 changelog/unreleased/kong/request_id.yml create mode 100644 kong/tracing/request_id.lua create mode 100644 spec/01-unit/26-tracing/03-request-id_spec.lua create mode 100644 spec/02-integration/05-proxy/33-request-id-header_spec.lua create mode 100644 spec/02-integration/14-tracing/04-trace-ids-log_spec.lua diff --git a/.requirements b/.requirements index 2dacfc1c3b5..bef9f855a60 100644 --- a/.requirements +++ b/.requirements @@ -9,4 +9,4 @@ RESTY_PCRE_VERSION=8.45 LIBYAML_VERSION=0.2.5 KONG_GO_PLUGINSERVER_VERSION=v0.6.1 KONG_BUILD_TOOLS_VERSION=4.40.1 -KONG_NGINX_MODULE_BRANCH=0.2.1 +KONG_NGINX_MODULE_BRANCH=0.2.2 diff --git a/changelog/unreleased/kong/lua_kong_nginx_module_bump.yml b/changelog/unreleased/kong/lua_kong_nginx_module_bump.yml new file mode 100644 index 00000000000..0062a00d4f0 --- /dev/null +++ b/changelog/unreleased/kong/lua_kong_nginx_module_bump.yml @@ -0,0 +1,3 @@ +message: Bump lua-kong-nginx-module from 0.2.1 to 0.2.2 +type: dependency +scope: Core diff --git a/changelog/unreleased/kong/request_id.yml b/changelog/unreleased/kong/request_id.yml new file mode 100644 index 00000000000..39d4daa08fc --- /dev/null +++ b/changelog/unreleased/kong/request_id.yml @@ -0,0 +1,6 @@ +message: > + A unique Request ID is now populated in the error log, access log, error templates, + log serializer, and in a new X-Kong-Request-Id header (configurable for upstream/downstream + using the `headers` and `headers_upstream` configuration options). +type: feature +scope: Core diff --git a/kong-2.8.4-0.rockspec b/kong-2.8.4-0.rockspec index c06749548cb..39e4ac10218 100644 --- a/kong-2.8.4-0.rockspec +++ b/kong-2.8.4-0.rockspec @@ -472,5 +472,7 @@ build = { ["kong.vaults.env"] = "kong/vaults/env/init.lua", ["kong.vaults.env.schema"] = "kong/vaults/env/schema.lua", + + ["kong.tracing.request_id"] = "kong/tracing/request_id.lua", } } diff --git a/kong.conf.default b/kong.conf.default index 4c91e39dd3f..73dd51acd3b 100644 --- a/kong.conf.default +++ b/kong.conf.default @@ -667,7 +667,7 @@ # # See docs for `ssl_cert_key` for detailed usage. -#headers = server_tokens, latency_tokens +#headers = server_tokens, latency_tokens, X-Kong-Request-Id # Comma-separated list of headers Kong should # inject in client responses. # @@ -697,6 +697,8 @@ # This is particularly useful for clients to # distinguish upstream statuses if the # response is rewritten by a plugin. + # - `X-Kong-Request-Id`: Unique identifier of + # the request. # - `server_tokens`: Same as specifying both # `Server` and `Via`. # - `latency_tokens`: Same as specifying @@ -713,6 +715,20 @@ # # Example: `headers = via, latency_tokens` +#headers_upstream = X-Kong-Request-Id + # Comma-separated list of headers Kong should + # inject in requests to upstream. + # + # At this time, the only accepted value is: + # - `X-Kong-Request-Id`: Unique identifier of + # the request. + # + # In addition, this value can be set + # to `off`, which prevents Kong from injecting + # the above header. Note that this + # does not prevent plugins from injecting + # headers of their own. + #trusted_ips = # Defines trusted IP addresses blocks that are # known to send correct `X-Forwarded-*` # headers. diff --git a/kong/conf_loader/init.lua b/kong/conf_loader/init.lua index feb873d99db..4bb20604c06 100644 --- a/kong/conf_loader/init.lua +++ b/kong/conf_loader/init.lua @@ -107,6 +107,11 @@ local HEADER_KEY_TO_NAME = { [string.lower(HEADERS.ADMIN_LATENCY)] = HEADERS.ADMIN_LATENCY, [string.lower(HEADERS.UPSTREAM_LATENCY)] = HEADERS.UPSTREAM_LATENCY, [string.lower(HEADERS.UPSTREAM_STATUS)] = HEADERS.UPSTREAM_STATUS, + [string.lower(HEADERS.REQUEST_ID)] = HEADERS.REQUEST_ID, +} + +local UPSTREAM_HEADER_KEY_TO_NAME = { + [string.lower(HEADERS.REQUEST_ID)] = HEADERS.REQUEST_ID, } @@ -407,6 +412,7 @@ local CONF_INFERENCES = { upstream_keepalive_idle_timeout = { typ = "number" }, headers = { typ = "array" }, + headers_upstream = { typ = "array" }, trusted_ips = { typ = "array" }, real_ip_header = { typ = "string", @@ -970,6 +976,15 @@ local function check_and_infer(conf, opts) end end + if conf.headers_upstream then + for _, token in ipairs(conf.headers_upstream) do + if token ~= "off" and not UPSTREAM_HEADER_KEY_TO_NAME[string.lower(token)] then + errors[#errors + 1] = fmt("headers_upstream: invalid entry '%s'", + tostring(token)) + end + end + end + if conf.dns_resolver then for _, server in ipairs(conf.dns_resolver) do local dns = utils.normalize_ip(server) @@ -1689,8 +1704,9 @@ local function load(path, custom_conf, opts) do -- load headers configuration - local enabled_headers = {} + -- (downstream) + local enabled_headers = {} for _, v in pairs(HEADER_KEY_TO_NAME) do enabled_headers[v] = false end @@ -1716,6 +1732,23 @@ local function load(path, custom_conf, opts) end conf.enabled_headers = setmetatable(enabled_headers, _nop_tostring_mt) + + + -- (upstream) + local enabled_headers_upstream = {} + for _, v in pairs(UPSTREAM_HEADER_KEY_TO_NAME) do + enabled_headers_upstream[v] = false + end + + if #conf.headers_upstream > 0 and conf.headers_upstream[1] ~= "off" then + for _, token in ipairs(conf.headers_upstream) do + if token ~= "off" then + enabled_headers_upstream[UPSTREAM_HEADER_KEY_TO_NAME[string.lower(token)]] = true + end + end + end + + conf.enabled_headers_upstream = setmetatable(enabled_headers_upstream, _nop_tostring_mt) end -- load absolute paths diff --git a/kong/constants.lua b/kong/constants.lua index f38bb11fe28..bc41182bd5b 100644 --- a/kong/constants.lua +++ b/kong/constants.lua @@ -107,6 +107,7 @@ local constants = { FORWARDED_PATH = "X-Forwarded-Path", FORWARDED_PREFIX = "X-Forwarded-Prefix", ANONYMOUS = "X-Anonymous-Consumer", + REQUEST_ID = "X-Kong-Request-Id", VIA = "Via", SERVER = "Server" }, diff --git a/kong/error_handlers.lua b/kong/error_handlers.lua index 117756305c6..9054337e218 100644 --- a/kong/error_handlers.lua +++ b/kong/error_handlers.lua @@ -2,6 +2,7 @@ local kong = kong local find = string.find local fmt = string.format local utils = require "kong.tools.utils" +local request_id = require "kong.tracing.request_id" local CONTENT_TYPE = "Content-Type" @@ -45,7 +46,8 @@ return function(ctx) else local mime_type = utils.get_mime_type(accept_header) - message = fmt(utils.get_error_template(mime_type), message) + local rid = request_id.get() or "" + message = fmt(utils.get_error_template(mime_type), message, rid) headers = { [CONTENT_TYPE] = mime_type } end diff --git a/kong/pdk/log.lua b/kong/pdk/log.lua index c68c1641e26..a7ee98b9915 100644 --- a/kong/pdk/log.lua +++ b/kong/pdk/log.lua @@ -32,6 +32,7 @@ local ngx = ngx local kong = kong local check_phase = phase_checker.check local split = utils.split +local request_id_get = require "kong.tracing.request_id".get local _PREFIX = "[kong] " @@ -696,6 +697,7 @@ do -- The following fields are included in the returned table: -- * `client_ip` - client IP address in textual format. -- * `latencies` - request/proxy latencies. + -- * `request.id` - request id. -- * `request.headers` - request headers. -- * `request.method` - request method. -- * `request.querystring` - request query strings. @@ -720,6 +722,12 @@ do -- * `request.tls.cipher` - TLS/SSL cipher used by the connection. -- * `request.tls.client_verify` - mTLS validation result. Contents are the same as described in [$ssl_client_verify](https://nginx.org/en/docs/http/ngx_http_ssl_module.html#var_ssl_client_verify). -- + -- The following field is only present in requests where a tracing plugin (OpenTelemetry or Zipkin) is executed: + -- * `trace_id` - trace ID. + -- + -- The following field is only present in requests where the Correlation ID plugin is executed: + -- * `correlation_id` - correlation ID. + -- -- **Warning:** This function may return sensitive data (e.g., API keys). -- Consider filtering before writing it to unsecured locations. -- @@ -783,6 +791,7 @@ do return edit_result(ctx, { request = { + id = request_id_get() or "", uri = request_uri, url = var.scheme .. "://" .. var.host .. ":" .. host_port .. request_uri, querystring = okong.request.get_query(), -- parameters, as a table @@ -909,14 +918,14 @@ local function new_log(namespace, format) if not buf then error(err, 2) end - + for log_lvl_name, log_lvl in pairs(_LEVELS) do - self[log_lvl_name] = gen_log_func(log_lvl, buf) + self[log_lvl_name] = gen_log_func(log_lvl, buf) end self.deprecation = new_deprecation(gen_log_func(_LEVELS.warn, buf, nil, 5)) end - + self.set_format(format) self.inspect = new_inspect(namespace) diff --git a/kong/pdk/response.lua b/kong/pdk/response.lua index 4677b64c31f..bd799bcad4b 100644 --- a/kong/pdk/response.lua +++ b/kong/pdk/response.lua @@ -16,6 +16,7 @@ local cjson = require "cjson.safe" 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 ngx = ngx @@ -1145,7 +1146,8 @@ local function new(self, major_version) local actual_message = message or HTTP_MESSAGES["s" .. status] or fmt(HTTP_MESSAGES.default, status) - body = fmt(utils.get_error_template(content_type), actual_message) + local rid = request_id.get() or "" + body = fmt(utils.get_error_template(content_type), actual_message, rid) end local ctx = ngx.ctx diff --git a/kong/plugins/correlation-id/handler.lua b/kong/plugins/correlation-id/handler.lua index 338da18885f..a7941256076 100644 --- a/kong/plugins/correlation-id/handler.lua +++ b/kong/plugins/correlation-id/handler.lua @@ -62,6 +62,8 @@ function CorrelationIdHandler:access(conf) end end + kong.log.set_serialize_value("correlation_id", correlation_id) + if conf.echo_downstream then -- For later use, to echo it back downstream kong.ctx.plugin.correlation_id = correlation_id diff --git a/kong/plugins/zipkin/tracing_headers.lua b/kong/plugins/zipkin/tracing_headers.lua index 89c83446957..c503ab6607e 100644 --- a/kong/plugins/zipkin/tracing_headers.lua +++ b/kong/plugins/zipkin/tracing_headers.lua @@ -364,6 +364,52 @@ local function find_header_type(headers) end +-- Performs a table merge to add trace ID formats to the current request's +-- trace ID and returns a table containing all the formats. +-- +-- Plugins can handle different formats of trace ids depending on their headers +-- configuration, multiple plugins executions may result in additional formats +-- of the current request's trace id. +-- +-- The `propagation_trace_id_all_fmt` table is stored in `ngx.ctx` to keep the +-- list of formats updated for the current request. +-- +-- Each item in the resulting `propagation_trace_id_all_fmt` table represents a +-- format associated with the trace ID for the current request. +-- +-- @param trace_id_new_fmt table containing the trace ID formats to be added +-- @returns propagation_trace_id_all_fmt table contains all the formats for +-- the current request +-- +-- @example +-- +-- propagation_trace_id_all_fmt = { datadog = "1234", +-- w3c = "abcd" } +-- +-- trace_id_new_fmt = { ot = "abcd", +-- w3c = "abcd" } +-- +-- propagation_trace_id_all_fmt = { datadog = "1234", +-- ot = "abcd", +-- w3c = "abcd" } +-- +local function add_trace_id_formats(trace_id_new_fmt) + -- TODO: @samugi - move trace ID table in the unified tracing context + local trace_id_all_fmt = ngx.ctx.propagation_trace_id_all_fmt + if not trace_id_all_fmt then + ngx.ctx.propagation_trace_id_all_fmt = trace_id_new_fmt + return trace_id_new_fmt + end + + -- add new formats to trace ID formats table + for format, value in pairs(trace_id_new_fmt) do + trace_id_all_fmt[format] = value + end + + return trace_id_all_fmt +end + + local function parse(headers, conf_header_type) if conf_header_type == "ignore" then return nil @@ -417,9 +463,24 @@ local function set(conf_header_type, found_header_type, proxy_span, conf_default found_header_type = found_header_type or conf_default_header_type or "b3" + -- contains all the different formats of the current trace ID, with zero or + -- more of the following entries: + -- { + -- ["b3"] = "", -- the trace_id when the request has a b3 or X-B3-TraceId (zipkin) header + -- ["w3c"] = "", -- the trace_id when the request has a W3C header + -- ["jaeger"] = "", -- the trace_id when the request has a jaeger tracing header + -- ["ot"] = "", -- the trace_id when the request has an OpenTelemetry tracing header + -- ["aws"] = "", -- the trace_id when the request has an aws tracing header + -- ["gcp"] = "", -- the trace_id when the request has a gcp tracing header + -- } + local trace_id_formats = {} + if conf_header_type == "b3" or found_header_type == "b3" then - set_header("x-b3-traceid", to_hex(proxy_span.trace_id)) + local trace_id = to_hex(proxy_span.trace_id) + trace_id_formats.b3 = trace_id + + set_header("x-b3-traceid", trace_id) set_header("x-b3-spanid", to_hex(proxy_span.span_id)) if proxy_span.parent_id then set_header("x-b3-parentspanid", to_hex(proxy_span.parent_id)) @@ -433,30 +494,43 @@ local function set(conf_header_type, found_header_type, proxy_span, conf_default end if conf_header_type == "b3-single" or found_header_type == "b3-single" then + local trace_id = to_hex(proxy_span.trace_id) + trace_id_formats.b3 = trace_id + set_header("b3", fmt("%s-%s-%s-%s", - to_hex(proxy_span.trace_id), + trace_id, to_hex(proxy_span.span_id), proxy_span.should_sample and "1" or "0", to_hex(proxy_span.parent_id))) end if conf_header_type == "w3c" or found_header_type == "w3c" then + local trace_id = to_hex(proxy_span.trace_id) + trace_id_formats.w3c = trace_id + set_header("traceparent", fmt("00-%s-%s-%s", - to_hex(proxy_span.trace_id), + trace_id, to_hex(proxy_span.span_id), proxy_span.should_sample and "01" or "00")) end if conf_header_type == "jaeger" or found_header_type == "jaeger" then + local trace_id = to_hex(proxy_span.trace_id) + trace_id_formats.jaeger = trace_id + set_header("uber-trace-id", fmt("%s:%s:%s:%s", - to_hex(proxy_span.trace_id), + trace_id, to_hex(proxy_span.span_id), to_hex(proxy_span.parent_id), proxy_span.should_sample and "01" or "00")) end if conf_header_type == "ot" or found_header_type == "ot" then - set_header("ot-tracer-traceid", to_hex(proxy_span.trace_id)) + local trace_id = to_hex(proxy_span.trace_id) + trace_id_formats.ot = trace_id + + set_header("ot-tracer-traceid", trace_id) + set_header("ot-tracer-spanid", to_hex(proxy_span.span_id)) set_header("ot-tracer-sampled", proxy_span.should_sample and "1" or "0") @@ -469,6 +543,10 @@ local function set(conf_header_type, found_header_type, proxy_span, conf_default -- XXX: https://github.com/opentracing/specification/issues/117 set_header("uberctx-"..key, ngx.escape_uri(value)) end + + trace_id_formats = add_trace_id_formats(trace_id_formats) + -- add trace IDs to log serializer output + kong.log.set_serialize_value("trace_id", trace_id_formats) end diff --git a/kong/runloop/handler.lua b/kong/runloop/handler.lua index 20a43270d25..0ce909baecb 100644 --- a/kong/runloop/handler.lua +++ b/kong/runloop/handler.lua @@ -12,35 +12,38 @@ local concurrency = require "kong.concurrency" local declarative = require "kong.db.declarative" local workspaces = require "kong.workspaces" local lrucache = require "resty.lrucache" +local request_id = require "kong.tracing.request_id" local PluginsIterator = require "kong.runloop.plugins_iterator" -local kong = kong -local type = type -local ipairs = ipairs -local tostring = tostring -local tonumber = tonumber -local setmetatable = setmetatable -local sub = string.sub -local byte = string.byte -local gsub = string.gsub -local find = string.find -local lower = string.lower -local fmt = string.format -local ngx = ngx -local var = ngx.var -local log = ngx.log -local exit = ngx.exit -local exec = ngx.exec -local header = ngx.header -local timer_at = ngx.timer.at -local subsystem = ngx.config.subsystem -local clear_header = ngx.req.clear_header -local http_version = ngx.req.http_version -local unpack = unpack -local escape = require("kong.tools.uri").escape +local kong = kong +local type = type +local ipairs = ipairs +local tostring = tostring +local tonumber = tonumber +local setmetatable = setmetatable +local sub = string.sub +local byte = string.byte +local gsub = string.gsub +local find = string.find +local lower = string.lower +local fmt = string.format +local ngx = ngx +local var = ngx.var +local log = ngx.log +local exit = ngx.exit +local exec = ngx.exec +local header = ngx.header +local set_header = ngx.req.set_header +local timer_at = ngx.timer.at +local subsystem = ngx.config.subsystem +local clear_header = ngx.req.clear_header +local http_version = ngx.req.http_version +local request_id_get = request_id.get +local unpack = unpack +local escape = require("kong.tools.uri").escape local is_http_module = subsystem == "http" @@ -1470,6 +1473,9 @@ return { end, -- Only executed if the `router` module found a route and allows nginx to proxy it. after = function(ctx) + local enabled_headers_upstream = kong.configuration.enabled_headers_upstream + local headers = constants.HEADERS + -- Nginx's behavior when proxying a request with an empty querystring -- `/foo?` is to keep `$is_args` an empty string, hence effectively -- stripping the empty querystring. @@ -1551,6 +1557,16 @@ return { if var.http_proxy_connection then clear_header("Proxy-Connection") end + + -- X-Kong-Request-Id upstream header + local rid, rid_get_err = request_id_get() + if not rid then + log(WARN, "failed to get Request ID: ", rid_get_err) + end + + if enabled_headers_upstream[headers.REQUEST_ID] and rid then + set_header(headers.REQUEST_ID, rid) + end end }, response = { @@ -1639,6 +1655,16 @@ return { end end end + + -- X-Kong-Request-Id downstream header + local rid, rid_get_err = request_id_get() + if not rid then + log(WARN, "failed to get Request ID: ", rid_get_err) + end + + if enabled_headers[headers.REQUEST_ID] and rid then + header[headers.REQUEST_ID] = rid + end end }, log = { diff --git a/kong/templates/kong_defaults.lua b/kong/templates/kong_defaults.lua index 598f4da1992..421da77a5ae 100644 --- a/kong/templates/kong_defaults.lua +++ b/kong/templates/kong_defaults.lua @@ -49,7 +49,8 @@ admin_ssl_cert = NONE admin_ssl_cert_key = NONE status_ssl_cert = NONE status_ssl_cert_key = NONE -headers = server_tokens, latency_tokens +headers = server_tokens, latency_tokens, x-kong-request-id +headers_upstream = x-kong-request-id trusted_ips = NONE error_default_type = text/plain upstream_keepalive = NONE diff --git a/kong/templates/nginx_kong.lua b/kong/templates/nginx_kong.lua index 73e0be2ab07..d2614ac2c56 100644 --- a/kong/templates/nginx_kong.lua +++ b/kong/templates/nginx_kong.lua @@ -55,6 +55,11 @@ init_worker_by_lua_block { } > if (role == "traditional" or role == "data_plane") and #proxy_listeners > 0 then +log_format kong_log_format '$remote_addr - $remote_user [$time_local] ' + '"$request" $status $body_bytes_sent ' + '"$http_referer" "$http_user_agent" ' + 'kong_request_id: "$request_id"'; + # Load variable indexes lua_kong_load_var_index $args; lua_kong_load_var_index $bytes_sent; @@ -121,7 +126,11 @@ server { error_page 400 404 405 408 411 413 414 417 494 /kong_error_handler; error_page 500 502 503 504 /kong_error_handler; - access_log ${{PROXY_ACCESS_LOG}}; + # Append the kong request id to the error log + # https://github.com/Kong/lua-kong-nginx-module#lua_kong_error_log_request_id + lua_kong_error_log_request_id $request_id; + + access_log ${{PROXY_ACCESS_LOG}} kong_log_format; error_log ${{PROXY_ERROR_LOG}} ${{LOG_LEVEL}}; > if proxy_ssl_enabled then diff --git a/kong/tools/utils.lua b/kong/tools/utils.lua index 6c92098cce9..68821a5d05b 100644 --- a/kong/tools/utils.lua +++ b/kong/tools/utils.lua @@ -1289,18 +1289,21 @@ do

Kong Error

%s.

+

request_id: %s

]], [CONTENT_TYPE_JSON] = [[ { - "message":"%s" + "message":"%s", + "request_id":"%s" }]], - [CONTENT_TYPE_PLAIN] = "%s\n", + [CONTENT_TYPE_PLAIN] = "%s\nrequest_id: %s\n", [CONTENT_TYPE_XML] = [[ %s + %s ]], } diff --git a/kong/tracing/request_id.lua b/kong/tracing/request_id.lua new file mode 100644 index 00000000000..c16f7a5d705 --- /dev/null +++ b/kong/tracing/request_id.lua @@ -0,0 +1,44 @@ +local ngx = ngx + +local NGX_VAR_PHASES = { + set = true, + rewrite = true, + access = true, + content = true, + header_filter = true, + body_filter = true, + log = true, + balancer = true, +} + + +local function get_ctx_request_id() + return ngx.ctx.request_id +end + + +local function get() + local rid = get_ctx_request_id() + + if not rid then + local phase = ngx.get_phase() + if not NGX_VAR_PHASES[phase] then + return nil, "cannot access ngx.var in " .. phase .. " phase" + end + + -- first access to the request id for this request: + -- initialize with the value of $request_id + rid = ngx.var.request_id + ngx.ctx.request_id = rid + end + + return rid +end + + +return { + get = get, + + -- for unit testing + _get_ctx_request_id = get_ctx_request_id, +} diff --git a/spec/01-unit/04-prefix_handler_spec.lua b/spec/01-unit/04-prefix_handler_spec.lua index 8b32b232755..75143b3d20a 100644 --- a/spec/01-unit/04-prefix_handler_spec.lua +++ b/spec/01-unit/04-prefix_handler_spec.lua @@ -473,7 +473,7 @@ describe("NGINX conf compiler", function() nginx_stream_tcp_nodelay = "on", })) local nginx_conf = prefix_handler.compile_kong_conf(conf) - assert.matches("access_log%s/dev/stdout;", nginx_conf) + assert.matches("access_log%s/dev/stdout%skong_log_format;", nginx_conf) local nginx_conf = prefix_handler.compile_kong_stream_conf(conf) assert.matches("access_log%slogs/access.log%sbasic;", nginx_conf) @@ -483,7 +483,7 @@ describe("NGINX conf compiler", function() nginx_stream_tcp_nodelay = "on", })) local nginx_conf = prefix_handler.compile_kong_conf(conf) - assert.matches("access_log%slogs/access.log;", nginx_conf) + assert.matches("access_log%slogs/access.log%skong_log_format;", nginx_conf) local nginx_conf = prefix_handler.compile_kong_stream_conf(conf) assert.matches("access_log%s/dev/stdout%scustom;", nginx_conf) end) diff --git a/spec/01-unit/10-log_serializer_spec.lua b/spec/01-unit/10-log_serializer_spec.lua index faf233c3d8e..dfd7ec108d1 100644 --- a/spec/01-unit/10-log_serializer_spec.lua +++ b/spec/01-unit/10-log_serializer_spec.lua @@ -20,6 +20,7 @@ describe("kong.log.serialize", function() }, }, var = { + request_id = "1234", request_uri = "/request_uri", upstream_uri = "/upstream_uri", scheme = "http", @@ -42,8 +43,14 @@ describe("kong.log.serialize", function() resp = { get_headers = function() return {header1 = "respheader1", header2 = "respheader2", ["set-cookie"] = "delicious=delicacy"} end }, + get_phase = function() return "access" end, + WARN = ngx.WARN, } + package.loaded["kong.tracing.request_id"] = nil + package.loaded["kong.pdk.log"] = nil + kong.log = require "kong.pdk.log".new(kong) + package.loaded["kong.pdk.request"] = nil local pdk_request = require "kong.pdk.request" kong.request = pdk_request.new(kong) @@ -74,6 +81,7 @@ describe("kong.log.serialize", function() assert.equal("/upstream_uri", res.upstream_uri) assert.equal(200, res.request.size) assert.equal("/request_uri", res.request.uri) + assert.equal("1234", res.request.id) -- Response assert.is_table(res.response) diff --git a/spec/01-unit/26-tracing/03-request-id_spec.lua b/spec/01-unit/26-tracing/03-request-id_spec.lua new file mode 100644 index 00000000000..7b6bf3537f4 --- /dev/null +++ b/spec/01-unit/26-tracing/03-request-id_spec.lua @@ -0,0 +1,62 @@ +local request_id = require "kong.tracing.request_id" + +local function reset_globals(id) + _G.ngx.ctx = {} + _G.ngx.var = { + request_id = id, + } + _G.ngx.get_phase = function() -- luacheck: ignore + return "access" + end + + _G.kong = { + log = { + notice = function() end, + info = function() end, + }, + } +end + + +describe("Request ID unit tests", function() + local ngx_var_request_id = "1234" + + describe("get()", function() + local old_ngx_ctx + local old_ngx_var + local old_ngx_get_phase + + lazy_setup(function() + old_ngx_ctx = _G.ngx.ctx + old_ngx_var = _G.ngx.var + old_ngx_get_phase = _G.ngx.get_phase + end) + + before_each(function() + reset_globals(ngx_var_request_id) + end) + + lazy_teardown(function() + _G.ngx.ctx = old_ngx_ctx + _G.ngx.var = old_ngx_var + _G.ngx.get_phase = old_ngx_get_phase + end) + + it("returns the expected Request ID and caches it in ctx", function() + local id, err = request_id.get() + assert.is_nil(err) + assert.equal(ngx_var_request_id, id) + + local ctx_request_id = request_id._get_ctx_request_id() + assert.equal(ngx_var_request_id, ctx_request_id) + end) + + it("fails if accessed from phase that cannot read ngx.var", function() + _G.ngx.get_phase = function() return "init" end + + local id, err = request_id.get() + assert.is_nil(id) + assert.equal("cannot access ngx.var in init phase", err) + end) + end) +end) diff --git a/spec/02-integration/05-proxy/06-ssl_spec.lua b/spec/02-integration/05-proxy/06-ssl_spec.lua index 1a6391cceed..c6833d8f3a3 100644 --- a/spec/02-integration/05-proxy/06-ssl_spec.lua +++ b/spec/02-integration/05-proxy/06-ssl_spec.lua @@ -232,7 +232,7 @@ for _, strategy in helpers.each_strategy() do }, }) local body = assert.res_status(502, res) - assert.equal("An invalid response was received from the upstream server", body) + assert.matches("An invalid response was received from the upstream server", body) assert.logfile().has.line("upstream SSL certificate verify error: " .. "(20:unable to get local issuer certificate) " .. "while SSL handshaking to upstream", true, 2) @@ -322,7 +322,8 @@ for _, strategy in helpers.each_strategy() do local body = assert.res_status(426, res) local json = cjson.decode(body) - assert.same({ message = "Please use HTTPS protocol" }, json) + assert.not_nil(json) + assert.matches("Please use HTTPS protocol", json.message) assert.contains("Upgrade", res.headers.connection) assert.equal("TLS/1.2, HTTP/1.1", res.headers.upgrade) @@ -337,7 +338,8 @@ for _, strategy in helpers.each_strategy() do body = assert.res_status(426, res) json = cjson.decode(body) - assert.same({ message = "Please use HTTPS protocol" }, json) + assert.not_nil(json) + assert.matches("Please use HTTPS protocol", json.message) assert.contains("Upgrade", res.headers.connection) assert.equal("TLS/1.2, HTTP/1.1", res.headers.upgrade) end) diff --git a/spec/02-integration/05-proxy/12-error_default_type_spec.lua b/spec/02-integration/05-proxy/12-error_default_type_spec.lua index 894ef706694..8adbfc63e0d 100644 --- a/spec/02-integration/05-proxy/12-error_default_type_spec.lua +++ b/spec/02-integration/05-proxy/12-error_default_type_spec.lua @@ -1,11 +1,13 @@ local helpers = require "spec.helpers" local cjson = require "cjson" +local constants = require "kong.constants" local XML_TEMPLATE = [[ %s + %s ]] @@ -19,10 +21,14 @@ local HTML_TEMPLATE = [[

Kong Error

%s.

+

request_id: %s

]] +local PLAIN_TEMPLATE = "%s\nrequest_id: %s" + + local RESPONSE_CODE = 504 local RESPONSE_MESSAGE = "The upstream server is timing out" @@ -65,6 +71,7 @@ for _, strategy in helpers.each_strategy() do before_each(function() proxy_client = helpers.proxy_client() + helpers.clean_logfile() end) after_each(function() @@ -83,7 +90,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(RESPONSE_CODE, res) - local html_message = string.format(HTML_TEMPLATE, RESPONSE_MESSAGE) + local request_id = res.headers[constants.HEADERS.REQUEST_ID] + local html_message = string.format(HTML_TEMPLATE, RESPONSE_MESSAGE, request_id) assert.equal(html_message, body) end) @@ -131,6 +139,7 @@ for _, strategy in helpers.each_strategy() do before_each(function() proxy_client = helpers.proxy_client() + helpers.clean_logfile() end) after_each(function() @@ -149,10 +158,16 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(RESPONSE_CODE, res) - assert.equal(RESPONSE_MESSAGE, body) + local request_id = res.headers[constants.HEADERS.REQUEST_ID] + local plain_message = string.format(PLAIN_TEMPLATE, RESPONSE_MESSAGE, request_id) + assert.equals(plain_message, body) end) describe("Accept header modified Content-Type", function() + before_each(function() + helpers.clean_logfile() + end) + it("text/html", function() local res = assert(proxy_client:send { method = "GET", @@ -163,7 +178,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(RESPONSE_CODE, res) - local html_message = string.format(HTML_TEMPLATE, RESPONSE_MESSAGE) + local request_id = res.headers[constants.HEADERS.REQUEST_ID] + local html_message = string.format(HTML_TEMPLATE, RESPONSE_MESSAGE, request_id) assert.equal(html_message, body) end) @@ -191,7 +207,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(RESPONSE_CODE, res) - local xml_message = string.format(XML_TEMPLATE, RESPONSE_MESSAGE) + local request_id = res.headers[constants.HEADERS.REQUEST_ID] + local xml_message = string.format(XML_TEMPLATE, RESPONSE_MESSAGE, request_id) assert.equal(xml_message, body) end) end) diff --git a/spec/02-integration/05-proxy/13-error_handlers_spec.lua b/spec/02-integration/05-proxy/13-error_handlers_spec.lua index d63f43daf9d..832aee96dc3 100644 --- a/spec/02-integration/05-proxy/13-error_handlers_spec.lua +++ b/spec/02-integration/05-proxy/13-error_handlers_spec.lua @@ -35,7 +35,7 @@ describe("Proxy error handlers", function() assert.res_status(400, res) local body = res:read_body() assert.matches("kong/", res.headers.server, nil, true) - assert.equal("Bad request\n", body) + assert.matches("Bad request\nrequest_id: %x+\n", body) end) it("does not expose OpenResty version", function() diff --git a/spec/02-integration/05-proxy/18-upstream_tls_spec.lua b/spec/02-integration/05-proxy/18-upstream_tls_spec.lua index c438af0c4ca..ca45816f311 100644 --- a/spec/02-integration/05-proxy/18-upstream_tls_spec.lua +++ b/spec/02-integration/05-proxy/18-upstream_tls_spec.lua @@ -177,7 +177,7 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(200, res) - assert.equals("it works", body) + assert.matches("it works", body) end) it("remove client_certificate removes access", function() @@ -239,7 +239,7 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(200, res) - assert.equals("it works", body) + assert.matches("it works", body) end) it("remove client_certificate removes access", function() @@ -294,7 +294,7 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(200, res) - assert.equals("it works", body) + assert.matches("it works", body) end) end) end) @@ -310,7 +310,7 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(200, res) - assert.equals("it works", body) + assert.matches("it works", body) end) it("#db turn it on, request is blocked", function() @@ -331,7 +331,7 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(502, res) - assert.equals("An invalid response was received from the upstream server", body) + assert.matches("An invalid response was received from the upstream server", body) end) end) @@ -355,7 +355,7 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(200, res) - assert.equals("it works", body) + assert.matches("it works", body) end) end) @@ -390,7 +390,7 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(502, res) - assert.equals("An invalid response was received from the upstream server", body) + assert.matches("An invalid response was received from the upstream server", body) end) it("request is allowed through if depth limit is sufficient", function() @@ -411,7 +411,7 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(200, res) - assert.equals("it works", body) + assert.matches("it works", body) end) end) end) diff --git a/spec/02-integration/05-proxy/33-request-id-header_spec.lua b/spec/02-integration/05-proxy/33-request-id-header_spec.lua new file mode 100644 index 00000000000..f8e0f222425 --- /dev/null +++ b/spec/02-integration/05-proxy/33-request-id-header_spec.lua @@ -0,0 +1,333 @@ +local helpers = require "spec.helpers" +local constants = require "kong.constants" +local cjson = require "cjson" + + +local function setup_db() + local bp = helpers.get_db_utils(nil, { + "routes", + "services", + "plugins", + }) + + local service = bp.services:insert { + host = helpers.mock_upstream_host, + port = helpers.mock_upstream_port, + protocol = helpers.mock_upstream_protocol, + } + + bp.routes:insert { + protocols = { "http" }, + hosts = { "request_id" }, + service = service, + } + + local route_post_func = bp.routes:insert { + protocols = { "http" }, + hosts = { "post-function-access" }, + service = service, + } + + bp.plugins:insert { + name = "post-function", + route = route_post_func, + config = { access = { + "ngx.req.set_header('" .. constants.HEADERS.REQUEST_ID .. "', 'overwritten')" + }} + } + + local route_post_func_2 = bp.routes:insert { + protocols = { "http" }, + hosts = { "post-function-header-filter" }, + service = service, + } + + bp.plugins:insert { + name = "post-function", + route = route_post_func_2, + config = { header_filter = { + "ngx.header['" .. constants.HEADERS.REQUEST_ID .. "'] = 'overwritten'" + }} + } + +end + + +describe(constants.HEADERS.REQUEST_ID .. " header", function() + local client + + describe("(downstream)", function() + describe("with default configuration", function() + lazy_setup(function() + setup_db() + + assert(helpers.start_kong { + nginx_conf = "spec/fixtures/custom_nginx.template", + plugins = "bundled", + }) + + client = helpers.proxy_client() + end) + + lazy_teardown(function() + if client then + client:close() + end + + helpers.stop_kong() + end) + + it("contains the expected value", function() + local res = assert(client:send { + method = "GET", + path = "/", + headers = { + host = "request_id", + } + }) + assert.res_status(200, res) + assert.matches("^[0-9a-f]+$", res.headers[constants.HEADERS.REQUEST_ID]) + end) + + it("should be populated when no API matched", function() + local res = assert(client:send { + method = "GET", + path = "/", + headers = { + host = "404.com", + } + }) + local body = assert.res_status(404, res) + body = cjson.decode(body) + + assert.matches(body.message, "no Route matched with those values") + assert.matches("^[0-9a-f]+$", res.headers[constants.HEADERS.REQUEST_ID]) + end) + + it("overwrites value set by plugin", function() + local res = assert(client:send { + method = "GET", + path = "/", + headers = { + host = "post-function-header-filter", + } + }) + assert.res_status(200, res) + + local downstream_header = res.headers[constants.HEADERS.REQUEST_ID] + assert.not_nil(downstream_header) + assert.matches("^[0-9a-f]+$", downstream_header) + assert.not_equal("overwritten", downstream_header) + end) + end) + + + describe("with configuration [headers=X-Kong-Request-Id]", function() + lazy_setup(function() + setup_db() + + assert(helpers.start_kong { + nginx_conf = "spec/fixtures/custom_nginx.template", + headers = "X-Kong-Request-Id", + }) + + client = helpers.proxy_client() + end) + + lazy_teardown(function() + if client then + client:close() + end + + helpers.stop_kong() + end) + + it("contains the expected value", function() + local res = assert(client:send { + method = "GET", + path = "/", + headers = { + host = "request_id", + } + }) + assert.res_status(200, res) + assert.matches("^[0-9a-f]+$", res.headers[constants.HEADERS.REQUEST_ID]) + end) + end) + + describe("is not injected with configuration [headers=off]", function() + lazy_setup(function() + setup_db() + + assert(helpers.start_kong { + nginx_conf = "spec/fixtures/custom_nginx.template", + headers = "off", + }) + + client = helpers.proxy_client() + end) + + lazy_teardown(function() + if client then + client:close() + end + + helpers.stop_kong() + end) + + it("is nil", function() + local res = assert(client:send { + method = "GET", + path = "/", + headers = { + host = "request_id", + } + }) + assert.res_status(200, res) + assert.is_nil(res.headers[constants.HEADERS.REQUEST_ID]) + end) + end) + end) + + describe("(upstream)", function() + describe("default configuration", function() + lazy_setup(function() + setup_db() + + assert(helpers.start_kong { + nginx_conf = "spec/fixtures/custom_nginx.template", + plugins = "bundled", + }) + + client = helpers.proxy_client() + end) + + lazy_teardown(function() + if client then + client:close() + end + + helpers.stop_kong() + end) + + it("contains the expected value", function() + local res = assert(client:send { + method = "GET", + path = "/anything", + headers = { + host = "request_id", + } + }) + local body = assert.res_status(200, res) + body = cjson.decode(body) + assert.matches("^[0-9a-f]+$", body.headers[string.lower(constants.HEADERS.REQUEST_ID)]) + end) + + it("overwrites client value if any", function() + local client_header_value = "client_value" + local res = assert(client:send { + method = "GET", + path = "/anything", + headers = { + host = "request_id", + ["X-Kong-Request-Id"] = client_header_value + } + }) + + local body = assert.res_status(200, res) + body = cjson.decode(body) + local upstream_received_header = body.headers[string.lower(constants.HEADERS.REQUEST_ID)] + + assert.matches("^[0-9a-f]+$", upstream_received_header) + assert.not_equal(client_header_value, upstream_received_header) + end) + + it("overwrites value set by plugin", function() + local res = assert(client:send { + method = "GET", + path = "/", + headers = { + host = "post-function-access", + } + }) + + local body = assert.res_status(200, res) + body = cjson.decode(body) + local upstream_received_header = body.headers[string.lower(constants.HEADERS.REQUEST_ID)] + + assert.matches("^[0-9a-f]+$", upstream_received_header) + assert.not_equal("overwritten", upstream_received_header) + end) + end) + + + describe("is injected with configuration [headers=X-Kong-Request-Id]", function() + lazy_setup(function() + setup_db() + + assert(helpers.start_kong { + nginx_conf = "spec/fixtures/custom_nginx.template", + headers_upstream = "X-Kong-Request-Id", + }) + + client = helpers.proxy_client() + end) + + lazy_teardown(function() + if client then + client:close() + end + + helpers.stop_kong() + end) + + it("contains the expected value", function() + local res = assert(client:send { + method = "GET", + path = "/", + headers = { + host = "request_id", + } + }) + local body = assert.res_status(200, res) + body = cjson.decode(body) + assert.matches("^[0-9a-f]+$", body.headers[string.lower(constants.HEADERS.REQUEST_ID)]) + end) + end) + + + describe("is not injected with configuration [headers=off]", function() + lazy_setup(function() + setup_db() + + assert(helpers.start_kong { + nginx_conf = "spec/fixtures/custom_nginx.template", + headers_upstream = "off", + }) + + client = helpers.proxy_client() + end) + + lazy_teardown(function() + if client then + client:close() + end + + helpers.stop_kong() + end) + + it("is nil", function() + local res = assert(client:send { + method = "GET", + path = "/", + headers = { + host = "request_id", + } + }) + local body = assert.res_status(200, res) + body = cjson.decode(body) + assert.is_nil(body.headers[string.lower(constants.HEADERS.REQUEST_ID)]) + end) + end) + end) +end) diff --git a/spec/02-integration/10-go_plugins/01-reports_spec.lua b/spec/02-integration/10-go_plugins/01-reports_spec.lua index 719c98eca7d..2cb60ca30a4 100644 --- a/spec/02-integration/10-go_plugins/01-reports_spec.lua +++ b/spec/02-integration/10-go_plugins/01-reports_spec.lua @@ -145,11 +145,11 @@ for _, strategy in helpers.each_strategy() do local logs = pl_file.read(cfg.prefix .. "/" .. cfg.proxy_error_log) for _, logpat in ipairs{ - "access_start: %d%d+\n", - "shared_msg: Kong!\n", - "request_header: this\n", - "response_header: mock_upstream\n", - "serialized:%b{}\n", + "access_start: %d%d+", + "shared_msg: Kong!", + "request_header: this", + "response_header: mock_upstream", + "serialized:%b{}", } do assert.match(logpat, logs) end diff --git a/spec/02-integration/14-tracing/04-trace-ids-log_spec.lua b/spec/02-integration/14-tracing/04-trace-ids-log_spec.lua new file mode 100644 index 00000000000..41783de86fc --- /dev/null +++ b/spec/02-integration/14-tracing/04-trace-ids-log_spec.lua @@ -0,0 +1,200 @@ +local helpers = require "spec.helpers" +local cjson = require "cjson.safe" +local pl_path = require "pl.path" +local pl_file = require "pl.file" +local pl_stringx = require "pl.stringx" + +local FILE_LOG_PATH = os.tmpname() + +local fmt = string.format + +local trace_id_hex_128 = "4bf92000000000000000000000000001" +local span_id = "0000000000000003" +local trace_id_hex_pattern = "^%x+$" + + +local tracing_headers = { + { + type = "b3", + serializer_key = "b3", + name = "X-B3-TraceId", + value = trace_id_hex_128, + trace_id = trace_id_hex_128, + trace_id_pattern = trace_id_hex_pattern, + }, + { + type = "b3-single", + serializer_key = "b3", + name = "b3", + value = fmt("%s-%s-1-%s", trace_id_hex_128, span_id, span_id), + trace_id = trace_id_hex_128, + trace_id_pattern = trace_id_hex_pattern, + }, + { + type = "jaeger", + serializer_key = "jaeger", + name = "uber-trace-id", + value = fmt("%s:%s:%s:%s", trace_id_hex_128, span_id, span_id, "01"), + trace_id = trace_id_hex_128, + trace_id_pattern = trace_id_hex_pattern, + }, + { + type = "w3c", + serializer_key = "w3c", + name = "traceparent", + value = fmt("00-%s-%s-01", trace_id_hex_128, span_id), + trace_id = trace_id_hex_128, + trace_id_pattern = trace_id_hex_pattern, + }, + { + type = "ot", + serializer_key = "ot", + name = "ot-tracer-traceid", + value = trace_id_hex_128, + trace_id = trace_id_hex_128, + trace_id_pattern = trace_id_hex_pattern, + }, +} + +local function wait_json_log() + helpers.wait_until(function() + return pl_path.exists(FILE_LOG_PATH) and pl_path.getsize(FILE_LOG_PATH) > 0 + end, 10) + + local log = pl_file.read(FILE_LOG_PATH) + return cjson.decode(pl_stringx.strip(log):match("%b{}")) +end + +for _, strategy in helpers.each_strategy() do + local proxy_client + + for _, config_header in ipairs(tracing_headers) do + describe("Trace IDs log serializer spec #" .. strategy, function() + lazy_setup(function() + local bp, _ = assert(helpers.get_db_utils(strategy, { + "services", + "routes", + "plugins", + })) + + local service = bp.services:insert() + + local zipkin_route = bp.routes:insert({ + service = service, + hosts = { "zipkin" }, + }) + + bp.plugins:insert { + name = "file-log", + config = { + path = FILE_LOG_PATH, + reopen = true, + }, + } + + bp.plugins:insert({ + name = "zipkin", + route = { id = zipkin_route.id }, + config = { + sample_ratio = 1, + http_endpoint = "http://localhost:8080/v1/traces", + header_type = config_header.type, + } + }) + + assert(helpers.start_kong { + database = strategy, + nginx_conf = "spec/fixtures/custom_nginx.template", + plugins = "bundled", + tracing_instrumentations = "all", + tracing_sampling_rate = 1, + }) + end) + + lazy_teardown(function() + helpers.stop_kong() + if proxy_client then + proxy_client:close() + end + end) + + before_each(function() + proxy_client = helpers.proxy_client() + os.remove(FILE_LOG_PATH) + end) + + after_each(function() + if proxy_client then + proxy_client:close() + end + + os.remove(FILE_LOG_PATH) + end) + + describe("with Zipkin", function() + local default_type_zipkin = "b3" + + it("contains only the configured trace ID type: " .. config_header.type .. + " + the default (b3) with no tracing headers in the request", function() + local r = proxy_client:get("/", { + headers = { + host = "zipkin", + }, + }) + assert.response(r).has.status(200) + local json_log = wait_json_log() + assert.not_nil(json_log) + + -- contains the configured trace id type + assert.matches(config_header.trace_id_pattern, + json_log.trace_id[config_header.serializer_key]) + -- contains the default trace id type (generated trace id) + assert.matches(trace_id_hex_pattern, + json_log.trace_id[default_type_zipkin]) + + -- does not contain other types + for _, header in ipairs(tracing_headers) do + local k = header.serializer_key + if k ~= config_header.serializer_key and k ~= default_type_zipkin then + assert.is_nil(json_log.trace_id[k]) + end + end + end) + + for _, req_header in ipairs(tracing_headers) do + it("contains only the configured trace ID type (" .. config_header.type .. + ") + the incoming (" .. req_header.type .. ")", function() + if req_header.type == config_header.type then + return + end + + local r = proxy_client:get("/", { + headers = { + host = "zipkin", + [req_header.name] = req_header.value, + }, + }) + assert.response(r).has.status(200) + local json_log = wait_json_log() + assert.not_nil(json_log) + + -- contains the configured trace id type of the incoming trace id + assert.matches(config_header.trace_id_pattern, + json_log.trace_id[config_header.serializer_key]) + -- contains the incoming trace id + assert.equals(req_header.trace_id, + json_log.trace_id[req_header.serializer_key]) + + -- does not contain other types + for _, header in ipairs(tracing_headers) do + local k = header.serializer_key + if k ~= config_header.serializer_key and k ~= req_header.serializer_key then + assert.is_nil(json_log.trace_id[k]) + end + end + end) + end + end) + end) + end +end diff --git a/spec/03-plugins/09-key-auth/02-access_spec.lua b/spec/03-plugins/09-key-auth/02-access_spec.lua index 57e277de487..0e0d1763a4f 100644 --- a/spec/03-plugins/09-key-auth/02-access_spec.lua +++ b/spec/03-plugins/09-key-auth/02-access_spec.lua @@ -206,7 +206,9 @@ for _, strategy in helpers.each_strategy() do }) assert.res_status(401, res) local body = assert.res_status(401, res) - assert.same({message = "No API key found in request"}, cjson.decode(body)) + local json = cjson.decode(body) + assert.not_nil(json) + assert.matches("No API key found in request", json.message) end) it("returns Unauthorized on missing credentials", function() local res = assert(proxy_client:send { @@ -218,7 +220,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "No API key found in request" }, json) + assert.not_nil(json) + assert.matches("No API key found in request", json.message) end) it("returns Unauthorized on empty key header", function() local res = assert(proxy_client:send { @@ -231,7 +234,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "No API key found in request" }, json) + assert.not_nil(json) + assert.matches("No API key found in request", json.message) end) it("returns Unauthorized on empty key querystring", function() local res = assert(proxy_client:send { @@ -243,7 +247,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "No API key found in request" }, json) + assert.not_nil(json) + assert.matches("No API key found in request", json.message) end) it("returns WWW-Authenticate header on missing credentials", function() local res = assert(proxy_client:send { @@ -279,7 +284,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) it("handles duplicated key in querystring", function() local res = assert(proxy_client:send { @@ -291,7 +297,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Duplicate API key found" }, json) + assert.not_nil(json) + assert.matches("Duplicate API key found", json.message) end) end) @@ -351,7 +358,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) -- lua-multipart doesn't currently handle duplicates at all. @@ -371,7 +379,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Duplicate API key found" }, json) + assert.not_nil(json) + assert.matches("Duplicate API key found", json.message) end) end @@ -386,7 +395,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Duplicate API key found" }, json) + assert.not_nil(json) + assert.matches("Duplicate API key found", json.message) end) it("does not identify apikey[] as api keys", function() @@ -399,7 +409,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "No API key found in request" }, json) + assert.not_nil(json) + assert.matches("No API key found in request", json.message) end) it("does not identify apikey[1] as api keys", function() @@ -412,7 +423,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "No API key found in request" }, json) + assert.not_nil(json) + assert.matches("No API key found in request", json.message) end) end end) @@ -442,7 +454,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) end) @@ -501,7 +514,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) res = assert(proxy_client:send { method = "GET", @@ -513,7 +527,8 @@ for _, strategy in helpers.each_strategy() do }) body = assert.res_status(401, res) json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) end) @@ -643,7 +658,8 @@ for _, strategy in helpers.each_strategy() do local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "No API key found in request" }, json) + assert.not_nil(json) + assert.matches("No API key found in request", json.message) end) end) diff --git a/spec/03-plugins/10-basic-auth/03-access_spec.lua b/spec/03-plugins/10-basic-auth/03-access_spec.lua index c7d7cee5fe9..bbb13640c42 100644 --- a/spec/03-plugins/10-basic-auth/03-access_spec.lua +++ b/spec/03-plugins/10-basic-auth/03-access_spec.lua @@ -143,7 +143,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Unauthorized" }, json) + assert.not_nil(json) + assert.matches("Unauthorized", json.message) end) it("returns WWW-Authenticate header on missing credentials", function() @@ -173,7 +174,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) it("returns 401 Unauthorized on invalid credentials in Proxy-Authorization", function() @@ -187,7 +189,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) it("returns 401 Unauthorized on password only", function() @@ -201,7 +204,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) it("returns 401 Unauthorized on username only", function() @@ -215,7 +219,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) it("rejects gRPC call without credentials", function() @@ -291,7 +296,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) it("authenticates valid credentials in Proxy-Authorization", function() diff --git a/spec/03-plugins/10-basic-auth/05-declarative_spec.lua b/spec/03-plugins/10-basic-auth/05-declarative_spec.lua index 747b68ccc94..29a2dc8c7e0 100644 --- a/spec/03-plugins/10-basic-auth/05-declarative_spec.lua +++ b/spec/03-plugins/10-basic-auth/05-declarative_spec.lua @@ -177,7 +177,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Invalid authentication credentials" }, json) + assert.not_nil(json) + assert.matches("Invalid authentication credentials", json.message) end) end) diff --git a/spec/03-plugins/11-correlation-id/01-access_spec.lua b/spec/03-plugins/11-correlation-id/01-access_spec.lua index 1a9242f4c6b..007f7f734a1 100644 --- a/spec/03-plugins/11-correlation-id/01-access_spec.lua +++ b/spec/03-plugins/11-correlation-id/01-access_spec.lua @@ -1,10 +1,23 @@ -local helpers = require "spec.helpers" -local cjson = require "cjson" - +local helpers = require "spec.helpers" +local cjson = require "cjson" +local pl_path = require "pl.path" +local pl_file = require "pl.file" +local pl_stringx = require "pl.stringx" local UUID_PATTERN = "%x%x%x%x%x%x%x%x%-%x%x%x%x%-%x%x%x%x%-%x%x%x%x%-%x%x%x%x%x%x%x%x%x%x%x%x" local UUID_COUNTER_PATTERN = UUID_PATTERN .. "#%d" local TRACKER_PATTERN = "%d+%.%d+%.%d+%.%d+%-%d+%-%d+%-%d+%-%d+%-%d%d%d%d%d%d%d%d%d%d%.%d%d%d" +local FILE_LOG_PATH = os.tmpname() + + +local function wait_json_log() + helpers.wait_until(function() + return pl_path.exists(FILE_LOG_PATH) and pl_path.getsize(FILE_LOG_PATH) > 0 + end, 10) + + local log = pl_file.read(FILE_LOG_PATH) + return cjson.decode(pl_stringx.strip(log):match("%b{}")) +end for _, strategy in helpers.each_strategy() do @@ -57,6 +70,10 @@ for _, strategy in helpers.each_strategy() do }), }) + local route_serializer = bp.routes:insert { + hosts = { "correlation-serializer.com" }, + } + bp.plugins:insert { name = "correlation-id", route = { id = route1.id }, @@ -138,6 +155,20 @@ for _, strategy in helpers.each_strategy() do }, } + bp.plugins:insert { + name = "file-log", + route = { id = route_serializer.id }, + config = { + path = FILE_LOG_PATH, + reopen = true, + }, + } + + bp.plugins:insert { + name = "correlation-id", + route = { id = route_serializer.id }, + } + assert(helpers.start_kong({ database = strategy, nginx_conf = "spec/fixtures/custom_nginx.template", @@ -415,5 +446,34 @@ for _, strategy in helpers.each_strategy() do local downstream_id = assert.response(res).has.header("kong-request-id") assert.equals("my very personal id", downstream_id) end) + + describe("log serializer", function() + before_each(function() + os.remove(FILE_LOG_PATH) + end) + + after_each(function() + os.remove(FILE_LOG_PATH) + end) + + it("contains the Correlation ID", function() + local correlation_id = "1234" + local r = proxy_client:get("/", { + headers = { + host = "correlation-serializer.com", + ["Kong-Request-ID"] = correlation_id, + }, + }) + assert.response(r).has.status(200) + + local json_log = wait_json_log() + local request_id = json_log and json_log.request and json_log.request.id + assert.matches("^[a-f0-9]+$", request_id) + assert.True(request_id:len() == 32) + + local logged_id = json_log and json_log.correlation_id + assert.equals(correlation_id, logged_id) + end) + end) end) end diff --git a/spec/03-plugins/12-request-size-limiting/01-access_spec.lua b/spec/03-plugins/12-request-size-limiting/01-access_spec.lua index e3302415119..eeef6f0a233 100644 --- a/spec/03-plugins/12-request-size-limiting/01-access_spec.lua +++ b/spec/03-plugins/12-request-size-limiting/01-access_spec.lua @@ -121,7 +121,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(413, res) local json = cjson.decode(body) - assert.same({ message = "Request size limit exceeded" }, json) + assert.not_nil(json) + assert.matches("Request size limit exceeded", json.message) end) it("blocks if size is greater than limit and Expect header", function() @@ -138,7 +139,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(417, res) local json = cjson.decode(body) - assert.same({ message = "Request size limit exceeded" }, json) + assert.not_nil(json) + assert.matches("Request size limit exceeded", json.message) end) for _, unit in ipairs(size_units) do @@ -155,7 +157,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(413, res) local json = cjson.decode(body) - assert.same({ message = "Request size limit exceeded" }, json) + assert.not_nil(json) + assert.matches("Request size limit exceeded", json.message) end) end @@ -219,7 +222,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(413, res) local json = cjson.decode(body) - assert.same({ message = "Request size limit exceeded" }, json) + assert.not_nil(json) + assert.matches("Request size limit exceeded", json.message) end) it("blocks if size is greater than limit and Expect header", function() @@ -236,7 +240,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(417, res) local json = cjson.decode(body) - assert.same({ message = "Request size limit exceeded" }, json) + assert.not_nil(json) + assert.matches("Request size limit exceeded", json.message) end) for _, unit in ipairs(size_units) do @@ -253,7 +258,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(413, res) local json = cjson.decode(body) - assert.same({ message = "Request size limit exceeded" }, json) + assert.not_nil(json) + assert.matches("Request size limit exceeded", json.message) end) end diff --git a/spec/03-plugins/14-request-termination/02-access_spec.lua b/spec/03-plugins/14-request-termination/02-access_spec.lua index e8b3664c1fd..0745b884de9 100644 --- a/spec/03-plugins/14-request-termination/02-access_spec.lua +++ b/spec/03-plugins/14-request-termination/02-access_spec.lua @@ -161,6 +161,7 @@ for _, strategy in helpers.each_strategy() do assert(helpers.start_kong({ database = strategy, nginx_conf = "spec/fixtures/custom_nginx.template", + headers_upstream = "off", })) end) diff --git a/spec/03-plugins/17-ip-restriction/02-access_spec.lua b/spec/03-plugins/17-ip-restriction/02-access_spec.lua index fba888543fc..789c9e0ab41 100644 --- a/spec/03-plugins/17-ip-restriction/02-access_spec.lua +++ b/spec/03-plugins/17-ip-restriction/02-access_spec.lua @@ -248,7 +248,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("blocks a request when the IP is denied with status/message", function() @@ -261,7 +262,9 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Forbidden" }, json) + + assert.not_nil(json) + assert.matches("Forbidden", json.message) end) it("blocks a request when the IP is denied #grpc", function() @@ -310,7 +313,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("blocks an IP on a allowed CIDR range", function() local res = assert(proxy_client:send { @@ -322,7 +326,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("takes precedence over an allowed IP", function() local res = assert(proxy_client:send { @@ -334,7 +339,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("takes precedence over an allowed CIDR range", function() local res = assert(proxy_client:send { @@ -346,7 +352,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) describe("X-Forwarded-For", function() @@ -386,7 +393,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) end) end) @@ -402,7 +410,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("allows a allowed IP", function() local res = assert(proxy_client:send { @@ -426,7 +435,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("block with not allowed X-Forwarded-For header", function() local res = assert(proxy_client:send { @@ -439,7 +449,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("block with not allowed X-Forwarded-For header #grpc", function() local ok, err = helpers.proxy_client_grpc(){ @@ -522,7 +533,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) describe("#regression", function() @@ -697,7 +709,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("allows a request when the IPv6 is not denied", function() local res = assert(proxy_client:send { @@ -723,7 +736,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("blocks an IPv6 on a allowed IPv6 CIDR range", function() local res = assert(proxy_client:send { @@ -736,7 +750,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("takes precedence over an allowed IPv6", function() local res = assert(proxy_client:send { @@ -749,7 +764,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("takes precedence over an allowed IPv6 CIDR range", function() local res = assert(proxy_client:send { @@ -761,7 +777,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) end) @@ -777,7 +794,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("allows a allowed IPv6", function() local res = assert(proxy_client:send { @@ -840,7 +858,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) describe("#regression", function() @@ -942,7 +961,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("blocks with blocked complex X-Forwarded-For header", function() local res = assert(proxy_client:send { @@ -955,7 +975,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("allows with allowed complex X-Forwarded-For header", function() local res = assert(proxy_client:send { @@ -984,7 +1005,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) it("allows with allowed X-Forwarded-For header", function() local res = assert(proxy_client:send { @@ -1023,7 +1045,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "Your IP address is not allowed" }, json) + assert.not_nil(json) + assert.matches("Your IP address is not allowed", json.message) end) end) end) diff --git a/spec/03-plugins/18-acl/02-access_spec.lua b/spec/03-plugins/18-acl/02-access_spec.lua index 12b60aff0e8..3b5c37cc4e7 100644 --- a/spec/03-plugins/18-acl/02-access_spec.lua +++ b/spec/03-plugins/18-acl/02-access_spec.lua @@ -793,7 +793,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Unauthorized" }, json) + assert.not_nil(json) + assert.matches("Unauthorized", json.message) end) it("should fail when an authentication plugin is missing (with credential)", function() @@ -804,7 +805,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should fail when not allowed", function() @@ -815,7 +817,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should fail when not allowed with authenticated groups", function() @@ -826,7 +829,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should work when allowed", function() @@ -921,7 +925,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should fail when denied with authenticated groups", function() @@ -932,7 +937,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should fail denied and with no authenticated groups", function() @@ -943,7 +949,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(401, res) local json = cjson.decode(body) - assert.same({ message = "Unauthorized" }, json) + assert.not_nil(json) + assert.matches("Unauthorized", json.message) end) end) @@ -978,7 +985,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should fail when not allowed with authenticated groups", function() @@ -989,7 +997,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should fail when denied", function() @@ -1000,7 +1009,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should fail when denied with authenticated groups", function() @@ -1011,7 +1021,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) @@ -1041,7 +1052,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should not work when one of the ACLs denied with authenticated groups", function() @@ -1052,7 +1064,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should work when one of the ACLs is allowed", function() @@ -1081,7 +1094,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("should not work when at least one of the ACLs denied with authenticated groups", function() @@ -1092,7 +1106,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) end) @@ -1301,7 +1316,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) it("authorized groups even when anonymous consumer is present", function() @@ -1312,7 +1328,8 @@ for _, strategy in helpers.each_strategy() do })) local body = assert.res_status(403, res) local json = cjson.decode(body) - assert.same({ message = "You cannot consume this service" }, json) + assert.not_nil(json) + assert.matches("You cannot consume this service", json.message) end) end) end) diff --git a/spec/03-plugins/19-hmac-auth/03-access_spec.lua b/spec/03-plugins/19-hmac-auth/03-access_spec.lua index 04d14efea3c..1f79d3aa8fa 100644 --- a/spec/03-plugins/19-hmac-auth/03-access_spec.lua +++ b/spec/03-plugins/19-hmac-auth/03-access_spec.lua @@ -362,7 +362,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) body = cjson.decode(body) - assert.same({ message = "HMAC signature cannot be verified" }, body) + assert.not_nil(body.message) + assert.matches("HMAC signature cannot be verified", body.message) end) it("should not pass with signature missing", function() @@ -381,7 +382,8 @@ for _, strategy in helpers.each_strategy() do }) local body = assert.res_status(401, res) body = cjson.decode(body) - assert.same({ message = "HMAC signature cannot be verified" }, body) + assert.not_nil(body.message) + assert.matches("HMAC signature cannot be verified", body.message) end) it("should pass with GET", function() diff --git a/spec/03-plugins/23-rate-limiting/04-access_spec.lua b/spec/03-plugins/23-rate-limiting/04-access_spec.lua index 6b48a1a1b10..9630f1b72c9 100644 --- a/spec/03-plugins/23-rate-limiting/04-access_spec.lua +++ b/spec/03-plugins/23-rate-limiting/04-access_spec.lua @@ -333,7 +333,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) it_with_retry("blocks if exceeding limit, only if done via same path", function() @@ -393,7 +394,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) it_with_retry("counts against the same service register from different routes", function() @@ -438,7 +440,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) it_with_retry("handles multiple limits #flaky", function() @@ -479,7 +482,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) end) describe("Without authentication (IP address)", function() @@ -516,8 +520,8 @@ for _, strategy in helpers.each_strategy() do assert.matches("ratelimit%-limit: 6", res) assert.matches("ratelimit%-remaining: 0", res) - local retry = tonumber(string.match(res, "retry%-after: (%d+)")) - assert.equal(true, retry <= 60 and retry > 0) + local retry = tonumber(string.match(res, "retry%-after: (%d+)")) + assert.equal(true, retry <= 60 and retry > 0) local reset = tonumber(string.match(res, "ratelimit%-reset: (%d+)")) @@ -555,7 +559,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) -- Using a different key of the same consumer works GET("/status/200?apikey=apikey333", { @@ -592,7 +597,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) it_with_retry("blocks if the only rate-limiting plugin existing is per consumer and not per API", function() @@ -623,7 +629,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) end) end) @@ -702,7 +709,8 @@ for _, strategy in helpers.each_strategy() do }, 500) local json = cjson.decode(body) - assert.same({ message = "An unexpected error occurred" }, json) + assert.not_nil(json.message) + assert.matches("An unexpected error occurred", json.message) db:reset() bp, db = helpers.get_db_utils(strategy) @@ -792,7 +800,8 @@ for _, strategy in helpers.each_strategy() do }, 500) local json = cjson.decode(body) - assert.same({ message = "An unexpected error occurred" }, json) + assert.not_nil(json.message) + assert.matches("An unexpected error occurred", json.message) end) it_with_retry("keeps working if an error occurs", function() @@ -950,7 +959,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) end) @@ -1026,7 +1036,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) end) @@ -1113,7 +1124,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end end) end) @@ -1184,7 +1196,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) end) @@ -1260,7 +1273,8 @@ for _, strategy in helpers.each_strategy() do assert.equal(true, reset <= 60 and reset > 0) local json = cjson.decode(body) - assert.same({ message = "API rate limit exceeded" }, json) + assert.not_nil(json.message) + assert.matches("API rate limit exceeded", json.message) end) end) end diff --git a/spec/03-plugins/33-serverless-functions/02-access_spec.lua b/spec/03-plugins/33-serverless-functions/02-access_spec.lua index 191ceac4fd5..5d5393a8cd3 100644 --- a/spec/03-plugins/33-serverless-functions/02-access_spec.lua +++ b/spec/03-plugins/33-serverless-functions/02-access_spec.lua @@ -256,7 +256,8 @@ for _, plugin_name in ipairs({ "pre-function", "post-function" }) do }) local body = assert.res_status(406, res) local json = cjson.decode(body) - assert.same({ message = "Invalid" }, json) + assert.not_nil(json) + assert.matches("Invalid", json.message) end) it("cascading functions for a 400 and exit", function() @@ -268,7 +269,7 @@ for _, plugin_name in ipairs({ "pre-function", "post-function" }) do } }) local body = assert.res_status(400, res) - assert.same("Bad request", body) + assert.matches("Bad request", body) end) it("runtime error aborts with a 500", function() @@ -280,7 +281,9 @@ for _, plugin_name in ipairs({ "pre-function", "post-function" }) do } }) local body = assert.res_status(500, res) - assert.same('{"message":"An unexpected error occurred"}', body) + local json = cjson.decode(body) + assert.not_nil(json) + assert.matches("An unexpected error occurred", json.message) end) end) diff --git a/spec/03-plugins/34-zipkin/tracing_headers_spec.lua b/spec/03-plugins/34-zipkin/tracing_headers_spec.lua index a96d0e50409..7f0b83599f8 100644 --- a/spec/03-plugins/34-zipkin/tracing_headers_spec.lua +++ b/spec/03-plugins/34-zipkin/tracing_headers_spec.lua @@ -557,7 +557,8 @@ describe("tracing_headers.set", function() log = { warn = function(msg) warnings[#warnings + 1] = msg - end + end, + set_serialize_value = function() end, } } diff --git a/t/01-pdk/08-response/13-error.t b/t/01-pdk/08-response/13-error.t index 8ee4d0e2b58..ae75b8486a9 100644 --- a/t/01-pdk/08-response/13-error.t +++ b/t/01-pdk/08-response/13-error.t @@ -29,10 +29,11 @@ Accept: application/json --- error_code: 502 --- response_headers_like Content-Type: application/json; charset=utf-8 ---- response_body chop -{ - "message":"An invalid response was received from the upstream server" -} +--- response_body eval +qr/{ +\s*"message":"An invalid response was received from the upstream server", +\s*"request_id":".*" +}/ --- no_error_log [error] @@ -54,10 +55,11 @@ GET /t --- error_code: 400 --- response_headers_like Content-Type: application/json; charset=utf-8 ---- response_body chop -{ - "message":"Bad request" -} +--- response_body eval +qr/{ +\s*"message":"Bad request", +\s*"request_id":".*" +}/ --- no_error_log [error] @@ -81,10 +83,11 @@ Accept: json --- error_code: 400 --- response_headers_like Content-Type: application/json; charset=utf-8 ---- response_body chop -{ - "message":"Bad request" -} +--- response_body eval +qr/{ +\s*"message":"Bad request", +\s*"request_id":".*" +}/ --- no_error_log [error] @@ -112,11 +115,11 @@ Accept: application/json --- error_code: 503 --- response_headers_like Content-Type: application/xml ---- response_body - - - this is fine - +--- response_body eval +qr/<\?xml version="1\.0" encoding="UTF\-8"\?>\n +\s*this is fine<\/message> +\s*.*<\/requestid> +<\/error>/ --- no_error_log [error] @@ -140,18 +143,19 @@ Accept: text/plain;q=0.3, text/html;q=0.7, text/html;level=1, text/html;level=2; --- error_code: 502 --- response_headers_like Content-Type: text/html; charset=utf-8 ---- response_body - - - - - Kong Error - - -

Kong Error

-

An invalid response was received from the upstream server.

- - +--- response_body eval +qr/ +\s* +\s* +\s* +\s*Kong Error<\/title> +\s*<\/head> +\s*<body> +\s*<h1>Kong Error<\/h1> +\s*<p>An invalid response was received from the upstream server.<\/p> +\s*<p>request_id: .*<\/p> +\s*<\/body> +\s*<\/html>/ --- no_error_log [error] @@ -183,10 +187,11 @@ GET /t --- error_code: 500 --- response_headers_like Content-Type: application/json; charset=utf-8 ---- response_body chop -{ - "message":"An unexpected error occurred" -} +--- response_body eval +qr/{ +\s*"message":"An unexpected error occurred", +\s*"request_id":".*" +}/ --- no_error_log [error] @@ -210,10 +215,11 @@ Accept: application/json --- error_code: 419 --- response_headers_like Content-Type: application/json; charset=utf-8 ---- response_body chop -{ - "message":"I'm not a teapot" -} +--- response_body eval +qr/{ +\s*"message":"I'm not a teapot", +\s*"request_id":".*" +}/ --- no_error_log [error] @@ -237,10 +243,11 @@ Accept: application/json --- error_code: 500 --- response_headers_like Content-Type: application/json; charset=utf-8 ---- response_body chop -{ - "message":"oh no" -} +--- response_body eval +qr/{ +\s*"message":"oh no", +\s*"request_id":".*" +}/ --- no_error_log [error] @@ -264,11 +271,11 @@ Accept: application/xml --- error_code: 502 --- response_headers_like Content-Type: application/xml; charset=utf-8 ---- response_body -<?xml version="1.0" encoding="UTF-8"?> -<error> - <message>{"a field":"not a default message"}</message> -</error> +--- response_body eval +qr/<\?xml version="1\.0" encoding="UTF\-8"\?>\n<error> +\s*<message>\{"a field":"not a default message"\}<\/message> +\s*<requestid>.*<\/requestid> +<\/error>/ --- no_error_log [error] @@ -292,8 +299,9 @@ Accept: text/* --- error_code: 410 --- response_headers_like Content-Type: text/plain; charset=utf-8 ---- response_body -Gone +--- response_body eval +qr/Gone +request_id:.*/ --- no_error_log [error]