io.grpc.Context getting cancelled

👋 Hi all, I was able to recreate the bug. I have a reproducer project available in this repo: ryandens/otel-grpc-context

I’m hopeful I’ll have time in the next few days to investigate and determine the source of the issue, but figured I’d give someone a starting point if they beat me to it. I was able to confirm that this error is not present in 1.1.0 but is present in 1.2.0.

After looking into this, I have a hypothesis that the instrumentation is working as intended - but in some sense, it is working too well and perhaps we do need to change it somehow.

When looking at this type of code pattern inside a gRPC handler

class Greeter {
  ExecutorService executor = Executors.newFixedThreadPool();

  sayHello() {
    responseObserver.onCompleted();
    executor.execute(() -> backend.sayGoodbye());
  }

It is in strict terms, “incorrect” gRPC code - gRPC context hasn’t been propagated into the executor. This means that deadline is not propagated as it’s supposed to be, and if using OpenCensus (gRPC’s native instrumentation), the trace would be broken. Similary, if using OpenTelemetry’s gRPC library instrumentation, the trace would be broken due to the lack of context propagation.

For this code to become correct, it needs to be something like Executor executor = Context.currentContextExecutor(Executors.newFixedThreadPool());. With deadline correctly propagated into the threadpool, this would cause the backend request to fail with the cancellation exception, no OpenTelemetry involved. Presumably you would call Context.fork() in the business logic to fix this business logic bug. Note that with such a change, adding OpenTelemetry library instrumentation would also just work - we sync the context between gRPC and OpenTelemetry because we want people to be able to add in the library instrumentation interceptors and have applications using gRPC context propagation to work out of the box, especially to help with OpenCensus migration.

Our problem here is that the javaagent is able to automatically propagate context for threadpool executors. Because we sync OpenTelemetry and gRPC context, this means that the gRPC deadline is also automatically propagated - so code that did not fail due to deadline issues will now fail. The early return pattern we see in the repro is a trival way of reproducing such code, but even traditional synchronous gRPC calls can fail if the client used .withDeadline() and the deadline got propagated to a location where it wasn’t intended. Usually it is intended though.

So the javaagent is making the app “better” by propagating deadline to more places it should be 😃 But we still have a rule that the javaagent can’t introduce exceptions to code that previously didn’t. I think I have reasoned out a workaround for the javaagent and let’s see how it goes.