open-telemetry / open-telemetry/opentelemetry-java-instrumentation

Traces disappear after calling gRPC with kotlin coroutine and `@WithSpan` annotation.

Open
#6,542 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug repro provided
Dominant language
Java
Stars
2.6k
Forks
1.2k
Avg merge
2d 18h
Merged PRs (30d)
228

Description

Describe the bug

When a suspend function is annotated with @WithSpan and call gRPC, traces disappear after calling gRPC.

Steps to reproduce
Here is an example code.
HelloWorldClient is copied from grpc-kotlin examples.
This logger is configured to display trace and span ids.

import io.grpc.ManagedChannelBuilder
import io.opentelemetry.extension.annotations.WithSpan
import kotlinx.coroutines.runBlocking
import org.slf4j.LoggerFactory

class App {
    companion object {
        private val log = LoggerFactory.getLogger(App::class.java)
    }

    fun run() {
        runBlocking {
            runInner()
        }
    }

    @WithSpan
    private suspend fun runInner() {
        log.info("start run")

        greet()

        log.info("finish run")
    }

    private suspend fun greet() {
        val channel = ManagedChannelBuilder.forAddress("localhost", 50051).usePlaintext().build()
        val client = HelloWorldClient(channel)

        client.use {
            log.info("before gRPC")
            it.greet("world")
            log.info("after gRPC")
        }
    }
}

fun main() {
    App().run()
}

If you annotate run() with @WithSpan instead of runInner(), the logs shows correct traces.

What did you expect to see?
All logs shows the same traces.

What did you see instead?

2022-09-05 15:46:57,329 INFO  [fd4f801b8fdb0d68813b93ec3e6bfe24-9532875b87e3c6f6-01] main App - start run
2022-09-05 15:46:58,044 INFO  [fd4f801b8fdb0d68813b93ec3e6bfe24-9532875b87e3c6f6-01] main App - before gRPC
2022-09-05 15:46:58,822 INFO  [--] main App - after gRPC
2022-09-05 15:46:58,874 INFO  [31410fbdd279d25857f4b0ccaa292ccb-4cd6a61499706ccf-01] main App - finish run

At the "after gRPC" log, the trace disappeared.
The "finish run" log shows newly created trace.

What version are you using?
1.17.0

Environment
Compiler: Corretto-17.0.2.8.1, Kotlin 1.6.20
OS: macOS 12.5.1

Additional context
gRPC Java 1.49.0
gRPC kotlin 1.3.0
protobuf 3.19.4

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with the App.runInner, greet, and HelloWorldClient flow shown in the reproduction, then inspect how @WithSpan spans cross the suspend gRPC call. Reproduce the log sequence and trace the context boundary around the call. Done means the after-gRPC and finish-run logs retain the expected trace, with a regression test covering the suspend function case.

Written by the indexing model from the issue text.

Assessment

Tech stack
grpc, kotlin
Domain
observability-sre
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.