akka-http : Duplicate context headers when propagating a trace

[pnerg]

Issue

When debugging headers sent between applications I noticed an odd behaviour.
Seems like context related headers are duplicated during the propagation.
I see double b3 and context-tags headers.

Kamon version used: "io.kamon" %% "kamon-bundle" % "2.1.17"

Tests to prove behaviour

To illustrate the behaviour I created a small app (see below) that supports two paths

• /forward - prints headers and sends a GET to /hello
• /hello - prints headers and just responds with a string

Sending a request via Postman

GET http://localhost:9669/forward
X-B3-TraceId: aaaaaaaaaaaaaa
X-B3-SpanId: 1111111111111112

Log from test app

[info] --------------
[info] Got request for '/forward' parsed/generated context traceId[aaaaaaaaaaaaaa], spanId[39760408a4dc2da0], parentSpanId[1111111111111112]
[info] Timeout-Access: <function1>
[info] X-B3-SpanId: 1111111111111112
[info] X-B3-TraceId: aaaaaaaaaaaaaa
[info] User-Agent: PostmanRuntime/7.26.8
[info] Accept: */*
[info] Postman-Token: 1e33d481-8b0a-4b28-ab09-b15313b89da2
[info] Host
[info] Accept-Encoding: gzip, deflate, br
[info] Connection: keep-alive
[info] --------------
[info] Got request for '/hello' parsed/generated context traceId[aaaaaaaaaaaaaa], spanId[0cc92d692023e180], parentSpanId[5931484589822481]
[info] Timeout-Access: <function1>
[info] Host
[info] X-B3-Sampled: 1
[info] X-B3-ParentSpanId: 39760408a4dc2da0
[info] X-B3-SpanId: 5931484589822481
[info] X-B3-TraceId: aaaaaaaaaaaaaa
[info] context-tags: upstream.name=area51-server;
[info] X-B3-Sampled: 1
[info] X-B3-ParentSpanId: 5931484589822481
[info] X-B3-SpanId: 507f6b65a922d102
[info] X-B3-TraceId: aaaaaaaaaaaaaa
[info] context-tags: upstream.name=area51-server;
[info] User-Agent: akka-http/10.2.4

Observation 1 : Wrong spanID in context

The first log to print parsed context states:

[info] Got request for '/forward' parsed/generated context traceId[aaaaaaaaaaaaaa], spanId[39760408a4dc2da0], parentSpanId[1111111111111112]

[info] X-B3-SpanId: 1111111111111112
[info] X-B3-TraceId: aaaaaaaaaaaaaa

So the app has received the spanid header but still has created a new span and set the received span as parent.
This does not seem correct for b3 propagation.

Observation 2: Double trace headers in '/hello'

Note the double b3 and context-tags headers when receiving the request at /hello.
What is even more concerning is that the second set of trace headers has the first as parent span.
I.e.
X-B3-ParentSpanId: 5931484589822481 refers to X-B3-SpanId: 5931484589822481
So somehow we are having a second span incorporated into the set of headers

Test application

import akka.actor.ActorSystem
import akka.http.scaladsl.Http
import akka.http.scaladsl.model.HttpRequest
import akka.http.scaladsl.server.Directives.{complete, get, pathPrefix, _}
import akka.http.scaladsl.server.Route
import com.typesafe.config.ConfigFactory
import kamon.Kamon

object DefaultDebugKamonServer extends App {

  Kamon.init(ConfigFactory.defaultReference())

  private implicit val system = ActorSystem("debug-kamon-server")
  private implicit val executionContext = system.dispatcher

  def debugPrint(path:String, request:HttpRequest):Unit = {
    val span = Kamon.currentSpan()
    println("--------------")
    println(s"Got request for '$path' parsed/generated context traceId[${span.trace.id.string}], spanId[${span.id.string}], parentSpanId[${span.parentId.string}]")
    request.headers.foreach(println)
  }

  private lazy val route: Route =
    pathPrefix("forward") {
      get {
        extractRequest { request =>
          debugPrint("/forward", request)
          onComplete(Http().singleRequest(HttpRequest(uri = "http://localhost:9696/hello/")).flatMap(x => Unmarshal(x.entity).to[String])) { response =>
            complete(response)
          }
        }
      }
    } ~ pathPrefix("hello") {
      get {
        extractRequest { request =>
          debugPrint("/hello", request)
          complete("World")
        }
      }
    }

  Http().newServerAt("0.0.0.0", 9696).bind(route).foreach(addr => println(s"Started server at [$addr]"))
}

[SimunKaracic]

For the first observation, we have the following setting:

Kamon/core/kamon-core/src/main/resources/reference.conf

Line 154 in 7bf8705

join-remote-parents-with-same-span-id = no

For the double headers, I'll dig deeper and try to figure it out, we're probably double instrumenting something

[SimunKaracic]

Fixed in 2.1.19