fix(tracing/propagation): set parent span correctly

* 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

@@ -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"

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
 
 

kong/runloop/handler.lua

@@ -1194,6 +1194,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()

kong/tracing/instrumentation.lua

@@ -1,5 +1,4 @@
 local pdk_tracer = require "kong.pdk.tracing".new()
-local propagation = require "kong.tracing.propagation"
 local buffer = require "string.buffer"
 local utils = require "kong.tools.utils"
 local tablepool = require "tablepool"
@@ -83,10 +82,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
 
@@ -216,6 +215,10 @@ _M.available_types = available_types
 
 -- Record inbound request
 function _M.request(ctx)
+  ctx.tracing = {
+    injected = {},
+  }
+
   local client = kong.client
 
   local method = get_method()
@@ -251,6 +254,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

kong/tracing/propagation.lua

@@ -562,35 +562,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
-  if reuse then
-    set_propagated(proxy_span)
-  end
 
   local set_header = kong.service.request.set_header
 
@@ -683,5 +666,4 @@ return {
   parse = parse,
   set = set,
   from_hex = from_hex,
-  get_propagated = get_propagated,
 }

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

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