From b945f17049a0651f8751f9d87f800db6ca8bdaf8 Mon Sep 17 00:00:00 2001 From: Samuele Date: Tue, 5 Sep 2023 09:28:13 +0200 Subject: [PATCH] fix(tracing/propagation): set parent span correctly (#11468) * fix an issue where the parent span was set incorrectly when the balancer instrumentation was disabled (the parent span was set to a temporary balancer span that was never reported) --- CHANGELOG/unreleased/kong/11468.yaml | 7 ++ kong/plugins/opentelemetry/handler.lua | 21 ++-- kong/runloop/handler.lua | 3 + kong/tracing/instrumentation.lua | 27 +++++- kong/tracing/propagation.lua | 18 +--- .../37-opentelemetry/03-propagation_spec.lua | 97 +++++++++++++++++++ .../kong/plugins/trace-propagator/handler.lua | 20 ++-- 7 files changed, 151 insertions(+), 42 deletions(-) create mode 100644 CHANGELOG/unreleased/kong/11468.yaml diff --git a/CHANGELOG/unreleased/kong/11468.yaml b/CHANGELOG/unreleased/kong/11468.yaml new file mode 100644 index 000000000000..af91c7347e7c --- /dev/null +++ b/CHANGELOG/unreleased/kong/11468.yaml @@ -0,0 +1,7 @@ +message: "**Opentelemetry**: fix an issue that resulted in invalid parent IDs in the propagated tracing headers" +type: bugfix +scope: Plugin +prs: + - 11468 +jiras: + - "KAG-2281" diff --git a/kong/plugins/opentelemetry/handler.lua b/kong/plugins/opentelemetry/handler.lua index 7cfd6703cf26..96f186cdf29a 100644 --- a/kong/plugins/opentelemetry/handler.lua +++ b/kong/plugins/opentelemetry/handler.lua @@ -103,34 +103,31 @@ function OpenTelemetryHandler:access(conf) kong.ctx.plugin.should_sample = false end + local injected_parent_span = ngx.ctx.tracing and + ngx.ctx.tracing.injected.balancer_span or root_span + local header_type, trace_id, span_id, parent_id, should_sample, _ = propagation_parse(headers, conf.header_type) if should_sample == false then tracer:set_should_sample(should_sample) + injected_parent_span.should_sample = should_sample end -- overwrite trace id -- as we are in a chain of existing trace if trace_id then - root_span.trace_id = trace_id + injected_parent_span.trace_id = trace_id kong.ctx.plugin.trace_id = trace_id end - -- overwrite root span's parent_id + -- overwrite parent span's parent_id if span_id then - root_span.parent_id = span_id + injected_parent_span.parent_id = span_id elseif parent_id then - root_span.parent_id = parent_id + injected_parent_span.parent_id = parent_id end - -- propagate the span that identifies the "last" balancer try - -- This has to happen "in advance". The span will be activated (linked) - -- after the OpenResty balancer results are available - local balancer_span = tracer.create_span(nil, { - span_kind = 3, - parent = root_span, - }) - propagation_set(conf.header_type, header_type, balancer_span, "w3c", true) + propagation_set(conf.header_type, header_type, injected_parent_span, "w3c") end diff --git a/kong/runloop/handler.lua b/kong/runloop/handler.lua index df80fe68ffbe..eaacbb712e9f 100644 --- a/kong/runloop/handler.lua +++ b/kong/runloop/handler.lua @@ -1137,6 +1137,9 @@ return { -- trace router local span = instrumentation.router() + -- create the balancer span "in advance" so its ID is available + -- to plugins in the access phase for doing headers propagation + instrumentation.precreate_balancer_span(ctx) -- routing request local router = get_updated_router() diff --git a/kong/tracing/instrumentation.lua b/kong/tracing/instrumentation.lua index e5f68ca0aab4..b227dc507dbd 100644 --- a/kong/tracing/instrumentation.lua +++ b/kong/tracing/instrumentation.lua @@ -1,5 +1,4 @@ local pdk_tracer = require "kong.pdk.tracing".new() -local propagation = require "kong.tracing.propagation" local utils = require "kong.tools.utils" local tablepool = require "tablepool" local tablex = require "pl.tablex" @@ -85,10 +84,10 @@ function _M.balancer(ctx) local last_try_balancer_span do - local propagated = propagation.get_propagated() + local balancer_span = ctx.tracing and ctx.tracing.injected.balancer_span -- pre-created balancer span was not linked yet - if propagated and not propagated.linked then - last_try_balancer_span = propagated + if balancer_span and not balancer_span.linked then + last_try_balancer_span = balancer_span end end @@ -210,6 +209,10 @@ _M.available_types = available_types -- Record inbound request function _M.request(ctx) + ctx.tracing = { + injected = {}, + } + local client = kong.client local method = get_method() @@ -245,6 +248,22 @@ function _M.request(ctx) end +function _M.precreate_balancer_span(ctx) + if _M.balancer == NOOP then + -- balancer instrumentation not enabled + return + end + + local root_span = ctx.KONG_SPANS and ctx.KONG_SPANS[1] + if ctx.tracing then + ctx.tracing.injected.balancer_span = tracer.create_span(nil, { + span_kind = 3, + parent = root_span, + }) + end +end + + local patch_dns_query do local raw_func diff --git a/kong/tracing/propagation.lua b/kong/tracing/propagation.lua index 29852ba0e906..566b5bd27cfa 100644 --- a/kong/tracing/propagation.lua +++ b/kong/tracing/propagation.lua @@ -440,33 +440,18 @@ local function parse(headers, conf_header_type) end -local function get_propagated() - return ngx.ctx.propagated_span -end - - -local function set_propagated(span) - ngx.ctx.propagated_span = span -end - - -- set outgoing propagation headers -- -- @tparam string conf_header_type type of tracing header to use -- @tparam string found_header_type type of tracing header found in request -- @tparam table proxy_span span to be propagated -- @tparam string conf_default_header_type used when conf_header_type=ignore --- @tparam bool reuse if true any existing propagated_span is reused instead of proxy_span -local function set(conf_header_type, found_header_type, proxy_span, conf_default_header_type, reuse) - if reuse then - proxy_span = get_propagated() or proxy_span - end +local function set(conf_header_type, found_header_type, proxy_span, conf_default_header_type) -- proxy_span can be noop, in which case it should not be propagated. if proxy_span.is_recording == false then kong.log.debug("skipping propagation of noop span") return end - set_propagated(proxy_span) local set_header = kong.service.request.set_header @@ -542,5 +527,4 @@ return { parse = parse, set = set, from_hex = from_hex, - get_propagated = get_propagated, } diff --git a/spec/03-plugins/37-opentelemetry/03-propagation_spec.lua b/spec/03-plugins/37-opentelemetry/03-propagation_spec.lua index b1d01f9c631c..35c32a8488bf 100644 --- a/spec/03-plugins/37-opentelemetry/03-propagation_spec.lua +++ b/spec/03-plugins/37-opentelemetry/03-propagation_spec.lua @@ -1,10 +1,12 @@ local helpers = require "spec.helpers" local cjson = require "cjson" local utils = require "kong.tools.utils" +local pretty = require "pl.pretty" local to_hex = require "resty.string".to_hex local fmt = string.format +local TCP_PORT = 35001 local function gen_trace_id() return to_hex(utils.get_rand_bytes(16)) @@ -15,6 +17,20 @@ local function gen_span_id() return to_hex(utils.get_rand_bytes(8)) end +local function get_span(name, spans) + for _, span in ipairs(spans) do + if span.name == name then + return span + end + end +end + +local function assert_has_span(name, spans) + local span = get_span(name, spans) + assert.is_truthy(span, fmt("\nExpected to find %q span in:\n%s\n", + name, pretty.write(spans))) + return span +end for _, strategy in helpers.each_strategy() do describe("propagation tests #" .. strategy, function() @@ -304,4 +320,85 @@ describe("propagation tests #" .. strategy, function() assert.matches("00%-%x+-" .. json.headers["x-b3-spanid"] .. "%-01", json.headers.traceparent) end) end) + +for _, instrumentation in ipairs({ "request", "request,balancer" }) do +describe("propagation tests with enabled " .. instrumentation .. " instrumentation (issue #11294) #" .. strategy, function() + local service, route + local proxy_client + + lazy_setup(function() + local bp = helpers.get_db_utils(strategy, { "services", "routes", "plugins" }, { "tcp-trace-exporter" }) + + service = bp.services:insert() + + route = bp.routes:insert({ + service = service, + hosts = { "http-route" }, + }) + + bp.plugins:insert({ + name = "opentelemetry", + route = {id = route.id}, + config = { + endpoint = "http://localhost:8080/v1/traces", + } + }) + + bp.plugins:insert({ + name = "tcp-trace-exporter", + config = { + host = "127.0.0.1", + port = TCP_PORT, + custom_spans = false, + } + }) + + helpers.start_kong({ + database = strategy, + plugins = "bundled, trace-propagator, tcp-trace-exporter", + nginx_conf = "spec/fixtures/custom_nginx.template", + tracing_instrumentations = instrumentation, + tracing_sampling_rate = 1, + }) + + proxy_client = helpers.proxy_client() + end) + + teardown(function() + helpers.stop_kong() + end) + + it("sets the outgoint parent span's ID correctly", function() + local trace_id = gen_trace_id() + local span_id = gen_span_id() + local thread = helpers.tcp_server(TCP_PORT) + + local r = proxy_client:get("/", { + headers = { + traceparent = fmt("00-%s-%s-01", trace_id, span_id), + host = "http-route" + }, + }) + local body = assert.response(r).has.status(200) + + local _, res = thread:join() + assert.is_string(res) + local spans = cjson.decode(res) + + local parent_span + if instrumentation == "request" then + -- balancer instrumentation is not enabled, + -- the outgoing parent span is the root span + parent_span = assert_has_span("kong", spans) + else + -- balancer instrumentation is enabled, + -- the outgoing parent span is the balancer span + parent_span = assert_has_span("kong.balancer", spans) + end + + local json = cjson.decode(body) + assert.matches("00%-" .. trace_id .. "%-" .. parent_span.span_id .. "%-01", json.headers.traceparent) + end) +end) +end end diff --git a/spec/fixtures/custom_plugins/kong/plugins/trace-propagator/handler.lua b/spec/fixtures/custom_plugins/kong/plugins/trace-propagator/handler.lua index 00211aa3e019..13b692e44603 100644 --- a/spec/fixtures/custom_plugins/kong/plugins/trace-propagator/handler.lua +++ b/spec/fixtures/custom_plugins/kong/plugins/trace-propagator/handler.lua @@ -14,31 +14,33 @@ local _M = { function _M:access(conf) local headers = ngx.req.get_headers() local tracer = kong.tracing.new("trace-propagator") - local root_span = tracer.start_span("root") + local root_span = ngx.ctx.KONG_SPANS and ngx.ctx.KONG_SPANS[1] + if not root_span then + root_span = tracer.start_span("root") + end + local injected_parent_span = ngx.ctx.tracing and + ngx.ctx.tracing.injected.balancer_span or root_span local header_type, trace_id, span_id, parent_id, should_sample = propagation_parse(headers) if should_sample == false then tracer:set_should_sample(should_sample) + injected_parent_span.should_sample = should_sample end if trace_id then - root_span.trace_id = trace_id + injected_parent_span.trace_id = trace_id end if span_id then - root_span.parent_id = span_id + injected_parent_span.parent_id = span_id elseif parent_id then - root_span.parent_id = parent_id + injected_parent_span.parent_id = parent_id end - local balancer_span = tracer.create_span(nil, { - span_kind = 3, - parent = root_span, - }) local type = header_type and "preserve" or "w3c" - propagation_set(type, header_type, balancer_span, "w3c", true) + propagation_set(type, header_type, injected_parent_span, "w3c") end return _M