quarkus: Regression: Programmatic OpenTelemetry spans get ignored

Describe the bug

NOTE: This is a regression in Quarkus 2.13.0.CR1. In previous releases this has always worked as expected.

Background: In our application we store the OpenTelemetry context of incoming REST calls and then use it as the parent in calls which are triggered by a schedule. The schedule does this by programmatically creating a new span with the original span’s Context as parent and then activates the span. When now within this span a RestEasy Reactive Client call is used to call some API, the corresponding CLIENT span ignores the programmatically created span and in fact has no parent span. In previous releases the CLIENT span would reference the programmatically created span as its parent.

The programmatic logic to create a span looks something like this (see org.acme.MyScheduler#scheduled() in attached test for details):

Span span = tracer.spanBuilder("scheduler").setParent(context).startSpan();
try (Scope ignore = context.makeCurrent(); Scope ignore1 = span.makeCurrent()) {
    response = client.hello(addressee);
    span.end();
}

Expected behavior

Programmatic creation of spans should work as it did in previous Quarkus releases.

Actual behavior

See description.

Here are the spans (serialized JSON) created by the attached example project:

{
  "resource": {
    "attributes": [
      {
        "key": "service.name",
        "value": {
          "stringValue": "code-with-quarkus"
        }
      },
      {
        "key": "service.version",
        "value": {
          "stringValue": "1.0.0-SNAPSHOT"
        }
      },
      {
        "key": "telemetry.sdk.language",
        "value": {
          "stringValue": "java"
        }
      },
      {
        "key": "telemetry.sdk.name",
        "value": {
          "stringValue": "opentelemetry"
        }
      },
      {
        "key": "telemetry.sdk.version",
        "value": {
          "stringValue": "1.17.0"
        }
      },
      {
        "key": "webengine.name",
        "value": {
          "stringValue": "Quarkus"
        }
      },
      {
        "key": "webengine.version",
        "value": {
          "stringValue": "2.13.0.CR1"
        }
      }
    ]
  },
  "scopeSpans": [
    {
      "scope": {
        "name": "io.quarkus.opentelemetry"
      },
      "spans": [
        {
          "traceId": "62ffe5f3278ee2dbefabc499f50037e2",
          "spanId": "5f78270f084c18c7",
          "parentSpanId": "a49e8f9f5b8e4d77",
          "name": "/hello",
          "kind": "SPAN_KIND_SERVER",
          "startTimeUnixNano": "1663341640147360000",
          "endTimeUnixNano": "1663341640191058401",
          "attributes": [
            {
              "key": "http.response_content_length",
              "value": {
                "intValue": "28"
              }
            },
            {
              "key": "http.route",
              "value": {
                "stringValue": "/hello"
              }
            },
            {
              "key": "http.user_agent",
              "value": {
                "stringValue": "Apache-HttpClient/4.5.13 (Java/17.0.4)"
              }
            },
            {
              "key": "http.flavor",
              "value": {
                "stringValue": "1.1"
              }
            },
            {
              "key": "http.target",
              "value": {
                "stringValue": "/hello"
              }
            },
            {
              "key": "http.status_code",
              "value": {
                "intValue": "200"
              }
            },
            {
              "key": "http.client_ip",
              "value": {
                "stringValue": "127.0.0.1"
              }
            },
            {
              "key": "http.scheme",
              "value": {
                "stringValue": "http"
              }
            },
            {
              "key": "http.host",
              "value": {
                "stringValue": "localhost:8081"
              }
            },
            {
              "key": "http.method",
              "value": {
                "stringValue": "GET"
              }
            }
          ],
          "events": [],
          "links": [],
          "status": {}
        },
        {
          "traceId": "3042707be1f4a888f1f52c1fd49f5520",
          "spanId": "56cbdfd8da10b8b3",
          "parentSpanId": "f2d8926f2e017182",
          "name": "/hello/internal",
          "kind": "SPAN_KIND_SERVER",
          "startTimeUnixNano": "1663341641109469200",
          "endTimeUnixNano": "1663341641115058800",
          "attributes": [
            {
              "key": "http.response_content_length",
              "value": {
                "intValue": "11"
              }
            },
            {
              "key": "http.route",
              "value": {
                "stringValue": "/hello/internal"
              }
            },
            {
              "key": "http.user_agent",
              "value": {
                "stringValue": "Resteasy Reactive Client"
              }
            },
            {
              "key": "http.flavor",
              "value": {
                "stringValue": "1.1"
              }
            },
            {
              "key": "http.target",
              "value": {
                "stringValue": "/hello/internal"
              }
            },
            {
              "key": "http.status_code",
              "value": {
                "intValue": "200"
              }
            },
            {
              "key": "http.client_ip",
              "value": {
                "stringValue": "127.0.0.1"
              }
            },
            {
              "key": "http.scheme",
              "value": {
                "stringValue": "http"
              }
            },
            {
              "key": "http.host",
              "value": {
                "stringValue": "localhost:8081"
              }
            },
            {
              "key": "http.method",
              "value": {
                "stringValue": "GET"
              }
            },
            {
              "key": "http.request_content_length",
              "value": {
                "intValue": "5"
              }
            }
          ],
          "events": [],
          "links": [],
          "status": {}
        },
        {
          "traceId": "3042707be1f4a888f1f52c1fd49f5520",
          "spanId": "f2d8926f2e017182",
          "name": "HTTP GET",
          "kind": "SPAN_KIND_CLIENT",
          "startTimeUnixNano": "1663341641105501300",
          "endTimeUnixNano": "1663341641119615600",
          "attributes": [
            {
              "key": "http.response_content_length",
              "value": {
                "intValue": "11"
              }
            },
            {
              "key": "http.user_agent",
              "value": {
                "stringValue": "Resteasy Reactive Client"
              }
            },
            {
              "key": "http.status_code",
              "value": {
                "intValue": "200"
              }
            },
            {
              "key": "http.method",
              "value": {
                "stringValue": "GET"
              }
            },
            {
              "key": "http.url",
              "value": {
                "stringValue": "http://localhost:8081/hello/internal"
              }
            }
          ],
          "events": [],
          "links": [],
          "status": {}
        },
        {
          "traceId": "62ffe5f3278ee2dbefabc499f50037e2",
          "spanId": "10611f1988f86ede",
          "parentSpanId": "5f78270f084c18c7",
          "name": "scheduler",
          "kind": "SPAN_KIND_INTERNAL",
          "startTimeUnixNano": "1663341641000663901",
          "endTimeUnixNano": "1663341641123223601",
          "attributes": [],
          "events": [],
          "links": [],
          "status": {}
        }
      ]
    }
  ]
}

How to Reproduce?

Run mvn verify in the attached test application: code-with-quarkus.zip

Output of uname -a or ver

No response

Output of java -version

No response

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.13.0.CR1

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

No response

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 17 (16 by maintainers)

Most upvoted comments

In fact I think we have an on-success hook (forgot what it is called right now) with which we immediately attempt to execute the registered operation. While still using OpenTracing we created a FOLLOWS_FROM span (part of the same trace). This concept doesn’t exist in OpenTelemetry, but we should again look into linked spans.

The workaround from above, even if ugly, would work.

Workarounds often have this characteristic 😃 But thanks a lot for investigating and this workaround. We will certainly be able to wait for a proper solution in a patch release.